Jan 28 13:58:00 volumio volumio-remote-updater[628]: [2026-01-28 13:58:00] [connect] Successful connection Jan 28 13:58:00 volumio volumio[20417]: info: Loading plugin "outputs"... Jan 28 13:58:00 volumio volumio[20417]: info: Loading plugin "albumart"... Jan 28 13:58:00 volumio volumio[20417]: info: Plugin example_plugin is not enabled Jan 28 13:58:00 volumio volumio[20417]: info: Loading plugin "inputs"... Jan 28 13:58:00 volumio volumio[20417]: info: Loading plugin "updater_comm"... Jan 28 13:58:00 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 13:58:00 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 13:58:00 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 13:58:00 volumio volumio[20417]: info: Plugin mpdemulation is not enabled Jan 28 13:58:00 volumio volumio[20417]: info: Loading plugin "rest_api"... Jan 28 13:58:00 volumio volumio[20417]: info: Loading plugin "websocket"... Jan 28 13:58:00 volumio volumio[20417]: info: Starting Socket.io Server version 1.7.4 Jan 28 13:58:00 volumio volumio[20417]: info: Loading plugin "RoonBridge"... Jan 28 13:58:01 volumio volumio[20417]: info: Applying required configuration parameters for plugin RoonBridge Jan 28 13:58:01 volumio volumio[20417]: info: Loading i18n strings for locale en Jan 28 13:58:01 volumio volumio[20417]: Updating browse sources language Jan 28 13:58:01 volumio volumio[20417]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 13:58:01 volumio volumio[20529]: Forking 3 albumart workers Jan 28 13:58:01 volumio volumio[20417]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 28 13:58:01 volumio volumio[20417]: info: CoreCommandRouter::initPlayerControls Jan 28 13:58:01 volumio volumio[20417]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 13:58:01 volumio volumio[20417]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 13:58:01 volumio volumio[20417]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 13:58:01 volumio volumio[20417]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 13:58:01 volumio volumio[20417]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 13:58:01 volumio volumio[20417]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 13:58:01 volumio volumio[20417]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 13:58:01 volumio volumio[20417]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 13:58:01 volumio volumio[20417]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 28 13:58:01 volumio volumio[20417]: Express server listening on port 3000 Jan 28 13:58:01 volumio volumio[20417]: [Metrics] WebUI: 16s 109.16ms Jan 28 13:58:01 volumio volumio[20417]: info: CoreStateMachine::resetVolumioState Jan 28 13:58:01 volumio volumio[20417]: info: CoreStateMachine::getcurrentVolume Jan 28 13:58:01 volumio volumio[20417]: info: CoreCommandRouter::volumioRetrievevolume Jan 28 13:58:01 volumio sudo[20574]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 28 13:58:01 volumio sudo[20574]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 13:58:01 volumio sudo[20574]: pam_unix(sudo:session): session closed for user root Jan 28 13:58:02 volumio sudo[20576]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 28 13:58:02 volumio sudo[20576]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 13:58:02 volumio volumio[20417]: info: Volumio Network Manager: Network status updated: 1 Jan 28 13:58:02 volumio sudo[20576]: pam_unix(sudo:session): session closed for user root Jan 28 13:58:02 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 12. Jan 28 13:58:02 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 13:58:02 volumio volumio[20417]: info: VolumeController:: Volume=100 Mute =false Jan 28 13:58:02 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 13:58:02 volumio go-librespot[20580]: go-librespot daemon starting... Jan 28 13:58:02 volumio volumio[20417]: info: CoreStateMachine::pushState Jan 28 13:58:02 volumio volumio[20417]: info: CorePlayQueue::getTrack 0 Jan 28 13:58:02 volumio volumio[20417]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 28 13:58:02 volumio volumio[20417]: info: CoreCommandRouter::volumioPushState Jan 28 13:58:02 volumio volumio[20417]: info: CoreStateMachine::updateTrackBlock Jan 28 13:58:02 volumio volumio[20417]: info: CorePlayQueue::getTrackBlock Jan 28 13:58:02 volumio volumio[20417]: info: CoreCommandRouter::volumioRetrievevolume Jan 28 13:58:02 volumio go-librespot[20581]: time="2026-01-28T13:58:02+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 13:58:02 volumio go-librespot[20581]: time="2026-01-28T13:58:02+07:00" level=debug msg="app state loaded" Jan 28 13:58:02 volumio go-librespot[20581]: time="2026-01-28T13:58:02+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 13:58:02 volumio volumio-remote-updater[628]: [2026-01-28 13:58:02] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1769583480 101 Jan 28 13:58:02 volumio volumio[20417]: 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 Jan 28 13:58:02 volumio volumio[20417]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 13:58:02 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 13:58:02 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 13:58:02 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 13:58:02 volumio volumio[20417]: info: Reloading queue from file Jan 28 13:58:02 volumio volumio[20417]: info: CoreStateMachine::setRepeat null single undefined Jan 28 13:58:02 volumio volumio[20417]: info: CoreStateMachine::pushState Jan 28 13:58:02 volumio volumio[20417]: info: CorePlayQueue::getTrack 0 Jan 28 13:58:02 volumio volumio[20417]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 28 13:58:02 volumio volumio[20417]: info: CoreCommandRouter::volumioPushState Jan 28 13:58:02 volumio volumio[20417]: info: CoreStateMachine::setRandom null Jan 28 13:58:02 volumio volumio[20417]: info: CoreStateMachine::pushState Jan 28 13:58:02 volumio volumio[20417]: info: CorePlayQueue::getTrack 0 Jan 28 13:58:02 volumio volumio[20417]: info: CoreCommandRouter::volumioPushState Jan 28 13:58:02 volumio volumio[20417]: info: Setting Device type: Raspberry PI Jan 28 13:58:02 volumio volumio[20417]: info: Completed loading Core Plugins Jan 28 13:58:02 volumio volumio[20417]: info: Preparing to generate the ALSA configuration file Jan 28 13:58:02 volumio volumio[20417]: info: VolumeController:: Volume=100 Mute =false Jan 28 13:58:02 volumio volumio[20417]: info: CoreStateMachine::pushState Jan 28 13:58:02 volumio volumio[20417]: info: CorePlayQueue::getTrack 0 Jan 28 13:58:02 volumio volumio[20417]: info: CoreCommandRouter::volumioPushState Jan 28 13:58:03 volumio go-librespot[20581]: time="2026-01-28T13:58:03+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 28 13:58:03 volumio go-librespot[20581]: time="2026-01-28T13:58:03+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]" Jan 28 13:58:03 volumio go-librespot[20581]: time="2026-01-28T13:58:03+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]" Jan 28 13:58:03 volumio volumio[20417]: info: Asound.conf file unchanged, so no further update is needed Jan 28 13:58:03 volumio volumio[20417]: info: Output device has changed, restarting MPD Jan 28 13:58:03 volumio go-librespot[20581]: time="2026-01-28T13:58:03+07:00" level=info msg="zeroconf server listening on port 32981" Jan 28 13:58:03 volumio sudo[20598]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Jan 28 13:58:03 volumio sudo[20598]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 13:58:03 volumio volumio[20417]: info: Output device has changed, restarting Shairport Sync Jan 28 13:58:03 volumio volumio[20417]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 13:58:03 volumio volumio[20417]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 13:58:03 volumio sudo[20600]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 28 13:58:03 volumio sudo[20600]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 13:58:03 volumio sudo[20603]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 28 13:58:03 volumio sudo[20603]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 13:58:03 volumio sudo[20598]: pam_unix(sudo:session): session closed for user root Jan 28 13:58:03 volumio sudo[20600]: pam_unix(sudo:session): session closed for user root Jan 28 13:58:03 volumio volumio[20417]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 28 13:58:03 volumio volumio[20417]: info: ___________ START PLUGINS ___________ Jan 28 13:58:03 volumio volumio[20417]: info: ControllerMpd::onStart: Initializing MPD Jan 28 13:58:03 volumio volumio[20417]: info: Creating MPD Configuration file Jan 28 13:58:03 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Jan 28 13:58:03 volumio go-librespot[20581]: time="2026-01-28T13:58:03+07:00" level=debug msg="obtained new client token: AAAY+LjDEJjuzjk99bESd99ZceKHMcWRwcVpsiv0Ir5mPaoAIoRRoVNrSYV1SPF7g+TlUBTAe7LbpLGKqtMBxsQpWJ0NGTWPZiG69h8oM4ljw7o3/8mW1yiZ+a0hU7IZhSSCOkDhvYwN2TwX6eTU9JWvZ7R0M9E7Y3huHOVaxC9xnNLEfY8aOFZ7pwgCewocC+Z5wfnEwnUhGJEsaUj7a+SLfNx7HHQAJtFddqeVAFDpODF9WgUi38OMViU=" Jan 28 13:58:03 volumio volumio[20417]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 28 13:58:03 volumio volumio[20417]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 13:58:03 volumio volumio[20417]: info: [1769583483385] CoreMusicLibrary::Adding element Media Servers Jan 28 13:58:03 volumio volumio[20417]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 13:58:03 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 28 13:58:03 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 28 13:58:03 volumio systemd[1]: mpd.service: Consumed 7.291s CPU time. Jan 28 13:58:03 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 28 13:58:03 volumio volumio[20417]: info: UPNP Browser: Client initialized successfully Jan 28 13:58:03 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 28 13:58:03 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 28 13:58:03 volumio go-librespot[20581]: time="2026-01-28T13:58:03+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 13:58:03 volumio sudo[20612]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 28 13:58:03 volumio sudo[20612]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 13:58:03 volumio sudo[20613]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 28 13:58:03 volumio sudo[20613]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 13:58:03 volumio sudo[20612]: pam_unix(sudo:session): session closed for user root Jan 28 13:58:03 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 28 13:58:03 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 28 13:58:03 volumio volumio[20417]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 13:58:03 volumio volumio[20417]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 13:58:03 volumio volumio[20417]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 28 13:58:03 volumio go-librespot[20581]: time="2026-01-28T13:58:03+07:00" level=debug msg="completed keyexchange" Jan 28 13:58:03 volumio go-librespot[20581]: time="2026-01-28T13:58:03+07:00" level=debug msg="completed challenge" Jan 28 13:58:03 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 28 13:58:03 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 28 13:58:03 volumio volumio[20417]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 13:58:03 volumio volumio[20417]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 13:58:03 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 28 13:58:03 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 28 13:58:03 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 28 13:58:03 volumio volumio[20417]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 28 13:58:03 volumio volumio[20417]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 13:58:03 volumio volumio[20417]: info: [1769583483705] CoreMusicLibrary::Adding element Last_100 Jan 28 13:58:03 volumio volumio[20417]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 13:58:03 volumio volumio[20417]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 13:58:03 volumio volumio[20417]: info: [1769583483715] CoreMusicLibrary::Adding element Webradio Jan 28 13:58:03 volumio volumio[20417]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 13:58:03 volumio volumio[20417]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 28 13:58:03 volumio go-librespot[20581]: time="2026-01-28T13:58:03+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 13:58:03 volumio volumio[20417]: info: Initializing BBC Radios Jan 28 13:58:03 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 28 13:58:03 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 28 13:58:03 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 13:58:03 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 13:58:03 volumio volumio[20417]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 28 13:58:03 volumio volumio[20417]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 13:58:03 volumio volumio[20417]: info: Creating Spotify config file Jan 28 13:58:03 volumio volumio[20417]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 13:58:04 volumio sudo[20630]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 28 13:58:04 volumio sudo[20630]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jan 28 13:58:04 volumio sudo[20630]: pam_unix(sudo:session): session closed for user root Jan 28 13:58:04 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 13:58:04 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 13:58:04 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 13:58:04 volumio volumio[20541]: Starting albumart workers Jan 28 13:58:04 volumio volumio[20539]: Starting albumart workers Jan 28 13:58:05 volumio volumio[20417]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 13:58:05 volumio volumio[20417]: info: [1769583485100] CoreMusicLibrary::Adding element YouTube Music Jan 28 13:58:05 volumio volumio[20417]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 13:58:05 volumio volumio[20417]: Cannot find translation for source YouTube Music Jan 28 13:58:05 volumio volumio[20417]: info: Volumio Calling Home Jan 28 13:58:05 volumio sudo[20644]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Jan 28 13:58:05 volumio sudo[20644]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 13:58:05 volumio sudo[20644]: pam_unix(sudo:session): session closed for user root Jan 28 13:58:05 volumio volumio[20540]: Starting albumart workers Jan 28 13:58:05 volumio volumio[20417]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Jan 28 13:58:05 volumio volumio[20417]: info: Discovery: Found device Volumio Jan 28 13:58:05 volumio volumio[20417]: info: CoreCommandRouter::volumioGetState Jan 28 13:58:05 volumio volumio[20417]: info: CorePlayQueue::getTrack 0 Jan 28 13:58:05 volumio volumio[20417]: info: MPD Permissions set Jan 28 13:58:05 volumio volumio[20417]: info: MPD Permissions set Jan 28 13:58:05 volumio volumio[20417]: info: Upmpdcli Daemon Started Jan 28 13:58:05 volumio volumio[20417]: info: Spotify config file written Jan 28 13:58:06 volumio volumio[20417]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Jan 28 13:58:06 volumio volumio[20417]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 13:58:06 volumio volumio[20417]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 13:58:06 volumio volumio[20417]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 13:58:06 volumio volumio[20417]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 13:58:06 volumio volumio[20417]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 13:58:06 volumio volumio[20417]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 13:58:06 volumio volumio[20417]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 13:58:06 volumio volumio[20417]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 13:58:06 volumio sudo[20650]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jan 28 13:58:06 volumio sudo[20650]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 13:58:06 volumio volumio[20417]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 13:58:06 volumio volumio[20417]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 13:58:06 volumio volumio[20417]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 13:58:06 volumio volumio[20417]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 13:58:06 volumio volumio[20417]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 13:58:06 volumio volumio[20417]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 13:58:06 volumio volumio[20417]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 13:58:06 volumio volumio[20417]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 13:58:06 volumio volumio[20417]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 13:58:06 volumio volumio[20417]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 13:58:06 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 13:58:06 volumio volumio[20417]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 13:58:06 volumio volumio[20417]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 13:58:06 volumio volumio[20417]: info: No need to fix Spotify hosts Jan 28 13:58:06 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 13:58:06 volumio go-librespot[20661]: go-librespot daemon starting... Jan 28 13:58:06 volumio sudo[20650]: pam_unix(sudo:session): session closed for user root Jan 28 13:58:06 volumio go-librespot[20663]: time="2026-01-28T13:58:06+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 13:58:06 volumio go-librespot[20663]: time="2026-01-28T13:58:06+07:00" level=debug msg="app state loaded" Jan 28 13:58:06 volumio go-librespot[20663]: time="2026-01-28T13:58:06+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 13:58:06 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 13:58:06 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 13:58:06 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 13:58:06 volumio volumio[20417]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Jan 28 13:58:06 volumio volumio[20417]: info: Discovery: Found device Volumio Jan 28 13:58:06 volumio volumio[20417]: info: CoreCommandRouter::volumioGetState Jan 28 13:58:06 volumio volumio[20417]: info: CorePlayQueue::getTrack 0 Jan 28 13:58:07 volumio go-librespot[20663]: time="2026-01-28T13:58:07+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 28 13:58:07 volumio go-librespot[20663]: time="2026-01-28T13:58:07+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]" Jan 28 13:58:07 volumio go-librespot[20663]: time="2026-01-28T13:58:07+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]" Jan 28 13:58:07 volumio go-librespot[20663]: time="2026-01-28T13:58:07+07:00" level=info msg="zeroconf server listening on port 44609" Jan 28 13:58:07 volumio go-librespot[20663]: time="2026-01-28T13:58:07+07:00" level=debug msg="obtained new client token: AAD0GqyX06BUzJNDrMu2rISJuD7x7vTGGTtyjl4aV+4R2shfvD8HPoyG1CLBY3Y2GcENpF8FLu7NdC8g5fTUCBfXidxY+RrkuebMZ3is21lhiMMyJj3N10X2VwZIC8uXgl6adnwaqLwazbDVuQhBTwAakl6TcBg2OD9VHfL0OVBpONPrxuWnujHw2RsEappTuDuMsvWOryixbgXb3GzFw25vK+RVaOerkQ0F/pXf9/AC6rqfcouHDsFLtUs=" Jan 28 13:58:07 volumio go-librespot[20663]: time="2026-01-28T13:58:07+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 13:58:07 volumio go-librespot[20663]: time="2026-01-28T13:58:07+07:00" level=debug msg="completed keyexchange" Jan 28 13:58:07 volumio go-librespot[20663]: time="2026-01-28T13:58:07+07:00" level=debug msg="completed challenge" Jan 28 13:58:07 volumio go-librespot[20663]: time="2026-01-28T13:58: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 " Jan 28 13:58:07 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 13:58:07 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 13:58:07 volumio volumio[20417]: info: Volumio called home Jan 28 13:58:07 volumio volumio[20417]: info: Starting Shairport Sync Jan 28 13:58:07 volumio volumio[20417]: info: Starting Shairport Sync Jan 28 13:58:07 volumio volumio[20417]: info: Starting Shairport Sync Jan 28 13:58:08 volumio sudo[20693]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 28 13:58:08 volumio sudo[20693]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 13:58:08 volumio volumio[20417]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 28 13:58:08 volumio volumio[20417]: SPOTIFY: BQDOMtQFM6tB8i5mvHAptCtWeZzbmLai6URoCtI01QDYIEWvl-DYHsfqAw6rIAI4UV035f8clU3MwDiIiaBMP8Z3W_pNbgDADtzcAgm-lujZ1qks9B7gz-OTRHaV9xas6VC4M6PoAaCptKNlU5_apCx9o_g37fJrSFR83RdRLH-VpfBpn_RWjNRkrsHSN3YtvHqMVbv1Frp6DeXSJ_-M4ECMvqhFRvp7MmOF6vt1rj6rSU8HS-Ayk5UFSZ9SGQiavaddhJMpK6d2725FU5wy5p4sT3GYwHlSPhPYE45F84JakXM6ja7Fx2wG Jan 28 13:58:08 volumio volumio[20417]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 28 13:58:08 volumio volumio[20417]: info: New Spotify access token = BQDOMtQFM6tB8i5mvHAptCtWeZzbmLai6URoCtI01QDYIEWvl-DYHsfqAw6rIAI4UV035f8clU3MwDiIiaBMP8Z3W_pNbgDADtzcAgm-lujZ1qks9B7gz-OTRHaV9xas6VC4M6PoAaCptKNlU5_apCx9o_g37fJrSFR83RdRLH-VpfBpn_RWjNRkrsHSN3YtvHqMVbv1Frp6DeXSJ_-M4ECMvqhFRvp7MmOF6vt1rj6rSU8HS-Ayk5UFSZ9SGQiavaddhJMpK6d2725FU5wy5p4sT3GYwHlSPhPYE45F84JakXM6ja7Fx2wG Jan 28 13:58:08 volumio volumio[20417]: info: Spotify credentials grant success - running version from March 24, 2019 Jan 28 13:58:08 volumio sudo[20695]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 28 13:58:08 volumio sudo[20695]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 13:58:08 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 28 13:58:08 volumio sudo[20697]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 28 13:58:08 volumio sudo[20697]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 13:58:08 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Jan 28 13:58:08 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 28 13:58:08 volumio systemd[1]: shairport-sync.service: Consumed 2.433s CPU time. Jan 28 13:58:08 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 28 13:58:08 volumio sudo[20693]: pam_unix(sudo:session): session closed for user root Jan 28 13:58:08 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 28 13:58:08 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Jan 28 13:58:08 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 28 13:58:08 volumio volumio[20417]: info: Shairport-Sync Started Jan 28 13:58:08 volumio volumio[20417]: Error adding Membership: Error: addMembership EINVAL Jan 28 13:58:08 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 28 13:58:08 volumio sudo[20697]: pam_unix(sudo:session): session closed for user root Jan 28 13:58:08 volumio sudo[20695]: pam_unix(sudo:session): session closed for user root Jan 28 13:58:08 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 13:58:08 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 13:58:08 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 13:58:08 volumio volumio[20417]: info: Shairport-Sync Started Jan 28 13:58:08 volumio volumio[20417]: info: Shairport-Sync Started Jan 28 13:58:08 volumio volumio[20417]: info: CoreCommandRouter::volumioGetState Jan 28 13:58:08 volumio volumio[20417]: info: CorePlayQueue::getTrack 0 Jan 28 13:58:08 volumio volumio[20417]: 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"} Jan 28 13:58:08 volumio volumio[20417]: info: Spotify Successfully logged in Jan 28 13:58:08 volumio volumio[20417]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 13:58:08 volumio volumio[20417]: info: [1769583488937] CoreMusicLibrary::Adding element Spotify Jan 28 13:58:08 volumio volumio[20417]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 13:58:08 volumio volumio[20417]: Cannot find translation for source YouTube Music Jan 28 13:58:08 volumio volumio[20417]: Cannot find translation for source Spotify Jan 28 13:58:09 volumio volumio[20417]: info: [yt-cast-receiver] DIAL server listening on port 8098 Jan 28 13:58:09 volumio volumio[20417]: info: CoreCommandRouter::volumioRetrievevolume Jan 28 13:58:10 volumio volumio[20417]: info: VolumeController:: Volume=100 Mute =false Jan 28 13:58:10 volumio volumio[20417]: info: CoreCommandRouter::volumioGetState Jan 28 13:58:10 volumio volumio[20417]: info: CorePlayQueue::getTrack 0 Jan 28 13:58:10 volumio volumio[20417]: info: CoreStateMachine::pushState Jan 28 13:58:10 volumio volumio[20417]: info: CorePlayQueue::getTrack 0 Jan 28 13:58:10 volumio volumio[20417]: info: CoreCommandRouter::volumioPushState Jan 28 13:58:10 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 13:58:10 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 13:58:10 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 13:58:10 volumio volumio[20417]: info: go-librespot daemon successfully initialized Jan 28 13:58:10 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 13. Jan 28 13:58:11 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 13:58:11 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 13:58:11 volumio go-librespot[20746]: go-librespot daemon starting... Jan 28 13:58:11 volumio go-librespot[20747]: time="2026-01-28T13:58:11+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 13:58:11 volumio go-librespot[20747]: time="2026-01-28T13:58:11+07:00" level=debug msg="app state loaded" Jan 28 13:58:11 volumio go-librespot[20747]: time="2026-01-28T13:58:11+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 13:58:11 volumio mpd[20642]: 2026-01-28T13:58:11 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 28 13:58:11 volumio systemd[1]: Started mpd.service - Music Player Daemon. Jan 28 13:58:11 volumio sudo[20603]: pam_unix(sudo:session): session closed for user root Jan 28 13:58:11 volumio sudo[20613]: pam_unix(sudo:session): session closed for user root Jan 28 13:58:11 volumio volumio[20417]: error: MPD error: The expression evaluated to a falsy value: Jan 28 13:58:11 volumio volumio[20417]: assert.ok(self.idling) Jan 28 13:58:11 volumio volumio[20417]: error: The expression evaluated to a falsy value: Jan 28 13:58:11 volumio volumio[20417]: assert.ok(self.idling) Jan 28 13:58:11 volumio volumio[20417]: info: MPD running with PID20642 Jan 28 13:58:11 volumio volumio[20417]: ,establishing connection Jan 28 13:58:11 volumio volumio[20417]: error: updateQueue error: null Jan 28 13:58:11 volumio go-librespot[20747]: time="2026-01-28T13:58:11+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 13:58:11 volumio go-librespot[20747]: time="2026-01-28T13:58:11+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]" Jan 28 13:58:11 volumio go-librespot[20747]: time="2026-01-28T13:58:11+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]" Jan 28 13:58:11 volumio go-librespot[20747]: time="2026-01-28T13:58:11+07:00" level=info msg="zeroconf server listening on port 32981" Jan 28 13:58:11 volumio volumio[20417]: info: Completed starting Core Plugins Jan 28 13:58:11 volumio volumio[20417]: info: ------------------------------------------- Jan 28 13:58:11 volumio volumio[20417]: info: ----- MyVolumio plugins startup ---- Jan 28 13:58:11 volumio volumio[20417]: info: ------------------------------------------- Jan 28 13:58:11 volumio volumio[20417]: info: [MyVolumio PluginManager] Fetching plans data.... Jan 28 13:58:11 volumio volumio[20417]: error: updateQueue error: null Jan 28 13:58:11 volumio go-librespot[20747]: time="2026-01-28T13:58:11+07:00" level=debug msg="obtained new client token: AAALZSdzOmyvNPUPuLA/cEXfn8e6DIy1aAvnxd20J/OTIputbLVBXmPcAx6310VPx0Nc+b/8nKFxHOBFstX+zWnuPcnI2Cu3fybe40TaUTIaG736dVo83fUOcbrnDPQXGESYh2/9uFOh48D5DzETQYcjDojZfxoc9IbgakguPjzLApJmb7wP8Q+gwY/t2mW2AQUyIf4NQmk7AXV9SKLdL6DB8ieC0WTN6Hqttp/13HbDa6B+7PFpXgX5fcc=" Jan 28 13:58:12 volumio go-librespot[20747]: time="2026-01-28T13:58:12+07:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:4070, retrying with a different AP" error="dial tcp 104.199.241.202:4070: connect: connection refused" Jan 28 13:58:12 volumio go-librespot[20747]: time="2026-01-28T13:58:12+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Jan 28 13:58:12 volumio go-librespot[20747]: time="2026-01-28T13:58:12+07:00" level=debug msg="completed keyexchange" Jan 28 13:58:12 volumio go-librespot[20747]: time="2026-01-28T13:58:12+07:00" level=debug msg="completed challenge" Jan 28 13:58:12 volumio go-librespot[20747]: time="2026-01-28T13:58:12+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 " Jan 28 13:58:12 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 13:58:12 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 13:58:12 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 13:58:12 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 13:58:12 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 13:58:13 volumio volumio[20417]: info: Initializing connection to go-librespot Websocket Jan 28 13:58:13 volumio volumio[20417]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 28 13:58:14 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 13:58:14 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 13:58:14 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 13:58:15 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 14. Jan 28 13:58:15 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 13:58:15 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 13:58:15 volumio go-librespot[20759]: go-librespot daemon starting... Jan 28 13:58:15 volumio go-librespot[20760]: time="2026-01-28T13:58:15+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 13:58:15 volumio go-librespot[20760]: time="2026-01-28T13:58:15+07:00" level=debug msg="app state loaded" Jan 28 13:58:15 volumio go-librespot[20760]: time="2026-01-28T13:58:15+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 13:58:16 volumio go-librespot[20760]: time="2026-01-28T13:58:16+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 13:58:16 volumio go-librespot[20760]: time="2026-01-28T13:58:16+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]" Jan 28 13:58:16 volumio go-librespot[20760]: time="2026-01-28T13:58:16+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]" Jan 28 13:58:16 volumio go-librespot[20760]: time="2026-01-28T13:58:16+07:00" level=info msg="zeroconf server listening on port 42969" Jan 28 13:58:16 volumio go-librespot[20760]: time="2026-01-28T13:58:16+07:00" level=debug msg="obtained new client token: AADnxNpLr/vaFzdvEs5TZIV2WMEhdrCA6pOLhPL3fhc8UQYFrHmbvrkj+qfxM7oJtw/aQXsm6bZT9v+K9dSMW4gmPDNY9pdTJ/yZk4Rn8dTDH3AMeeKIiv/1PD9LImv9QAuodIFKvrKKyKlziKo2PXTJL7bFZ5tIoSxmBRALsPDnFAqDboyHrNhPWMnWW5+aw6WEP5P/Cjns0VzYeGv2KjsvSGxpTChzoGaDDOctw3SAe84PmMFjKXXH" Jan 28 13:58:16 volumio go-librespot[20760]: time="2026-01-28T13:58:16+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 13:58:16 volumio volumio[20417]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Jan 28 13:58:16 volumio go-librespot[20760]: time="2026-01-28T13:58:16+07:00" level=debug msg="completed keyexchange" Jan 28 13:58:16 volumio go-librespot[20760]: time="2026-01-28T13:58:16+07:00" level=debug msg="completed challenge" Jan 28 13:58:16 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 13:58:16 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 13:58:16 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 13:58:16 volumio go-librespot[20760]: time="2026-01-28T13:58: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 " Jan 28 13:58:16 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 13:58:16 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 13:58:16 volumio volumio[20417]: info: Initializing connection to go-librespot Websocket Jan 28 13:58:16 volumio volumio[20417]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 28 13:58:18 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 13:58:18 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 13:58:18 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 13:58:19 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 15. Jan 28 13:58:19 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 13:58:19 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 13:58:19 volumio go-librespot[20769]: go-librespot daemon starting... Jan 28 13:58:19 volumio go-librespot[20770]: time="2026-01-28T13:58:19+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 13:58:19 volumio go-librespot[20770]: time="2026-01-28T13:58:19+07:00" level=debug msg="app state loaded" Jan 28 13:58:19 volumio volumio[20417]: info: Initializing connection to go-librespot Websocket Jan 28 13:58:19 volumio go-librespot[20770]: time="2026-01-28T13:58:19+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 13:58:19 volumio go-librespot[20770]: time="2026-01-28T13:58:19+07:00" level=debug msg="new websocket client" Jan 28 13:58:19 volumio volumio[20417]: info: Connection to go-librespot Websocket established Jan 28 13:58:20 volumio go-librespot[20770]: time="2026-01-28T13:58:20+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 13:58:20 volumio go-librespot[20770]: time="2026-01-28T13:58:20+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]" Jan 28 13:58:20 volumio go-librespot[20770]: time="2026-01-28T13:58:20+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]" Jan 28 13:58:20 volumio go-librespot[20770]: time="2026-01-28T13:58:20+07:00" level=info msg="zeroconf server listening on port 34901" Jan 28 13:58:20 volumio volumio[20417]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Jan 28 13:58:20 volumio volumio[20417]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Jan 28 13:58:20 volumio volumio[20417]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Jan 28 13:58:20 volumio volumio[20417]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Jan 28 13:58:20 volumio volumio[20417]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Jan 28 13:58:20 volumio volumio[20417]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Jan 28 13:58:20 volumio volumio[20417]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Jan 28 13:58:20 volumio volumio[20417]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Jan 28 13:58:20 volumio volumio[20417]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Jan 28 13:58:20 volumio volumio[20417]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Jan 28 13:58:20 volumio volumio[20417]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Jan 28 13:58:20 volumio volumio[20417]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Jan 28 13:58:20 volumio volumio[20417]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Jan 28 13:58:20 volumio volumio[20417]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Jan 28 13:58:20 volumio volumio[20417]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Jan 28 13:58:20 volumio volumio[20417]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Jan 28 13:58:20 volumio volumio[20417]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Jan 28 13:58:20 volumio volumio[20417]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Jan 28 13:58:20 volumio volumio[20417]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Jan 28 13:58:20 volumio volumio[20417]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Jan 28 13:58:20 volumio volumio[20417]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Jan 28 13:58:20 volumio volumio[20417]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Jan 28 13:58:20 volumio volumio[20417]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Jan 28 13:58:20 volumio volumio[20417]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Jan 28 13:58:20 volumio volumio[20417]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Jan 28 13:58:20 volumio volumio[20417]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Jan 28 13:58:20 volumio volumio[20417]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Jan 28 13:58:20 volumio volumio[20417]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Jan 28 13:58:20 volumio volumio[20417]: info: Adding plugin bluetooth to MyMusic Plugins Jan 28 13:58:20 volumio volumio[20417]: info: Adding plugin multiroom to MyMusic Plugins Jan 28 13:58:20 volumio volumio[20417]: info: Adding plugin metavolumio to MyMusic Plugins Jan 28 13:58:20 volumio volumio[20417]: info: Adding plugin cd_controller to MyMusic Plugins Jan 28 13:58:20 volumio volumio[20417]: info: Adding plugin qobuzconnect to MyMusic Plugins Jan 28 13:58:20 volumio volumio[20417]: info: Adding plugin smart_inputs to MyMusic Plugins Jan 28 13:58:20 volumio volumio[20417]: info: Adding plugin tidalconnect to MyMusic Plugins Jan 28 13:58:20 volumio volumio[20417]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Jan 28 13:58:20 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 13:58:20 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 13:58:20 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 13:58:20 volumio go-librespot[20770]: time="2026-01-28T13:58:20+07:00" level=debug msg="obtained new client token: AABHwZXLaahwWzOsy6gIjseW3ljcdy9dBy0YLaZfYGaeVMRfJnTqn7mKvi3ZDCpE3L1h4gxzKuUNsqtr6lfMg6GQh1z3I63GJ4OfXkmc0rYd61kGa2Rqilh5rYMxpbj/+VfOZblHz3/Bx61+NS1Ip5IDoPXFd7F0pmMMHPDD8yyvcyg/I7ihE7ybhSXSazn4M1RQwxORdEHy5gs2djKYlq8I47FludzBNKyB+uK44cYdSP3KXRHfkaU/MAo=" Jan 28 13:58:20 volumio go-librespot[20770]: time="2026-01-28T13:58:20+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 13:58:20 volumio go-librespot[20770]: time="2026-01-28T13:58:20+07:00" level=debug msg="completed keyexchange" Jan 28 13:58:20 volumio go-librespot[20770]: time="2026-01-28T13:58:20+07:00" level=debug msg="completed challenge" Jan 28 13:58:20 volumio go-librespot[20770]: time="2026-01-28T13:58: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 " Jan 28 13:58:20 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 13:58:20 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 13:58:22 volumio volumio[20417]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Jan 28 13:58:22 volumio volumio[20417]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Jan 28 13:58:22 volumio volumio[20417]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 13:58:22 volumio volumio[20417]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 13:58:22 volumio volumio[20417]: info: Starting MyVolumio Remote Streaming Endpoints Jan 28 13:58:22 volumio volumio[20417]: info: MyVolumio login type: Token Jan 28 13:58:22 volumio volumio[20417]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Jan 28 13:58:22 volumio volumio[20417]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Jan 28 13:58:22 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 13:58:22 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 13:58:22 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 13:58:23 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 16. Jan 28 13:58:23 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 13:58:24 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 13:58:24 volumio go-librespot[20792]: go-librespot daemon starting... Jan 28 13:58:24 volumio go-librespot[20793]: time="2026-01-28T13:58:24+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 13:58:24 volumio go-librespot[20793]: time="2026-01-28T13:58:24+07:00" level=debug msg="app state loaded" Jan 28 13:58:24 volumio go-librespot[20793]: time="2026-01-28T13:58:24+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 13:58:24 volumio volumio[20417]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Jan 28 13:58:24 volumio volumio[20417]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Jan 28 13:58:24 volumio volumio[20417]: info: Streaming services startup Jan 28 13:58:24 volumio volumio[20417]: info: Starting Streaming Daemon Jan 28 13:58:24 volumio volumio[20417]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Jan 28 13:58:24 volumio sudo[20801]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jan 28 13:58:24 volumio sudo[20801]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 13:58:24 volumio sudo[20801]: pam_unix(sudo:session): session closed for user root Jan 28 13:58:24 volumio volumio[20417]: info: Getting Spotify volume Jan 28 13:58:24 volumio volumio[20417]: info: Connection to go-librespot Websocket closed Jan 28 13:58:24 volumio volumio[20417]: error: Cannot start Volumio Streaming Daemon Jan 28 13:58:24 volumio volumio[20417]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Jan 28 13:58:24 volumio volumio[20417]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Jan 28 13:58:24 volumio volumio[20417]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Jan 28 13:58:24 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 13:58:24 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 13:58:24 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 13:58:24 volumio go-librespot[20793]: time="2026-01-28T13:58: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]" Jan 28 13:58:24 volumio go-librespot[20793]: time="2026-01-28T13:58: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]" Jan 28 13:58:24 volumio go-librespot[20793]: time="2026-01-28T13:58: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]" Jan 28 13:58:24 volumio volumio[20417]: info: CoreCommandRouter::volumioGetState Jan 28 13:58:24 volumio volumio[20417]: info: CorePlayQueue::getTrack 0 Jan 28 13:58:24 volumio go-librespot[20793]: time="2026-01-28T13:58:24+07:00" level=info msg="zeroconf server listening on port 46573" Jan 28 13:58:24 volumio volumio[20417]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jan 28 13:58:24 volumio volumio[20417]: SPOTIFY: SPOTIFY VOLUME undefined Jan 28 13:58:24 volumio volumio[20417]: SPOTIFY: VOLUMIO VOLUME 100 Jan 28 13:58:24 volumio volumio[20417]: info: Aligning Spotify Volume to Volumio Volume Jan 28 13:58:24 volumio volumio[20417]: info: CoreCommandRouter::volumioGetState Jan 28 13:58:24 volumio volumio[20417]: info: CorePlayQueue::getTrack 0 Jan 28 13:58:24 volumio volumio[20417]: info: Setting Spotify Volume from Volumio: 100 Jan 28 13:58:24 volumio go-librespot[20793]: time="2026-01-28T13:58:24+07:00" level=debug msg="obtained new client token: AADob/wOrUSTTFM9gTnyu6KlVS7P40ihVwmdFH5kM7vHNQDDs43DdXEHAlMCFtWr0psOyBWTmWY8to0nGoK4+zSquJoBc+7/nwxzLkb3H0HT+XlLTMb1qtMjL9Itus/DYxwT+B3beEi30TyZrREa2cHHaQiJGouzZyx53OFpIjKZYLDyxUErpPBXRniSy56QJwXmA+Y6b+kwly2kTBsVMJYiHHTRwoiJKjABFco7TZ8jCoUR8xS5RTvyZpo=" Jan 28 13:58:24 volumio go-librespot[20793]: time="2026-01-28T13:58:24+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 13:58:25 volumio go-librespot[20793]: time="2026-01-28T13:58:25+07:00" level=debug msg="completed keyexchange" Jan 28 13:58:25 volumio go-librespot[20793]: time="2026-01-28T13:58:25+07:00" level=debug msg="completed challenge" Jan 28 13:58:25 volumio go-librespot[20793]: time="2026-01-28T13:58:25+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 " Jan 28 13:58:25 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 13:58:25 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 13:58:25 volumio volumio[20417]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 28 13:58:25 volumio volumio[20417]: Error: socket hang up Jan 28 13:58:25 volumio volumio[20417]: at connResetException (node:internal/errors:720:14) Jan 28 13:58:25 volumio volumio[20417]: at Socket.socketOnEnd (node:_http_client:519:23) Jan 28 13:58:25 volumio volumio[20417]: at Socket.emit (node:events:526:35) Jan 28 13:58:25 volumio volumio[20417]: at endReadableNT (node:internal/streams/readable:1376:12) Jan 28 13:58:25 volumio volumio[20417]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Jan 28 13:58:25 volumio volumio[20417]: code: 'ECONNRESET', Jan 28 13:58:25 volumio volumio[20417]: response: undefined Jan 28 13:58:25 volumio volumio[20417]: } Jan 28 13:58:25 volumio volumio[20417]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 28 13:58:26 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 13:58:26 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 13:58:26 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 13:58:26 volumio sudo[20822]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-01-28 13:57' Jan 28 13:58:26 volumio sudo[20822]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 13:58:26 volumio sudo[20822]: pam_unix(sudo:session): session closed for user root Jan 28 13:58:28 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 17. Jan 28 13:58:28 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 13:58:28 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 13:58:28 volumio go-librespot[20831]: go-librespot daemon starting... Jan 28 13:58:28 volumio go-librespot[20832]: time="2026-01-28T13:58:28+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 13:58:28 volumio go-librespot[20832]: time="2026-01-28T13:58:28+07:00" level=debug msg="app state loaded" Jan 28 13:58:28 volumio go-librespot[20832]: time="2026-01-28T13:58:28+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 13:58:28 volumio volumio-remote-updater[628]: [2026-01-28 13:58:28] [error] handle_read_frame error: asio.system:104 (Connection reset by peer) Jan 28 13:58:28 volumio volumio-remote-updater[628]: [2026-01-28 13:58:28] [disconnect] Disconnect close local:[1006,Connection reset by peer] remote:[1006] Jan 28 13:58:28 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Jan 28 13:58:28 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Jan 28 13:58:28 volumio systemd[1]: volumio.service: Consumed 59.150s CPU time. Jan 28 13:58:28 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 28 13:58:28 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 13:58:28 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 13:58:28 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 13:58:28 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 10227. Jan 28 13:58:28 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Jan 28 13:58:28 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Jan 28 13:58:28 volumio systemd[1]: volumio.service: Consumed 59.150s CPU time. Jan 28 13:58:28 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Jan 28 13:58:28 volumio go-librespot[20832]: time="2026-01-28T13:58: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-gew4.spotify.com:80]" Jan 28 13:58:28 volumio go-librespot[20832]: time="2026-01-28T13:58:28+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]" Jan 28 13:58:28 volumio go-librespot[20832]: time="2026-01-28T13:58:28+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]" Jan 28 13:58:28 volumio go-librespot[20832]: time="2026-01-28T13:58:28+07:00" level=info msg="zeroconf server listening on port 37247" Jan 28 13:58:29 volumio go-librespot[20832]: time="2026-01-28T13:58:29+07:00" level=debug msg="obtained new client token: AAClJBGxjVmn4fhnuLZ+nMSsbHo6cTTJDayMziM1gaLf+v8/USeVlTko37c9682oBG5jXgC/rOQK4Ixqo6LYpt8VNErACd9N+AxObJz21PiaCMdTBHk7pGTF5f3dlqoZh0lkWusDLmUNDl62gg2ye0di6WrHEOWl3vEYVGIW9B2L2FnudiRD2Fgnjr5W1kziivwsZbPcLgDIziE706Emv80yeIQFYzixV1B5KALf1/QwcVdTRaw9ysgB" Jan 28 13:58:29 volumio go-librespot[20832]: time="2026-01-28T13:58:29+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 13:58:29 volumio go-librespot[20832]: time="2026-01-28T13:58:29+07:00" level=debug msg="completed keyexchange" Jan 28 13:58:29 volumio go-librespot[20832]: time="2026-01-28T13:58:29+07:00" level=debug msg="completed challenge" Jan 28 13:58:29 volumio go-librespot[20832]: time="2026-01-28T13:58:29+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 " Jan 28 13:58:29 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 13:58:29 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 13:58:30 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 13:58:30 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 13:58:30 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 13:58:32 volumio volumio[20847]: info: ------------------------------------------- Jan 28 13:58:32 volumio volumio[20847]: info: ----- Volumio3 ---- Jan 28 13:58:32 volumio volumio[20847]: info: ------------------------------------------- Jan 28 13:58:32 volumio volumio[20847]: info: ----- System startup ---- Jan 28 13:58:32 volumio volumio[20847]: info: ------------------------------------------- Jan 28 13:58:32 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 18. Jan 28 13:58:32 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 13:58:32 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 13:58:32 volumio go-librespot[20864]: go-librespot daemon starting... Jan 28 13:58:32 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 13:58:32 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 13:58:32 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 13:58:32 volumio go-librespot[20865]: time="2026-01-28T13:58:32+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 13:58:32 volumio go-librespot[20865]: time="2026-01-28T13:58:32+07:00" level=debug msg="app state loaded" Jan 28 13:58:32 volumio go-librespot[20865]: time="2026-01-28T13:58:32+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 13:58:33 volumio go-librespot[20865]: time="2026-01-28T13:58:33+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 13:58:33 volumio go-librespot[20865]: time="2026-01-28T13:58:33+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]" Jan 28 13:58:33 volumio go-librespot[20865]: time="2026-01-28T13:58:33+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]" Jan 28 13:58:33 volumio go-librespot[20865]: time="2026-01-28T13:58:33+07:00" level=info msg="zeroconf server listening on port 45729" Jan 28 13:58:33 volumio volumio-remote-updater[628]: [2026-01-28 13:58:33] [connect] Successful connection Jan 28 13:58:33 volumio go-librespot[20865]: time="2026-01-28T13:58:33+07:00" level=debug msg="obtained new client token: AACRSquYxtmsjW5LMoCX4cS6A/R96YxPbFV5RoSlvdwMt9O+k31YgLmShRy8QVJU+NMh+SYmk0418Hk+CgiWomUSWZ5AyY0ndVs3SZSl4FtZwdWkNeEqntrmwYF5+T+sdwjR+jbj5Jw68haWSX+aP+6dznxUnkkVN1kzjgb7VRFjd/YksIODCcQhVXnPJPBdd9HE+AykIOPNPPHJn8j8kY88QhXi6vHA+JoKR84mdAZwfzBOehfs6mumrNA=" Jan 28 13:58:33 volumio go-librespot[20865]: time="2026-01-28T13:58:33+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" Jan 28 13:58:33 volumio volumio[20847]: info: MYVOLUMIO Environment detected Jan 28 13:58:33 volumio go-librespot[20865]: time="2026-01-28T13:58:33+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Jan 28 13:58:33 volumio volumio[20847]: info: Plugin folders cleanup Jan 28 13:58:33 volumio volumio[20847]: info: Scanning into folder /volumio/app/plugins/ Jan 28 13:58:33 volumio go-librespot[20865]: time="2026-01-28T13:58:33+07:00" level=debug msg="completed keyexchange" Jan 28 13:58:33 volumio volumio[20847]: info: Scanning category audio_interface Jan 28 13:58:33 volumio go-librespot[20865]: time="2026-01-28T13:58:33+07:00" level=debug msg="completed challenge" Jan 28 13:58:33 volumio volumio[20847]: info: Scanning category miscellanea Jan 28 13:58:33 volumio volumio[20847]: info: Scanning category music_service Jan 28 13:58:33 volumio volumio[20847]: info: Scanning category plugins.json Jan 28 13:58:33 volumio volumio[20847]: info: Scanning category system_controller Jan 28 13:58:33 volumio volumio[20847]: info: Scanning category user_interface Jan 28 13:58:33 volumio volumio[20847]: info: Scanning into folder /data/plugins/ Jan 28 13:58:33 volumio volumio[20847]: info: Scanning category music_service Jan 28 13:58:33 volumio volumio[20847]: info: Plugin folders cleanup completed Jan 28 13:58:33 volumio volumio[20847]: info: ------------------------------------------- Jan 28 13:58:33 volumio volumio[20847]: info: ----- Core plugins startup ---- Jan 28 13:58:33 volumio volumio[20847]: info: ------------------------------------------- Jan 28 13:58:33 volumio volumio[20847]: info: Loading plugins from folder /volumio/app/plugins/ Jan 28 13:58:33 volumio volumio[20847]: info: Adding plugin upnp to MyMusic Plugins Jan 28 13:58:33 volumio volumio[20847]: info: Adding plugin airplay_emulation to MyMusic Plugins Jan 28 13:58:33 volumio volumio[20847]: info: Adding plugin upnp_browser to MyMusic Plugins Jan 28 13:58:33 volumio volumio[20847]: info: Loading plugins from folder /data/plugins/ Jan 28 13:58:33 volumio volumio[20847]: info: Loading plugin "system"... Jan 28 13:58:33 volumio go-librespot[20865]: time="2026-01-28T13:58: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 " Jan 28 13:58:33 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 13:58:33 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 13:58:33 volumio volumio[20847]: info: Loading plugin "appearance"... Jan 28 13:58:34 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 13:58:34 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 13:58:34 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 13:58:35 volumio volumio[20847]: info: Loading plugin "network"... Jan 28 13:58:35 volumio volumio[20847]: info: Refreshing Cached IP Addresses Jan 28 13:58:35 volumio sudo[20880]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 28 13:58:35 volumio sudo[20880]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 13:58:35 volumio volumio[20847]: info: Loading plugin "services"... Jan 28 13:58:35 volumio sudo[20882]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 28 13:58:35 volumio sudo[20882]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 13:58:35 volumio volumio[20847]: info: Loading plugin "alsa_controller"... Jan 28 13:58:35 volumio sudo[20882]: pam_unix(sudo:session): session closed for user root Jan 28 13:58:35 volumio sudo[20880]: pam_unix(sudo:session): session closed for user root Jan 28 13:58:35 volumio sudo[20889]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Jan 28 13:58:35 volumio sudo[20889]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 13:58:36 volumio volumio[20847]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 28 13:58:36 volumio volumio[20847]: info: Loading plugin "wizard"... Jan 28 13:58:36 volumio volumio[20847]: info: Loading plugin "networkfs"... Jan 28 13:58:36 volumio volumio[20847]: info: Starting Udev Watcher for removable devices Jan 28 13:58:36 volumio volumio[20847]: info: Ignoring mount for partition: boot Jan 28 13:58:36 volumio volumio[20847]: info: Ignoring mount for partition: volumio Jan 28 13:58:36 volumio volumio[20847]: info: Ignoring mount for partition: volumio_data Jan 28 13:58:36 volumio volumio[20847]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 28 13:58:36 volumio volumio[20847]: info: Loading plugin "volumio_command_line_client"... Jan 28 13:58:36 volumio volumio[20847]: info: Loading plugin "upnp"... Jan 28 13:58:36 volumio volumio[20847]: info: [1769583516222] Starting Upmpd Daemon Jan 28 13:58:36 volumio volumio[20847]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 28 13:58:36 volumio volumio[20847]: info: Loading plugin "my_music"... Jan 28 13:58:36 volumio volumio[20847]: info: Loading plugin "mpd"... Jan 28 13:58:36 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 13:58:36 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 13:58:36 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 13:58:36 volumio volumio[20847]: info: Loading plugin "upnp_browser"... Jan 28 13:58:36 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 19. Jan 28 13:58:36 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 13:58:37 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 13:58:37 volumio go-librespot[20913]: go-librespot daemon starting... Jan 28 13:58:37 volumio go-librespot[20914]: time="2026-01-28T13:58:37+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 13:58:37 volumio go-librespot[20914]: time="2026-01-28T13:58:37+07:00" level=debug msg="app state loaded" Jan 28 13:58:37 volumio go-librespot[20914]: time="2026-01-28T13:58:37+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 13:58:37 volumio go-librespot[20914]: time="2026-01-28T13:58:37+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]" Jan 28 13:58:37 volumio go-librespot[20914]: time="2026-01-28T13:58:37+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]" Jan 28 13:58:37 volumio go-librespot[20914]: time="2026-01-28T13:58:37+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]" Jan 28 13:58:37 volumio go-librespot[20914]: time="2026-01-28T13:58:37+07:00" level=info msg="zeroconf server listening on port 35003" Jan 28 13:58:37 volumio go-librespot[20914]: time="2026-01-28T13:58:37+07:00" level=debug msg="obtained new client token: AAA5iqsMhw5hd+8u8QW306fxHKjUjo7LTQju6PuoqB6tuaS5O6B+O8YMJqJU6pwBpQQnPwK+fSnHkD9HlTqdCzwBQ1foQ6ysny83kqFd/bey4yz3f2Djaa91E+6L8nRZETwTLn9EzJ/S5Ygo7QLGFwccbYO1o+HoRVHouubnOvbzBU9Td0HdP23NMGGx2ZPhizY7gckRK1i3S/MUfQO34DE4FsMCFvIJvDIl8yuRShfI50Y9TCrfZkBso/Y=" Jan 28 13:58:37 volumio go-librespot[20914]: time="2026-01-28T13:58:37+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 13:58:38 volumio go-librespot[20914]: time="2026-01-28T13:58:38+07:00" level=debug msg="completed keyexchange" Jan 28 13:58:38 volumio go-librespot[20914]: time="2026-01-28T13:58:38+07:00" level=debug msg="completed challenge" Jan 28 13:58:38 volumio go-librespot[20914]: time="2026-01-28T13:58:38+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 " Jan 28 13:58:38 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 13:58:38 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 13:58:38 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 13:58:38 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 13:58:38 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 13:58:38 volumio sudo[20889]: pam_unix(sudo:session): session closed for user root Jan 28 13:58:39 volumio volumio[20847]: info: Starting UPNP Browser Jan 28 13:58:39 volumio volumio[20847]: info: Loading plugin "alarm-clock"... Jan 28 13:58:40 volumio volumio[20847]: info: Loading plugin "airplay_emulation"... Jan 28 13:58:40 volumio volumio[20847]: info: Starting Shairport Sync Jan 28 13:58:40 volumio volumio[20847]: info: Loading plugin "last_100"... Jan 28 13:58:40 volumio volumio[20847]: info: Loading plugin "webradio"... Jan 28 13:58:40 volumio volumio[20847]: info: Loading plugin "i2s_dacs"... Jan 28 13:58:40 volumio volumio[20847]: info: Loading plugin "volumiodiscovery"... Jan 28 13:58:40 volumio volumio[20847]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 28 13:58:40 volumio volumio[20847]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 13:58:40 volumio node[20847]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 28 13:58:40 volumio volumio[20847]: *** WARNING *** For more information see Jan 28 13:58:40 volumio volumio[20847]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 28 13:58:40 volumio volumio[20847]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 13:58:40 volumio volumio[20847]: *** WARNING *** For more information see Jan 28 13:58:40 volumio node[20847]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 13:58:40 volumio node[20847]: *** WARNING *** For more information see Jan 28 13:58:40 volumio node[20847]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 28 13:58:40 volumio node[20847]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 13:58:40 volumio node[20847]: *** WARNING *** For more information see Jan 28 13:58:40 volumio volumio[20847]: info: Applying required configuration parameters for plugin volumiodiscovery Jan 28 13:58:40 volumio volumio[20847]: info: Discovery: Started advertising with name: Volumio Jan 28 13:58:40 volumio volumio[20847]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 28 13:58:40 volumio volumio[20847]: info: Loading plugin "spop"... Jan 28 13:58:40 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 13:58:40 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 13:58:40 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 13:58:41 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 20. Jan 28 13:58:41 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 13:58:41 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 13:58:41 volumio go-librespot[20923]: go-librespot daemon starting... Jan 28 13:58:41 volumio go-librespot[20924]: time="2026-01-28T13:58:41+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 13:58:41 volumio go-librespot[20924]: time="2026-01-28T13:58:41+07:00" level=debug msg="app state loaded" Jan 28 13:58:41 volumio go-librespot[20924]: time="2026-01-28T13:58:41+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 13:58:41 volumio go-librespot[20924]: time="2026-01-28T13:58:41+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 13:58:41 volumio go-librespot[20924]: time="2026-01-28T13:58:41+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]" Jan 28 13:58:41 volumio go-librespot[20924]: time="2026-01-28T13:58:41+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]" Jan 28 13:58:41 volumio go-librespot[20924]: time="2026-01-28T13:58:41+07:00" level=info msg="zeroconf server listening on port 44481" Jan 28 13:58:42 volumio go-librespot[20924]: time="2026-01-28T13:58:42+07:00" level=debug msg="obtained new client token: AACrt9DhU+OHYATHK5d0aeLq4ydZxuPjDr4ESWyNV4EVxgJaxm+LCWuw65/BQPWc8RvR8TgC9z4v1yk1IHU5PKJ9CrS+1QG3++H3zD+/Fip2+Sb3jCfFoUvDrROvmjfIThdhvLOrtI6MPyAoxny1KaKNkvzcCbmzm8vAVHL7afr3/7hFDkPgLsyOc2ChGa+8BCgxuDbW4ktoa7SAQjOsxd7AQtlcI+AKafQdbRcu+1LsSrX2bDCvmc7T" Jan 28 13:58:42 volumio go-librespot[20924]: time="2026-01-28T13:58:42+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 13:58:42 volumio go-librespot[20924]: time="2026-01-28T13:58:42+07:00" level=debug msg="completed keyexchange" Jan 28 13:58:42 volumio go-librespot[20924]: time="2026-01-28T13:58:42+07:00" level=debug msg="completed challenge" Jan 28 13:58:42 volumio go-librespot[20924]: time="2026-01-28T13:58:42+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 13:58:42 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 13:58:42 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 13:58:42 volumio volumio[20847]: info: Loading plugin "ytcr"... Jan 28 13:58:42 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 13:58:42 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 13:58:42 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 13:58:44 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 13:58:44 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 13:58:44 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 13:58:45 volumio volumio[20847]: info: Loading plugin "ytmusic"... Jan 28 13:58:45 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 21. Jan 28 13:58:45 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 13:58:45 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 13:58:45 volumio go-librespot[20931]: go-librespot daemon starting... Jan 28 13:58:45 volumio go-librespot[20932]: time="2026-01-28T13:58:45+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 13:58:45 volumio go-librespot[20932]: time="2026-01-28T13:58:45+07:00" level=debug msg="app state loaded" Jan 28 13:58:45 volumio go-librespot[20932]: time="2026-01-28T13:58:45+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 13:58:45 volumio volumio-remote-updater[628]: [2026-01-28 13:58:45] [connect] Successful connection Jan 28 13:58:46 volumio go-librespot[20932]: time="2026-01-28T13:58:46+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 28 13:58:46 volumio go-librespot[20932]: time="2026-01-28T13:58:46+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]" Jan 28 13:58:46 volumio go-librespot[20932]: time="2026-01-28T13:58:46+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]" Jan 28 13:58:46 volumio go-librespot[20932]: time="2026-01-28T13:58:46+07:00" level=info msg="zeroconf server listening on port 39703" Jan 28 13:58:46 volumio volumio[20847]: info: Loading plugin "outputs"... Jan 28 13:58:46 volumio volumio[20847]: info: Loading plugin "albumart"... Jan 28 13:58:46 volumio go-librespot[20932]: time="2026-01-28T13:58:46+07:00" level=debug msg="obtained new client token: AAAxKbck/lh4UyXDEo5dA6Dyx8BrHKjb2ev+l0zygTXDj2TzME/u6319laawegZSLQoegar9w9K2MhljNNn+leD8tXw9rXtgypdgl69urMSuswqxrIasmm/DOwSeohQYqva2nBdsePJOd2sOS0B9rOYtay8vDEWuEzRkBBTYi02pFY47IAEfrj3BOcSZe223/rPlDNHbw+K6kJ+wZecW1WgrdTq9dJTB9vC32wuQ1mTtSEmo4VP5KOhT" Jan 28 13:58:46 volumio volumio[20847]: info: Plugin example_plugin is not enabled Jan 28 13:58:46 volumio volumio[20847]: info: Loading plugin "inputs"... Jan 28 13:58:46 volumio volumio[20847]: info: Loading plugin "updater_comm"... Jan 28 13:58:46 volumio go-librespot[20932]: time="2026-01-28T13:58:46+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 13:58:46 volumio go-librespot[20932]: time="2026-01-28T13:58:46+07:00" level=debug msg="completed keyexchange" Jan 28 13:58:46 volumio go-librespot[20932]: time="2026-01-28T13:58:46+07:00" level=debug msg="completed challenge" Jan 28 13:58:46 volumio volumio[20847]: info: Plugin mpdemulation is not enabled Jan 28 13:58:46 volumio volumio[20847]: info: Loading plugin "rest_api"... Jan 28 13:58:46 volumio go-librespot[20932]: time="2026-01-28T13:58:46+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 13:58:46 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 13:58:46 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 13:58:46 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 13:58:46 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 13:58:46 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 13:58:46 volumio volumio[20847]: info: Loading plugin "websocket"... Jan 28 13:58:46 volumio volumio[20847]: info: Starting Socket.io Server version 1.7.4 Jan 28 13:58:46 volumio volumio[20847]: info: Loading plugin "RoonBridge"... Jan 28 13:58:47 volumio volumio[20847]: info: Applying required configuration parameters for plugin RoonBridge Jan 28 13:58:47 volumio volumio[20847]: info: Loading i18n strings for locale en Jan 28 13:58:47 volumio volumio[20847]: Updating browse sources language Jan 28 13:58:47 volumio volumio[20847]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 13:58:47 volumio volumio[20953]: Forking 3 albumart workers Jan 28 13:58:47 volumio volumio[20847]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 28 13:58:47 volumio volumio[20847]: info: CoreCommandRouter::initPlayerControls Jan 28 13:58:47 volumio volumio[20847]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 13:58:47 volumio volumio[20847]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 13:58:47 volumio volumio[20847]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 13:58:47 volumio volumio[20847]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 13:58:47 volumio volumio[20847]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 13:58:47 volumio volumio[20847]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 13:58:47 volumio volumio[20847]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 13:58:47 volumio volumio[20847]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 13:58:47 volumio volumio[20847]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 28 13:58:47 volumio volumio[20847]: Express server listening on port 3000 Jan 28 13:58:47 volumio volumio[20847]: [Metrics] WebUI: 16s 155.37ms Jan 28 13:58:47 volumio volumio[20847]: info: CoreStateMachine::resetVolumioState Jan 28 13:58:47 volumio volumio[20847]: info: CoreStateMachine::getcurrentVolume Jan 28 13:58:47 volumio volumio[20847]: info: CoreCommandRouter::volumioRetrievevolume Jan 28 13:58:47 volumio sudo[20996]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 28 13:58:47 volumio sudo[20996]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 13:58:47 volumio sudo[20996]: pam_unix(sudo:session): session closed for user root Jan 28 13:58:47 volumio sudo[21000]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 28 13:58:47 volumio sudo[21000]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 13:58:47 volumio sudo[21000]: pam_unix(sudo:session): session closed for user root Jan 28 13:58:47 volumio volumio[20847]: info: Volumio Network Manager: Network status updated: 1 Jan 28 13:58:48 volumio volumio[20847]: info: VolumeController:: Volume=100 Mute =false Jan 28 13:58:48 volumio volumio[20847]: info: CoreStateMachine::pushState Jan 28 13:58:48 volumio volumio[20847]: info: CorePlayQueue::getTrack 0 Jan 28 13:58:48 volumio volumio[20847]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 28 13:58:48 volumio volumio[20847]: info: CoreCommandRouter::volumioPushState Jan 28 13:58:48 volumio volumio[20847]: info: CoreStateMachine::updateTrackBlock Jan 28 13:58:48 volumio volumio[20847]: info: CorePlayQueue::getTrackBlock Jan 28 13:58:48 volumio volumio[20847]: info: CoreCommandRouter::volumioRetrievevolume Jan 28 13:58:48 volumio volumio-remote-updater[628]: [2026-01-28 13:58:48] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1769583525 101 Jan 28 13:58:48 volumio volumio[20847]: 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 Jan 28 13:58:48 volumio volumio[20847]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 13:58:48 volumio volumio[20847]: info: Reloading queue from file Jan 28 13:58:48 volumio volumio[20847]: info: CoreStateMachine::setRepeat null single undefined Jan 28 13:58:48 volumio volumio[20847]: info: CoreStateMachine::pushState Jan 28 13:58:48 volumio volumio[20847]: info: CorePlayQueue::getTrack 0 Jan 28 13:58:48 volumio volumio[20847]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 28 13:58:48 volumio volumio[20847]: info: CoreCommandRouter::volumioPushState Jan 28 13:58:48 volumio volumio[20847]: info: CoreStateMachine::setRandom null Jan 28 13:58:48 volumio volumio[20847]: info: CoreStateMachine::pushState Jan 28 13:58:48 volumio volumio[20847]: info: CorePlayQueue::getTrack 0 Jan 28 13:58:48 volumio volumio[20847]: info: CoreCommandRouter::volumioPushState Jan 28 13:58:48 volumio volumio[20847]: info: Setting Device type: Raspberry PI Jan 28 13:58:48 volumio volumio[20847]: info: Completed loading Core Plugins Jan 28 13:58:48 volumio volumio[20847]: info: Preparing to generate the ALSA configuration file Jan 28 13:58:48 volumio volumio[20847]: info: VolumeController:: Volume=100 Mute =false Jan 28 13:58:48 volumio volumio[20847]: info: CoreStateMachine::pushState Jan 28 13:58:48 volumio volumio[20847]: info: CorePlayQueue::getTrack 0 Jan 28 13:58:48 volumio volumio[20847]: info: CoreCommandRouter::volumioPushState Jan 28 13:58:48 volumio volumio[20847]: info: Asound.conf file unchanged, so no further update is needed Jan 28 13:58:48 volumio volumio[20847]: info: Output device has changed, restarting MPD Jan 28 13:58:48 volumio volumio[20847]: info: Output device has changed, restarting Shairport Sync Jan 28 13:58:48 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 13:58:48 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 13:58:48 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 13:58:48 volumio volumio[20847]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 13:58:48 volumio volumio[20847]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 13:58:48 volumio sudo[21015]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Jan 28 13:58:48 volumio sudo[21015]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 13:58:48 volumio sudo[21017]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 28 13:58:48 volumio sudo[21017]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 13:58:48 volumio volumio[20847]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 28 13:58:48 volumio volumio[20847]: info: ___________ START PLUGINS ___________ Jan 28 13:58:48 volumio sudo[21017]: pam_unix(sudo:session): session closed for user root Jan 28 13:58:48 volumio sudo[21019]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 28 13:58:48 volumio volumio[20847]: info: ControllerMpd::onStart: Initializing MPD Jan 28 13:58:48 volumio sudo[21019]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 13:58:48 volumio volumio[20847]: info: Creating MPD Configuration file Jan 28 13:58:48 volumio volumio[20847]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 28 13:58:48 volumio volumio[20847]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 13:58:48 volumio volumio[20847]: info: [1769583528741] CoreMusicLibrary::Adding element Media Servers Jan 28 13:58:48 volumio volumio[20847]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 13:58:48 volumio sudo[21015]: pam_unix(sudo:session): session closed for user root Jan 28 13:58:48 volumio sudo[21028]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 28 13:58:48 volumio sudo[21028]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 13:58:48 volumio sudo[21028]: pam_unix(sudo:session): session closed for user root Jan 28 13:58:48 volumio volumio[20847]: info: UPNP Browser: Client initialized successfully Jan 28 13:58:48 volumio sudo[21030]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 28 13:58:48 volumio sudo[21030]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 13:58:48 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Jan 28 13:58:48 volumio volumio[20847]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 13:58:48 volumio volumio[20847]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 13:58:48 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 28 13:58:48 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 28 13:58:48 volumio systemd[1]: mpd.service: Consumed 7.271s CPU time. Jan 28 13:58:48 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 28 13:58:48 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 28 13:58:48 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 28 13:58:48 volumio volumio[20847]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 28 13:58:48 volumio volumio[20847]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 13:58:48 volumio volumio[20847]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 13:58:49 volumio volumio[20847]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 28 13:58:49 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 28 13:58:49 volumio volumio[20847]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 13:58:49 volumio volumio[20847]: info: [1769583529055] CoreMusicLibrary::Adding element Last_100 Jan 28 13:58:49 volumio volumio[20847]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 13:58:49 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 28 13:58:49 volumio volumio[20847]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 13:58:49 volumio volumio[20847]: info: [1769583529080] CoreMusicLibrary::Adding element Webradio Jan 28 13:58:49 volumio volumio[20847]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 13:58:49 volumio volumio[20847]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 28 13:58:49 volumio volumio[20847]: info: Initializing BBC Radios Jan 28 13:58:49 volumio volumio[20847]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 28 13:58:49 volumio volumio[20847]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 13:58:49 volumio volumio[20847]: info: Creating Spotify config file Jan 28 13:58:49 volumio volumio[20847]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 13:58:49 volumio sudo[21042]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 28 13:58:49 volumio sudo[21042]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jan 28 13:58:49 volumio sudo[21042]: pam_unix(sudo:session): session closed for user root Jan 28 13:58:49 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 22. Jan 28 13:58:49 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 13:58:49 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 13:58:49 volumio go-librespot[21058]: go-librespot daemon starting... Jan 28 13:58:49 volumio go-librespot[21059]: time="2026-01-28T13:58:49+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 13:58:50 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 13:58:50 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 13:58:50 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 13:58:50 volumio go-librespot[21059]: time="2026-01-28T13:58:50+07:00" level=info msg="zeroconf server listening on port 43753" Jan 28 13:58:50 volumio volumio[20964]: Starting albumart workers Jan 28 13:58:50 volumio volumio[20965]: Starting albumart workers Jan 28 13:58:51 volumio volumio[20963]: Starting albumart workers Jan 28 13:58:51 volumio volumio[20847]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 13:58:51 volumio volumio[20847]: info: [1769583531105] CoreMusicLibrary::Adding element YouTube Music Jan 28 13:58:51 volumio volumio[20847]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 13:58:51 volumio volumio[20847]: Cannot find translation for source YouTube Music Jan 28 13:58:51 volumio volumio[20847]: info: Volumio Calling Home Jan 28 13:58:51 volumio sudo[21067]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Jan 28 13:58:51 volumio sudo[21067]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 13:58:51 volumio sudo[21067]: pam_unix(sudo:session): session closed for user root Jan 28 13:58:51 volumio volumio[20847]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Jan 28 13:58:51 volumio volumio[20847]: info: Discovery: Found device Volumio Jan 28 13:58:51 volumio volumio[20847]: info: CoreCommandRouter::volumioGetState Jan 28 13:58:51 volumio volumio[20847]: info: CorePlayQueue::getTrack 0 Jan 28 13:58:51 volumio volumio[20847]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Jan 28 13:58:51 volumio volumio[20847]: info: Discovery: Found device Volumio Jan 28 13:58:51 volumio volumio[20847]: info: CoreCommandRouter::volumioGetState Jan 28 13:58:51 volumio volumio[20847]: info: CorePlayQueue::getTrack 0 Jan 28 13:58:52 volumio volumio[20847]: info: MPD Permissions set Jan 28 13:58:52 volumio volumio[20847]: info: MPD Permissions set Jan 28 13:58:52 volumio volumio[20847]: info: Upmpdcli Daemon Started Jan 28 13:58:52 volumio volumio[20847]: info: Spotify config file written Jan 28 13:58:52 volumio sudo[21073]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jan 28 13:58:52 volumio sudo[21073]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 13:58:52 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Jan 28 13:58:52 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Jan 28 13:58:52 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 13:58:52 volumio volumio[20847]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Jan 28 13:58:52 volumio volumio[20847]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 13:58:52 volumio volumio[20847]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 13:58:52 volumio volumio[20847]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 13:58:52 volumio volumio[20847]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 13:58:52 volumio volumio[20847]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 13:58:52 volumio volumio[20847]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 13:58:52 volumio volumio[20847]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 13:58:52 volumio volumio[20847]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 13:58:52 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 13:58:52 volumio go-librespot[21075]: go-librespot daemon starting... Jan 28 13:58:52 volumio sudo[21073]: pam_unix(sudo:session): session closed for user root Jan 28 13:58:52 volumio volumio[20847]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 13:58:52 volumio volumio[20847]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 13:58:52 volumio volumio[20847]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 13:58:52 volumio volumio[20847]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 13:58:52 volumio volumio[20847]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 13:58:52 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 13:58:52 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 13:58:52 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 13:58:52 volumio volumio[20847]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 13:58:52 volumio volumio[20847]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 13:58:52 volumio volumio[20847]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 13:58:52 volumio volumio[20847]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 13:58:52 volumio volumio[20847]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 13:58:52 volumio go-librespot[21078]: time="2026-01-28T13:58:52+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 13:58:52 volumio go-librespot[21078]: time="2026-01-28T13:58:52+07:00" level=debug msg="app state loaded" Jan 28 13:58:52 volumio volumio[20847]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 13:58:52 volumio go-librespot[21078]: time="2026-01-28T13:58:52+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 13:58:52 volumio volumio[20847]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 13:58:52 volumio volumio[20847]: info: No need to fix Spotify hosts Jan 28 13:58:53 volumio go-librespot[21078]: time="2026-01-28T13:58: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 13:58:53 volumio go-librespot[21078]: time="2026-01-28T13:58:53+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]" Jan 28 13:58:53 volumio go-librespot[21078]: time="2026-01-28T13:58:53+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]" Jan 28 13:58:53 volumio go-librespot[21078]: time="2026-01-28T13:58:53+07:00" level=info msg="zeroconf server listening on port 39555" Jan 28 13:58:53 volumio volumio[20847]: info: Volumio called home Jan 28 13:58:53 volumio go-librespot[21078]: time="2026-01-28T13:58:53+07:00" level=debug msg="obtained new client token: AABNzzrg3L4/asQ3XOaoCKpKgj/hDcK8MnqHjDsWnHo4gNLa6q/o5xeDELHr7Dzk7xXc8wFprV0ksoeodX7vwDOF3E2EaZJstzFNInfAJtPJITPFiU+ALm+kXmgisD3vkbLZMu5M1XddwV57AInWSGSUH/8QU/ecNcPPw/Cg0YzbfRR/2xjTiOFEhFcC0cwD/TAFER72EMToAEAzfz/vaXvDxo4LRt2ko4zzQ6j/iyz9jRe1niQbNLUFSRY=" Jan 28 13:58:53 volumio go-librespot[21078]: time="2026-01-28T13:58:53+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 13:58:53 volumio go-librespot[21078]: time="2026-01-28T13:58:53+07:00" level=debug msg="completed keyexchange" Jan 28 13:58:53 volumio go-librespot[21078]: time="2026-01-28T13:58:53+07:00" level=debug msg="completed challenge" Jan 28 13:58:53 volumio volumio[20847]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 28 13:58:53 volumio volumio[20847]: SPOTIFY: BQDBie9EFv69OK75LhSvjC9E44QYCal-z0RbMWBHdMny2QuRSvG5RcxPQKMl8K054jmjN6sXpxbKnysNFX6UxmWC18e1fIKi7LM2nJPf02OpzTpYi5E0BbJNKahBE2hFhVshLIgbTFJcEkBIz51PL5oPWTF1z4MiFIVjfOaWLFNnKsLN-7hXIjl5MSIKggQukWRm62FEedROX5sO6JcBoesTa6d82rKSmRlrPz_aM_Wxm0r7cdtV9pkV6BJeghD6IPvHRdKbrHiSBVklBapy5tv2KFcF7mfEaD2OH6vdIPi_6ENozd95sgdb Jan 28 13:58:53 volumio volumio[20847]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 28 13:58:53 volumio volumio[20847]: info: New Spotify access token = BQDBie9EFv69OK75LhSvjC9E44QYCal-z0RbMWBHdMny2QuRSvG5RcxPQKMl8K054jmjN6sXpxbKnysNFX6UxmWC18e1fIKi7LM2nJPf02OpzTpYi5E0BbJNKahBE2hFhVshLIgbTFJcEkBIz51PL5oPWTF1z4MiFIVjfOaWLFNnKsLN-7hXIjl5MSIKggQukWRm62FEedROX5sO6JcBoesTa6d82rKSmRlrPz_aM_Wxm0r7cdtV9pkV6BJeghD6IPvHRdKbrHiSBVklBapy5tv2KFcF7mfEaD2OH6vdIPi_6ENozd95sgdb Jan 28 13:58:53 volumio volumio[20847]: info: Spotify credentials grant success - running version from March 24, 2019 Jan 28 13:58:53 volumio go-librespot[21078]: time="2026-01-28T13:58:53+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 " Jan 28 13:58:53 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 13:58:53 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 13:58:53 volumio volumio[20847]: info: Starting Shairport Sync Jan 28 13:58:53 volumio volumio[20847]: info: Starting Shairport Sync Jan 28 13:58:54 volumio volumio[20847]: info: Starting Shairport Sync Jan 28 13:58:54 volumio sudo[21115]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 28 13:58:54 volumio sudo[21115]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 13:58:54 volumio sudo[21117]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 28 13:58:54 volumio sudo[21117]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 13:58:54 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 28 13:58:54 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Jan 28 13:58:54 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 28 13:58:54 volumio systemd[1]: shairport-sync.service: Consumed 2.368s CPU time. Jan 28 13:58:54 volumio sudo[21120]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 28 13:58:54 volumio sudo[21120]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 13:58:54 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 28 13:58:54 volumio volumio[20847]: info: CoreCommandRouter::volumioGetState Jan 28 13:58:54 volumio volumio[20847]: info: CorePlayQueue::getTrack 0 Jan 28 13:58:54 volumio sudo[21115]: pam_unix(sudo:session): session closed for user root Jan 28 13:58:54 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 28 13:58:54 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Jan 28 13:58:54 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 28 13:58:54 volumio volumio[20847]: info: Shairport-Sync Started Jan 28 13:58:54 volumio volumio[20847]: Error adding Membership: Error: addMembership EINVAL Jan 28 13:58:54 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 28 13:58:54 volumio sudo[21117]: pam_unix(sudo:session): session closed for user root Jan 28 13:58:54 volumio sudo[21120]: pam_unix(sudo:session): session closed for user root Jan 28 13:58:54 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 13:58:54 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 13:58:54 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 13:58:54 volumio volumio[20847]: 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"} Jan 28 13:58:54 volumio volumio[20847]: info: Spotify Successfully logged in Jan 28 13:58:54 volumio volumio[20847]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 13:58:54 volumio volumio[20847]: info: [1769583534643] CoreMusicLibrary::Adding element Spotify Jan 28 13:58:54 volumio volumio[20847]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 13:58:54 volumio volumio[20847]: Cannot find translation for source YouTube Music Jan 28 13:58:54 volumio volumio[20847]: Cannot find translation for source Spotify Jan 28 13:58:54 volumio volumio[20847]: info: Shairport-Sync Started Jan 28 13:58:54 volumio volumio[20847]: info: Shairport-Sync Started Jan 28 13:58:55 volumio volumio[20847]: info: [yt-cast-receiver] DIAL server listening on port 8098 Jan 28 13:58:55 volumio volumio[20847]: info: CoreCommandRouter::volumioRetrievevolume Jan 28 13:58:55 volumio volumio[20847]: info: VolumeController:: Volume=100 Mute =false Jan 28 13:58:55 volumio volumio[20847]: info: CoreCommandRouter::volumioGetState Jan 28 13:58:55 volumio volumio[20847]: info: CorePlayQueue::getTrack 0 Jan 28 13:58:55 volumio volumio[20847]: info: CoreStateMachine::pushState Jan 28 13:58:55 volumio volumio[20847]: info: CorePlayQueue::getTrack 0 Jan 28 13:58:55 volumio volumio[20847]: info: CoreCommandRouter::volumioPushState Jan 28 13:58:56 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 13:58:56 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 13:58:56 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 13:58:56 volumio mpd[21057]: 2026-01-28T13:58:56 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 28 13:58:56 volumio systemd[1]: Started mpd.service - Music Player Daemon. Jan 28 13:58:56 volumio sudo[21030]: pam_unix(sudo:session): session closed for user root Jan 28 13:58:56 volumio sudo[21019]: pam_unix(sudo:session): session closed for user root Jan 28 13:58:56 volumio volumio[20847]: info: go-librespot daemon successfully initialized Jan 28 13:58:56 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Jan 28 13:58:56 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 13:58:57 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 13:58:57 volumio go-librespot[21163]: go-librespot daemon starting... Jan 28 13:58:57 volumio go-librespot[21164]: time="2026-01-28T13:58:57+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 13:58:57 volumio go-librespot[21164]: time="2026-01-28T13:58:57+07:00" level=debug msg="app state loaded" Jan 28 13:58:57 volumio volumio[20847]: error: MPD error: The expression evaluated to a falsy value: Jan 28 13:58:57 volumio volumio[20847]: assert.ok(self.idling) Jan 28 13:58:57 volumio volumio[20847]: error: The expression evaluated to a falsy value: Jan 28 13:58:57 volumio volumio[20847]: assert.ok(self.idling) Jan 28 13:58:57 volumio go-librespot[21164]: time="2026-01-28T13:58:57+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 13:58:57 volumio volumio[20847]: error: updateQueue error: null Jan 28 13:58:57 volumio volumio[20847]: info: Completed starting Core Plugins Jan 28 13:58:57 volumio volumio[20847]: info: ------------------------------------------- Jan 28 13:58:57 volumio volumio[20847]: info: ----- MyVolumio plugins startup ---- Jan 28 13:58:57 volumio volumio[20847]: info: ------------------------------------------- Jan 28 13:58:57 volumio volumio[20847]: info: [MyVolumio PluginManager] Fetching plans data.... Jan 28 13:58:57 volumio volumio[20847]: info: MPD running with PID21057 Jan 28 13:58:57 volumio volumio[20847]: ,establishing connection Jan 28 13:58:57 volumio volumio[20847]: error: updateQueue error: null Jan 28 13:58:57 volumio go-librespot[21164]: time="2026-01-28T13:58:57+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 13:58:57 volumio go-librespot[21164]: time="2026-01-28T13:58:57+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]" Jan 28 13:58:57 volumio go-librespot[21164]: time="2026-01-28T13:58:57+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]" Jan 28 13:58:57 volumio go-librespot[21164]: time="2026-01-28T13:58:57+07:00" level=info msg="zeroconf server listening on port 43825" Jan 28 13:58:57 volumio go-librespot[21164]: time="2026-01-28T13:58:57+07:00" level=debug msg="obtained new client token: AADHSaTxZ9AMnu/NIGzC/CuyOUsvouZaUUpe418PBjSMMmykyIuaefTmN01BrYwp/oUbtnqJNpQnqRyQwqFjIN7RbNrpY1smL3tqXEvTfJyHuKglfihyn7Y126hl59Ktqzg/8UkeyigD+zCJhBOQXybeOGpT+ks8SSIhEexHIvNfGI7AEeUz03oK+gi/pYJFWPW//W80PPg+HW9yvLPvIbXhdYIi1pI55uXL0Zby5or76fqFlzktE2PutzY=" Jan 28 13:58:57 volumio go-librespot[21164]: time="2026-01-28T13:58:57+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 13:58:58 volumio go-librespot[21164]: time="2026-01-28T13:58:58+07:00" level=debug msg="completed keyexchange" Jan 28 13:58:58 volumio go-librespot[21164]: time="2026-01-28T13:58:58+07:00" level=debug msg="completed challenge" Jan 28 13:58:58 volumio go-librespot[21164]: time="2026-01-28T13:58: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 " Jan 28 13:58:58 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 13:58:58 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 13:58:58 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 13:58:58 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 13:58:58 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 13:58:59 volumio volumio[20847]: info: Initializing connection to go-librespot Websocket Jan 28 13:58:59 volumio volumio[20847]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 28 13:59:00 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 13:59:00 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 13:59:00 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 13:59:01 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Jan 28 13:59:01 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 13:59:01 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 13:59:01 volumio go-librespot[21171]: go-librespot daemon starting... Jan 28 13:59:01 volumio go-librespot[21172]: time="2026-01-28T13:59:01+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 13:59:01 volumio go-librespot[21172]: time="2026-01-28T13:59:01+07:00" level=debug msg="app state loaded" Jan 28 13:59:01 volumio go-librespot[21172]: time="2026-01-28T13:59:01+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 13:59:01 volumio go-librespot[21172]: time="2026-01-28T13:59:01+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 13:59:01 volumio go-librespot[21172]: time="2026-01-28T13:59:01+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]" Jan 28 13:59:01 volumio go-librespot[21172]: time="2026-01-28T13:59:01+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]" Jan 28 13:59:01 volumio go-librespot[21172]: time="2026-01-28T13:59:01+07:00" level=info msg="zeroconf server listening on port 34355" Jan 28 13:59:01 volumio volumio[20847]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Jan 28 13:59:02 volumio go-librespot[21172]: time="2026-01-28T13:59:02+07:00" level=debug msg="obtained new client token: AABmM4+LZC+/aC8vsnUKDkrVfJChdiuwlhjB52LhorTdP97YFjUpS55IyNBIJvONV9a7j+Gk//IN17UrMlfjxGV2KUFf5fAKz6tyO7rx/FkwsmrWvrZdDhlQdDCE1uAQWZhrmvGn1gkrNElbgen4ePEzhs/sbPzxAqHPeY4u5xOwSJCRLd1ZA0AMnm8sTutIyDpakWwYEJ4Rd8ENh4RHQP2iqqMGXs7aENd/lR1LpbfdApePXUKwKNQJ" Jan 28 13:59:02 volumio go-librespot[21172]: time="2026-01-28T13:59:02+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 13:59:02 volumio go-librespot[21172]: time="2026-01-28T13:59:02+07:00" level=debug msg="completed keyexchange" Jan 28 13:59:02 volumio go-librespot[21172]: time="2026-01-28T13:59:02+07:00" level=debug msg="completed challenge" Jan 28 13:59:02 volumio go-librespot[21172]: time="2026-01-28T13:59: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 " Jan 28 13:59:02 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 13:59:02 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 13:59:02 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 13:59:02 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 13:59:02 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 13:59:02 volumio volumio[20847]: info: Initializing connection to go-librespot Websocket Jan 28 13:59:02 volumio volumio[20847]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 28 13:59:04 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 13:59:04 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 13:59:04 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 13:59:05 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Jan 28 13:59:05 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 13:59:05 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 13:59:05 volumio go-librespot[21179]: go-librespot daemon starting... Jan 28 13:59:05 volumio go-librespot[21180]: time="2026-01-28T13:59:05+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 13:59:05 volumio go-librespot[21180]: time="2026-01-28T13:59:05+07:00" level=debug msg="app state loaded" Jan 28 13:59:05 volumio go-librespot[21180]: time="2026-01-28T13:59:05+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 13:59:05 volumio volumio[20847]: info: Initializing connection to go-librespot Websocket Jan 28 13:59:05 volumio go-librespot[21180]: time="2026-01-28T13:59:05+07:00" level=debug msg="new websocket client" Jan 28 13:59:05 volumio volumio[20847]: info: Connection to go-librespot Websocket established Jan 28 13:59:05 volumio volumio[20847]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Jan 28 13:59:05 volumio volumio[20847]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Jan 28 13:59:05 volumio volumio[20847]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Jan 28 13:59:05 volumio volumio[20847]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Jan 28 13:59:05 volumio volumio[20847]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Jan 28 13:59:05 volumio volumio[20847]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Jan 28 13:59:05 volumio volumio[20847]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Jan 28 13:59:05 volumio volumio[20847]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Jan 28 13:59:05 volumio volumio[20847]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Jan 28 13:59:05 volumio volumio[20847]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Jan 28 13:59:05 volumio volumio[20847]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Jan 28 13:59:05 volumio volumio[20847]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Jan 28 13:59:05 volumio volumio[20847]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Jan 28 13:59:05 volumio volumio[20847]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Jan 28 13:59:05 volumio volumio[20847]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Jan 28 13:59:05 volumio volumio[20847]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Jan 28 13:59:05 volumio volumio[20847]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Jan 28 13:59:05 volumio volumio[20847]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Jan 28 13:59:05 volumio volumio[20847]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Jan 28 13:59:05 volumio volumio[20847]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Jan 28 13:59:05 volumio volumio[20847]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Jan 28 13:59:05 volumio volumio[20847]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Jan 28 13:59:05 volumio volumio[20847]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Jan 28 13:59:05 volumio volumio[20847]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Jan 28 13:59:05 volumio volumio[20847]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Jan 28 13:59:05 volumio volumio[20847]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Jan 28 13:59:05 volumio volumio[20847]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Jan 28 13:59:05 volumio volumio[20847]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Jan 28 13:59:06 volumio volumio[20847]: info: Adding plugin bluetooth to MyMusic Plugins Jan 28 13:59:06 volumio volumio[20847]: info: Adding plugin multiroom to MyMusic Plugins Jan 28 13:59:06 volumio volumio[20847]: info: Adding plugin metavolumio to MyMusic Plugins Jan 28 13:59:06 volumio volumio[20847]: info: Adding plugin cd_controller to MyMusic Plugins Jan 28 13:59:06 volumio volumio[20847]: info: Adding plugin qobuzconnect to MyMusic Plugins Jan 28 13:59:06 volumio volumio[20847]: info: Adding plugin smart_inputs to MyMusic Plugins Jan 28 13:59:06 volumio volumio[20847]: info: Adding plugin tidalconnect to MyMusic Plugins Jan 28 13:59:06 volumio volumio[20847]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Jan 28 13:59:06 volumio go-librespot[21180]: time="2026-01-28T13:59: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]" Jan 28 13:59:06 volumio go-librespot[21180]: time="2026-01-28T13:59: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]" Jan 28 13:59:06 volumio go-librespot[21180]: time="2026-01-28T13:59: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]" Jan 28 13:59:06 volumio go-librespot[21180]: time="2026-01-28T13:59:06+07:00" level=info msg="zeroconf server listening on port 39595" Jan 28 13:59:06 volumio go-librespot[21180]: time="2026-01-28T13:59:06+07:00" level=debug msg="obtained new client token: AAB5KZg+ABnXbE0Unhwnn3oAxVq6x1wnKTTx7y0PkOhik+JHOLya20ZcLsaadfUMpi1ddspXmnEXdZUXXy3lKWS41Sy+rEPi7ekTYL5ObcfX+tXw5F1oM1kQuHSizuRBKpmYZJZw5De1jNizpgTwVl2LagFGGlO1BMZRXtjEIkjw+KbOjpnZ9OGBCGH2Cl1BK7MUWOWmfQvFFuSzh36sIhLsRElkbIYMjiLdGhCfF5jkNEL0uDkpjrWt2R4=" Jan 28 13:59:06 volumio go-librespot[21180]: time="2026-01-28T13:59:06+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 13:59:06 volumio go-librespot[21180]: time="2026-01-28T13:59:06+07:00" level=debug msg="completed keyexchange" Jan 28 13:59:06 volumio go-librespot[21180]: time="2026-01-28T13:59:06+07:00" level=debug msg="completed challenge" Jan 28 13:59:06 volumio go-librespot[21180]: time="2026-01-28T13:59:06+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 " Jan 28 13:59:06 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 13:59:06 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 13:59:06 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 13:59:06 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 13:59:06 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 13:59:07 volumio volumio[20847]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Jan 28 13:59:08 volumio volumio[20847]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Jan 28 13:59:08 volumio volumio[20847]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 13:59:08 volumio volumio[20847]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 13:59:08 volumio volumio[20847]: info: Starting MyVolumio Remote Streaming Endpoints Jan 28 13:59:08 volumio volumio[20847]: info: MyVolumio login type: Token Jan 28 13:59:08 volumio volumio[20847]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Jan 28 13:59:08 volumio volumio[20847]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Jan 28 13:59:08 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 13:59:08 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 13:59:08 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 13:59:09 volumio volumio[20847]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Jan 28 13:59:09 volumio volumio[20847]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Jan 28 13:59:09 volumio volumio[20847]: info: Streaming services startup Jan 28 13:59:09 volumio volumio[20847]: info: Starting Streaming Daemon Jan 28 13:59:09 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Jan 28 13:59:09 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 13:59:09 volumio sudo[21204]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jan 28 13:59:09 volumio sudo[21204]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 13:59:09 volumio volumio[20847]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Jan 28 13:59:09 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 13:59:09 volumio go-librespot[21207]: go-librespot daemon starting... Jan 28 13:59:09 volumio sudo[21204]: pam_unix(sudo:session): session closed for user root Jan 28 13:59:09 volumio go-librespot[21211]: time="2026-01-28T13:59:09+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 13:59:09 volumio go-librespot[21211]: time="2026-01-28T13:59:09+07:00" level=debug msg="app state loaded" Jan 28 13:59:09 volumio go-librespot[21211]: time="2026-01-28T13:59:09+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 13:59:09 volumio volumio[20847]: info: Getting Spotify volume Jan 28 13:59:09 volumio volumio[20847]: info: Connection to go-librespot Websocket closed Jan 28 13:59:09 volumio volumio[20847]: error: Cannot start Volumio Streaming Daemon Jan 28 13:59:09 volumio volumio[20847]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Jan 28 13:59:09 volumio volumio[20847]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Jan 28 13:59:10 volumio volumio[20847]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Jan 28 13:59:10 volumio volumio[20847]: info: CoreCommandRouter::volumioGetState Jan 28 13:59:10 volumio volumio[20847]: info: CorePlayQueue::getTrack 0 Jan 28 13:59:10 volumio volumio[20847]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jan 28 13:59:10 volumio volumio[20847]: SPOTIFY: SPOTIFY VOLUME undefined Jan 28 13:59:10 volumio volumio[20847]: SPOTIFY: VOLUMIO VOLUME 100 Jan 28 13:59:10 volumio volumio[20847]: info: Aligning Spotify Volume to Volumio Volume Jan 28 13:59:10 volumio volumio[20847]: info: CoreCommandRouter::volumioGetState Jan 28 13:59:10 volumio volumio[20847]: info: CorePlayQueue::getTrack 0 Jan 28 13:59:10 volumio volumio[20847]: info: Setting Spotify Volume from Volumio: 100 Jan 28 13:59:10 volumio go-librespot[21211]: time="2026-01-28T13:59: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]" Jan 28 13:59:10 volumio go-librespot[21211]: time="2026-01-28T13:59: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]" Jan 28 13:59:10 volumio go-librespot[21211]: time="2026-01-28T13:59: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]" Jan 28 13:59:10 volumio go-librespot[21211]: time="2026-01-28T13:59:10+07:00" level=info msg="zeroconf server listening on port 39025" Jan 28 13:59:10 volumio go-librespot[21211]: time="2026-01-28T13:59:10+07:00" level=debug msg="obtained new client token: AAAGDotzAWQjIS9MqYVBztI4KK+T7xLBq70zDDkdYQFIM6silzV063itJ3L695b+avd3LzGnjDiY3IrisxP2cW5I83blpWutkg39tbpk9+amH71dffy9al/UnCiuYVBRhJncyR2wxaBFKzkKCsr9H0wn3s0p4ZRZO87KHDQwrCeaJ9yJ3CYX8dNgWm9Z+cxkwFPn7jmtYFG9hh2PciAw56t6510rQpWcnBMWDrQ4pfnb2y5vmoWEHcWkPeE=" Jan 28 13:59:10 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 13:59:10 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 13:59:10 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 13:59:10 volumio go-librespot[21211]: time="2026-01-28T13:59:10+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 13:59:10 volumio go-librespot[21211]: time="2026-01-28T13:59:10+07:00" level=debug msg="completed keyexchange" Jan 28 13:59:10 volumio go-librespot[21211]: time="2026-01-28T13:59:10+07:00" level=debug msg="completed challenge" Jan 28 13:59:10 volumio go-librespot[21211]: time="2026-01-28T13:59:10+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 13:59:10 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 13:59:10 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 13:59:10 volumio volumio[20847]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 28 13:59:10 volumio volumio[20847]: Error: socket hang up Jan 28 13:59:10 volumio volumio[20847]: at connResetException (node:internal/errors:720:14) Jan 28 13:59:10 volumio volumio[20847]: at Socket.socketOnEnd (node:_http_client:519:23) Jan 28 13:59:10 volumio volumio[20847]: at Socket.emit (node:events:526:35) Jan 28 13:59:10 volumio volumio[20847]: at endReadableNT (node:internal/streams/readable:1376:12) Jan 28 13:59:10 volumio volumio[20847]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Jan 28 13:59:10 volumio volumio[20847]: code: 'ECONNRESET', Jan 28 13:59:10 volumio volumio[20847]: response: undefined Jan 28 13:59:10 volumio volumio[20847]: } Jan 28 13:59:10 volumio volumio[20847]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 28 13:59:12 volumio sudo[21233]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-01-28 13:58' Jan 28 13:59:12 volumio sudo[21233]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 13:59:12 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 13:59:12 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 13:59:12 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 13:59:12 volumio sudo[21233]: pam_unix(sudo:session): session closed for user root Jan 28 13:59:12 volumio volumio-remote-updater[628]: [2026-01-28 13:59:12] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Jan 28 13:59:12 volumio volumio-remote-updater[628]: [2026-01-28 13:59:12] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Jan 28 13:59:12 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Jan 28 13:59:12 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Jan 28 13:59:12 volumio systemd[1]: volumio.service: Consumed 59.087s CPU time. Jan 28 13:59:12 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 28 13:59:12 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Jan 28 13:59:12 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 10228. Jan 28 13:59:12 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 28 13:59:12 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Jan 28 13:59:12 volumio systemd[1]: volumio.service: Consumed 59.087s CPU time. Jan 28 13:59:12 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Jan 28 13:59:12 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Jan 28 13:59:13 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Jan 28 13:59:13 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 13:59:14 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 13:59:14 volumio go-librespot[21260]: go-librespot daemon starting... Jan 28 13:59:14 volumio go-librespot[21261]: time="2026-01-28T13:59:14+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 13:59:14 volumio go-librespot[21261]: time="2026-01-28T13:59:14+07:00" level=debug msg="app state loaded" Jan 28 13:59:14 volumio go-librespot[21261]: time="2026-01-28T13:59:14+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 13:59:14 volumio go-librespot[21261]: time="2026-01-28T13:59:14+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 13:59:14 volumio go-librespot[21261]: time="2026-01-28T13:59:14+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]" Jan 28 13:59:14 volumio go-librespot[21261]: time="2026-01-28T13:59:14+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]" Jan 28 13:59:14 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 13:59:14 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 13:59:14 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 13:59:14 volumio go-librespot[21261]: time="2026-01-28T13:59:14+07:00" level=info msg="zeroconf server listening on port 43399" Jan 28 13:59:14 volumio go-librespot[21261]: time="2026-01-28T13:59:14+07:00" level=debug msg="obtained new client token: AAByRVplsy82l2dHzVcpN6tA9OhkHFJHomXXSSh7bFq+4pWKUoVHZVA67s9jf9top99215RoZY0XRUPJ2jXhPzvMlMIgZ8FO4CAYUzjiJr21ynNct9iiGNucKPW5bwK5amltc9tWe1bwfowYjuFPIHNRdKEFEyFMclt43eGBLSRn8Jif1tlEo2ZRF3OyfstX5/gySDTiCxv0MKXGgeSpDSiQCsPrcW/rYqirZkEdw4KmmnUK3gcFq79PIZw=" Jan 28 13:59:15 volumio go-librespot[21261]: time="2026-01-28T13:59:15+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" Jan 28 13:59:15 volumio go-librespot[21261]: time="2026-01-28T13:59:15+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Jan 28 13:59:15 volumio go-librespot[21261]: time="2026-01-28T13:59:15+07:00" level=debug msg="completed keyexchange" Jan 28 13:59:15 volumio go-librespot[21261]: time="2026-01-28T13:59:15+07:00" level=debug msg="completed challenge" Jan 28 13:59:15 volumio go-librespot[21261]: time="2026-01-28T13:59: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 " Jan 28 13:59:15 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 13:59:15 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 13:59:16 volumio volumio[21245]: info: ------------------------------------------- Jan 28 13:59:16 volumio volumio[21245]: info: ----- Volumio3 ---- Jan 28 13:59:16 volumio volumio[21245]: info: ------------------------------------------- Jan 28 13:59:16 volumio volumio[21245]: info: ----- System startup ---- Jan 28 13:59:16 volumio volumio[21245]: info: ------------------------------------------- Jan 28 13:59:16 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 13:59:16 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 13:59:16 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 13:59:17 volumio volumio-remote-updater[628]: [2026-01-28 13:59:17] [connect] Successful connection Jan 28 13:59:17 volumio volumio[21245]: info: MYVOLUMIO Environment detected Jan 28 13:59:18 volumio volumio[21245]: info: Plugin folders cleanup Jan 28 13:59:18 volumio volumio[21245]: info: Scanning into folder /volumio/app/plugins/ Jan 28 13:59:18 volumio volumio[21245]: info: Scanning category audio_interface Jan 28 13:59:18 volumio volumio[21245]: info: Scanning category miscellanea Jan 28 13:59:18 volumio volumio[21245]: info: Scanning category music_service Jan 28 13:59:18 volumio volumio[21245]: info: Scanning category plugins.json Jan 28 13:59:18 volumio volumio[21245]: info: Scanning category system_controller Jan 28 13:59:18 volumio volumio[21245]: info: Scanning category user_interface Jan 28 13:59:18 volumio volumio[21245]: info: Scanning into folder /data/plugins/ Jan 28 13:59:18 volumio volumio[21245]: info: Scanning category music_service Jan 28 13:59:18 volumio volumio[21245]: info: Plugin folders cleanup completed Jan 28 13:59:18 volumio volumio[21245]: info: ------------------------------------------- Jan 28 13:59:18 volumio volumio[21245]: info: ----- Core plugins startup ---- Jan 28 13:59:18 volumio volumio[21245]: info: ------------------------------------------- Jan 28 13:59:18 volumio volumio[21245]: info: Loading plugins from folder /volumio/app/plugins/ Jan 28 13:59:18 volumio volumio[21245]: info: Adding plugin upnp to MyMusic Plugins Jan 28 13:59:18 volumio volumio[21245]: info: Adding plugin airplay_emulation to MyMusic Plugins Jan 28 13:59:18 volumio volumio[21245]: info: Adding plugin upnp_browser to MyMusic Plugins Jan 28 13:59:18 volumio volumio[21245]: info: Loading plugins from folder /data/plugins/ Jan 28 13:59:18 volumio volumio[21245]: info: Loading plugin "system"... Jan 28 13:59:18 volumio volumio[21245]: info: Loading plugin "appearance"... Jan 28 13:59:18 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Jan 28 13:59:18 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 13:59:18 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 13:59:18 volumio go-librespot[21281]: go-librespot daemon starting... Jan 28 13:59:18 volumio go-librespot[21282]: time="2026-01-28T13:59:18+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 13:59:18 volumio go-librespot[21282]: time="2026-01-28T13:59:18+07:00" level=debug msg="app state loaded" Jan 28 13:59:18 volumio go-librespot[21282]: time="2026-01-28T13:59:18+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 13:59:18 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 13:59:18 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 13:59:18 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 13:59:19 volumio go-librespot[21282]: time="2026-01-28T13:59: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 13:59:19 volumio go-librespot[21282]: time="2026-01-28T13:59:19+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]" Jan 28 13:59:19 volumio go-librespot[21282]: time="2026-01-28T13:59:19+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]" Jan 28 13:59:19 volumio go-librespot[21282]: time="2026-01-28T13:59:19+07:00" level=info msg="zeroconf server listening on port 32895" Jan 28 13:59:19 volumio go-librespot[21282]: time="2026-01-28T13:59:19+07:00" level=debug msg="obtained new client token: AADiW816bs1uyGYCWcJaRz4kY0trH1nsdNczkhYVDZeHx99aLKv8m2K0sBbbATTKyRddz+1l0oEY/f4Yiepk80QIHhTHV/RD5VV1AvdLa+feouJn+0vJMoqbEX3YmiuQP+arLA+75oNHf3X/76xNj6tHCx6Ydh25dmkgZHYC7WVWHnCQp4vwoTB4z/wwTqVRamwetGJcTUYs+rGQNrzhgqQkrRHxVu6/Ee30pCO14yrelKm3JyKYTToPJlQ=" Jan 28 13:59:19 volumio go-librespot[21282]: time="2026-01-28T13:59:19+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" Jan 28 13:59:19 volumio go-librespot[21282]: time="2026-01-28T13:59:19+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Jan 28 13:59:19 volumio go-librespot[21282]: time="2026-01-28T13:59:19+07:00" level=debug msg="completed keyexchange" Jan 28 13:59:19 volumio go-librespot[21282]: time="2026-01-28T13:59:19+07:00" level=debug msg="completed challenge" Jan 28 13:59:19 volumio go-librespot[21282]: time="2026-01-28T13:59:19+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 13:59:19 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 13:59:19 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 13:59:20 volumio volumio[21245]: info: Loading plugin "network"... Jan 28 13:59:20 volumio volumio[21245]: info: Refreshing Cached IP Addresses Jan 28 13:59:20 volumio sudo[21290]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 28 13:59:20 volumio sudo[21290]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 13:59:20 volumio sudo[21292]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 28 13:59:20 volumio sudo[21292]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 13:59:20 volumio sudo[21290]: pam_unix(sudo:session): session closed for user root Jan 28 13:59:20 volumio sudo[21292]: pam_unix(sudo:session): session closed for user root Jan 28 13:59:20 volumio volumio[21245]: info: Loading plugin "services"... Jan 28 13:59:20 volumio volumio[21245]: info: Loading plugin "alsa_controller"... Jan 28 13:59:20 volumio sudo[21301]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Jan 28 13:59:20 volumio sudo[21301]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 13:59:20 volumio volumio[21245]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 28 13:59:20 volumio volumio[21245]: info: Loading plugin "wizard"... Jan 28 13:59:20 volumio volumio[21245]: info: Loading plugin "networkfs"... Jan 28 13:59:20 volumio volumio[21245]: info: Starting Udev Watcher for removable devices Jan 28 13:59:20 volumio volumio[21245]: info: Ignoring mount for partition: boot Jan 28 13:59:20 volumio volumio[21245]: info: Ignoring mount for partition: volumio Jan 28 13:59:20 volumio volumio[21245]: info: Ignoring mount for partition: volumio_data Jan 28 13:59:20 volumio volumio[21245]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 28 13:59:20 volumio volumio[21245]: info: Loading plugin "volumio_command_line_client"... Jan 28 13:59:20 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 13:59:20 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 13:59:20 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 13:59:20 volumio volumio[21245]: info: Loading plugin "upnp"... Jan 28 13:59:20 volumio volumio[21245]: info: [1769583560650] Starting Upmpd Daemon Jan 28 13:59:20 volumio volumio[21245]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 28 13:59:20 volumio volumio[21245]: info: Loading plugin "my_music"... Jan 28 13:59:20 volumio volumio[21245]: info: Loading plugin "mpd"... Jan 28 13:59:21 volumio volumio[21245]: info: Loading plugin "upnp_browser"... Jan 28 13:59:22 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 13:59:22 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 13:59:22 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 13:59:22 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Jan 28 13:59:22 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 13:59:22 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 13:59:22 volumio go-librespot[21323]: go-librespot daemon starting... Jan 28 13:59:22 volumio go-librespot[21324]: time="2026-01-28T13:59:22+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 13:59:22 volumio go-librespot[21324]: time="2026-01-28T13:59:22+07:00" level=debug msg="app state loaded" Jan 28 13:59:22 volumio go-librespot[21324]: time="2026-01-28T13:59:22+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 13:59:23 volumio sudo[21301]: pam_unix(sudo:session): session closed for user root Jan 28 13:59:23 volumio go-librespot[21324]: time="2026-01-28T13:59: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 13:59:23 volumio go-librespot[21324]: time="2026-01-28T13:59:23+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]" Jan 28 13:59:23 volumio go-librespot[21324]: time="2026-01-28T13:59:23+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]" Jan 28 13:59:23 volumio go-librespot[21324]: time="2026-01-28T13:59:23+07:00" level=info msg="zeroconf server listening on port 34095" Jan 28 13:59:23 volumio go-librespot[21324]: time="2026-01-28T13:59:23+07:00" level=debug msg="obtained new client token: AACpQ7JzK9KHSbBy8vab/P0egnXwucntljjqtLvVHiK3jYKciO1gWrcxMU+o6rWrJbuHncYE46dBO/zkIRMG/SG52QZARchtuknRtPfZk7QWweqOkCh3OmTJQSPzWg4BPvp9sNfcwCgv14Z0unXcnPWg5fKxC+NdTkGvF8wC+YdZh7KNYVmlEebbBZc1EEAqZXO/hGTPI2k0gDMJgx+Y9li1vByy/Ahiw6qakqfAuTiPyqCzzy2qG14IAWg=" Jan 28 13:59:23 volumio go-librespot[21324]: time="2026-01-28T13:59:23+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 13:59:23 volumio go-librespot[21324]: time="2026-01-28T13:59:23+07:00" level=debug msg="completed keyexchange" Jan 28 13:59:23 volumio go-librespot[21324]: time="2026-01-28T13:59:23+07:00" level=debug msg="completed challenge" Jan 28 13:59:23 volumio go-librespot[21324]: time="2026-01-28T13:59:23+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 " Jan 28 13:59:23 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 13:59:23 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 13:59:24 volumio volumio[21245]: info: Starting UPNP Browser Jan 28 13:59:24 volumio volumio[21245]: info: Loading plugin "alarm-clock"... Jan 28 13:59:24 volumio volumio[21245]: info: Loading plugin "airplay_emulation"... Jan 28 13:59:24 volumio volumio[21245]: info: Starting Shairport Sync Jan 28 13:59:24 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 13:59:24 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 13:59:24 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 13:59:24 volumio volumio[21245]: info: Loading plugin "last_100"... Jan 28 13:59:24 volumio volumio[21245]: info: Loading plugin "webradio"... Jan 28 13:59:24 volumio volumio[21245]: info: Loading plugin "i2s_dacs"... Jan 28 13:59:24 volumio volumio[21245]: info: Loading plugin "volumiodiscovery"... Jan 28 13:59:24 volumio volumio[21245]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 28 13:59:24 volumio volumio[21245]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 13:59:24 volumio node[21245]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 28 13:59:24 volumio volumio[21245]: *** WARNING *** For more information see Jan 28 13:59:24 volumio volumio[21245]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 28 13:59:24 volumio volumio[21245]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 13:59:24 volumio volumio[21245]: *** WARNING *** For more information see Jan 28 13:59:24 volumio node[21245]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 13:59:24 volumio node[21245]: *** WARNING *** For more information see Jan 28 13:59:24 volumio node[21245]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 28 13:59:24 volumio node[21245]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 13:59:24 volumio node[21245]: *** WARNING *** For more information see Jan 28 13:59:24 volumio volumio[21245]: info: Applying required configuration parameters for plugin volumiodiscovery Jan 28 13:59:24 volumio volumio[21245]: info: Discovery: Started advertising with name: Volumio Jan 28 13:59:24 volumio volumio[21245]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 28 13:59:25 volumio volumio[21245]: info: Loading plugin "spop"... Jan 28 13:59:26 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 13:59:26 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 13:59:26 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 13:59:26 volumio volumio[21245]: info: Loading plugin "ytcr"... Jan 28 13:59:26 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Jan 28 13:59:26 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 13:59:27 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 13:59:27 volumio go-librespot[21333]: go-librespot daemon starting... Jan 28 13:59:27 volumio go-librespot[21334]: time="2026-01-28T13:59:27+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 13:59:27 volumio go-librespot[21334]: time="2026-01-28T13:59:27+07:00" level=debug msg="app state loaded" Jan 28 13:59:27 volumio go-librespot[21334]: time="2026-01-28T13:59:27+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 13:59:27 volumio go-librespot[21334]: time="2026-01-28T13:59:27+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 13:59:27 volumio go-librespot[21334]: time="2026-01-28T13:59:27+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 28 13:59:27 volumio go-librespot[21334]: time="2026-01-28T13:59:27+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 28 13:59:27 volumio go-librespot[21334]: time="2026-01-28T13:59:27+07:00" level=info msg="zeroconf server listening on port 37755" Jan 28 13:59:27 volumio go-librespot[21334]: time="2026-01-28T13:59:27+07:00" level=debug msg="obtained new client token: AABC+juQi9NWvJLCMi68wF1kIZ5j+nygAUGYE91aixGbOuPPQTk6sxjipPuyOPQLBrv9++QNUPSzpqBLbDsfiShCXX5rM9BVRwlUoEm0vF3zDYqPxiRXtYlgXJLsLrLmFAiz8906n+ijpXLe/Ua+EBy18uKtUHqLcdYp5eGD8oDKZ8Yx1ItNEqo7sIci+ERrZBJNgfPj9wkTzvp+WPt3O12qunHvN9hi+P4QmmxHM8q5Mk9bTxO5lZeji+8=" Jan 28 13:59:27 volumio go-librespot[21334]: time="2026-01-28T13:59:27+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 13:59:27 volumio go-librespot[21334]: time="2026-01-28T13:59:27+07:00" level=debug msg="completed keyexchange" Jan 28 13:59:27 volumio go-librespot[21334]: time="2026-01-28T13:59:27+07:00" level=debug msg="completed challenge" Jan 28 13:59:28 volumio go-librespot[21334]: time="2026-01-28T13:59: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 " Jan 28 13:59:28 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 13:59:28 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 13:59:28 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 13:59:28 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 13:59:28 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 13:59:29 volumio volumio[21245]: info: Loading plugin "ytmusic"... Jan 28 13:59:30 volumio volumio-remote-updater[628]: [2026-01-28 13:59:30] [connect] Successful connection Jan 28 13:59:30 volumio volumio[21245]: info: Loading plugin "outputs"... Jan 28 13:59:30 volumio volumio[21245]: info: Loading plugin "albumart"... Jan 28 13:59:30 volumio volumio[21245]: info: Plugin example_plugin is not enabled Jan 28 13:59:30 volumio volumio[21245]: info: Loading plugin "inputs"... Jan 28 13:59:30 volumio volumio[21245]: info: Loading plugin "updater_comm"... Jan 28 13:59:30 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 13:59:30 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 13:59:30 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 13:59:30 volumio volumio[21245]: info: Plugin mpdemulation is not enabled Jan 28 13:59:30 volumio volumio[21245]: info: Loading plugin "rest_api"... Jan 28 13:59:30 volumio volumio[21245]: info: Loading plugin "websocket"... Jan 28 13:59:30 volumio volumio[21245]: info: Starting Socket.io Server version 1.7.4 Jan 28 13:59:30 volumio volumio[21245]: info: Loading plugin "RoonBridge"... Jan 28 13:59:31 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Jan 28 13:59:31 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 13:59:31 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 13:59:31 volumio go-librespot[21367]: go-librespot daemon starting... Jan 28 13:59:31 volumio go-librespot[21368]: time="2026-01-28T13:59:31+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 13:59:31 volumio go-librespot[21368]: time="2026-01-28T13:59:31+07:00" level=debug msg="app state loaded" Jan 28 13:59:31 volumio go-librespot[21368]: time="2026-01-28T13:59:31+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 13:59:31 volumio volumio[21245]: info: Applying required configuration parameters for plugin RoonBridge Jan 28 13:59:31 volumio volumio[21245]: info: Loading i18n strings for locale en Jan 28 13:59:31 volumio volumio[21245]: Updating browse sources language Jan 28 13:59:31 volumio volumio[21245]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 13:59:31 volumio volumio[21357]: Forking 3 albumart workers Jan 28 13:59:31 volumio volumio[21245]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 28 13:59:31 volumio volumio[21245]: info: CoreCommandRouter::initPlayerControls Jan 28 13:59:31 volumio volumio[21245]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 13:59:31 volumio volumio[21245]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 13:59:31 volumio volumio[21245]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 13:59:31 volumio volumio[21245]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 13:59:31 volumio volumio[21245]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 13:59:31 volumio volumio[21245]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 13:59:31 volumio volumio[21245]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 13:59:31 volumio volumio[21245]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 13:59:31 volumio volumio[21245]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 28 13:59:31 volumio volumio[21245]: Express server listening on port 3000 Jan 28 13:59:31 volumio volumio[21245]: [Metrics] WebUI: 16s 170.40ms Jan 28 13:59:31 volumio volumio[21245]: info: CoreStateMachine::resetVolumioState Jan 28 13:59:31 volumio volumio[21245]: info: CoreStateMachine::getcurrentVolume Jan 28 13:59:31 volumio volumio[21245]: info: CoreCommandRouter::volumioRetrievevolume Jan 28 13:59:31 volumio go-librespot[21368]: time="2026-01-28T13:59:31+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 13:59:31 volumio go-librespot[21368]: time="2026-01-28T13:59:31+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 28 13:59:31 volumio go-librespot[21368]: time="2026-01-28T13:59:31+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 28 13:59:31 volumio go-librespot[21368]: time="2026-01-28T13:59:31+07:00" level=info msg="zeroconf server listening on port 46823" Jan 28 13:59:32 volumio sudo[21407]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 28 13:59:32 volumio sudo[21407]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 13:59:32 volumio sudo[21407]: pam_unix(sudo:session): session closed for user root Jan 28 13:59:32 volumio volumio[21245]: info: Volumio Network Manager: Network status updated: 1 Jan 28 13:59:32 volumio sudo[21409]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 28 13:59:32 volumio sudo[21409]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 13:59:32 volumio sudo[21409]: pam_unix(sudo:session): session closed for user root Jan 28 13:59:32 volumio go-librespot[21368]: time="2026-01-28T13:59:32+07:00" level=debug msg="obtained new client token: AAB6PA1ZH2Fp44M5dN4bGyFGnPpuwBI2XqySU/5mqPvJja5ktPoFfe3tEpXuEk1CclEKuaaG9itmQ//vAUFPG/65maMkjiwD4mLC5CBZ2nlcU1Abc0waY7c3k+7hOyRxGhamZc95ao8RqeIVJNq6oii/ix/wHWAMWAcHps+ZRES1rZTsok83F7uuxTXhxECYB6jlUMRyq6/TjK26RqoY7liS5+Z7zJSXLmrtOKVwINyVi5GgR/C6bhNG" Jan 28 13:59:32 volumio go-librespot[21368]: time="2026-01-28T13:59:32+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 13:59:32 volumio volumio[21245]: info: VolumeController:: Volume=100 Mute =false Jan 28 13:59:32 volumio volumio[21245]: info: CoreStateMachine::pushState Jan 28 13:59:32 volumio volumio[21245]: info: CorePlayQueue::getTrack 0 Jan 28 13:59:32 volumio volumio[21245]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 28 13:59:32 volumio volumio[21245]: info: CoreCommandRouter::volumioPushState Jan 28 13:59:32 volumio go-librespot[21368]: time="2026-01-28T13:59:32+07:00" level=debug msg="completed keyexchange" Jan 28 13:59:32 volumio go-librespot[21368]: time="2026-01-28T13:59:32+07:00" level=debug msg="completed challenge" Jan 28 13:59:32 volumio volumio[21245]: info: CoreStateMachine::updateTrackBlock Jan 28 13:59:32 volumio volumio[21245]: info: CorePlayQueue::getTrackBlock Jan 28 13:59:32 volumio volumio[21245]: info: CoreCommandRouter::volumioRetrievevolume Jan 28 13:59:32 volumio go-librespot[21368]: time="2026-01-28T13:59:32+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 13:59:32 volumio volumio-remote-updater[628]: [2026-01-28 13:59:32] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1769583570 101 Jan 28 13:59:32 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 13:59:32 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 13:59:32 volumio volumio[21245]: 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 Jan 28 13:59:32 volumio volumio[21245]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 13:59:32 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 13:59:32 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 13:59:32 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 13:59:32 volumio volumio[21245]: info: Reloading queue from file Jan 28 13:59:32 volumio volumio[21245]: info: CoreStateMachine::setRepeat null single undefined Jan 28 13:59:32 volumio volumio[21245]: info: CoreStateMachine::pushState Jan 28 13:59:32 volumio volumio[21245]: info: CorePlayQueue::getTrack 0 Jan 28 13:59:32 volumio volumio[21245]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 28 13:59:32 volumio volumio[21245]: info: CoreCommandRouter::volumioPushState Jan 28 13:59:32 volumio volumio[21245]: info: CoreStateMachine::setRandom null Jan 28 13:59:32 volumio volumio[21245]: info: CoreStateMachine::pushState Jan 28 13:59:32 volumio volumio[21245]: info: CorePlayQueue::getTrack 0 Jan 28 13:59:32 volumio volumio[21245]: info: CoreCommandRouter::volumioPushState Jan 28 13:59:32 volumio volumio[21245]: info: Setting Device type: Raspberry PI Jan 28 13:59:32 volumio volumio[21245]: info: Completed loading Core Plugins Jan 28 13:59:32 volumio volumio[21245]: info: Preparing to generate the ALSA configuration file Jan 28 13:59:32 volumio volumio[21245]: info: VolumeController:: Volume=100 Mute =false Jan 28 13:59:32 volumio volumio[21245]: info: CoreStateMachine::pushState Jan 28 13:59:32 volumio volumio[21245]: info: CorePlayQueue::getTrack 0 Jan 28 13:59:32 volumio volumio[21245]: info: CoreCommandRouter::volumioPushState Jan 28 13:59:32 volumio volumio[21245]: info: Asound.conf file unchanged, so no further update is needed Jan 28 13:59:32 volumio volumio[21245]: info: Output device has changed, restarting MPD Jan 28 13:59:32 volumio sudo[21425]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Jan 28 13:59:32 volumio sudo[21425]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 13:59:33 volumio volumio[21245]: info: Output device has changed, restarting Shairport Sync Jan 28 13:59:33 volumio volumio[21245]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 13:59:33 volumio volumio[21245]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 13:59:33 volumio sudo[21427]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 28 13:59:33 volumio sudo[21427]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 13:59:33 volumio sudo[21427]: pam_unix(sudo:session): session closed for user root Jan 28 13:59:33 volumio sudo[21430]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 28 13:59:33 volumio sudo[21430]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 13:59:33 volumio volumio[21245]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 28 13:59:33 volumio volumio[21245]: info: ___________ START PLUGINS ___________ Jan 28 13:59:33 volumio volumio[21245]: info: ControllerMpd::onStart: Initializing MPD Jan 28 13:59:33 volumio volumio[21245]: info: Creating MPD Configuration file Jan 28 13:59:33 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Jan 28 13:59:33 volumio sudo[21425]: pam_unix(sudo:session): session closed for user root Jan 28 13:59:33 volumio volumio[21245]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 28 13:59:33 volumio volumio[21245]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 13:59:33 volumio volumio[21245]: info: [1769583573274] CoreMusicLibrary::Adding element Media Servers Jan 28 13:59:33 volumio volumio[21245]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 13:59:33 volumio sudo[21438]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 28 13:59:33 volumio sudo[21438]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 13:59:33 volumio sudo[21438]: pam_unix(sudo:session): session closed for user root Jan 28 13:59:33 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 28 13:59:33 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 28 13:59:33 volumio systemd[1]: mpd.service: Consumed 7.409s CPU time. Jan 28 13:59:33 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 28 13:59:33 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 28 13:59:33 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 28 13:59:33 volumio sudo[21440]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 28 13:59:33 volumio volumio[21245]: info: UPNP Browser: Client initialized successfully Jan 28 13:59:33 volumio sudo[21440]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 13:59:33 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 28 13:59:33 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 28 13:59:33 volumio volumio[21245]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 13:59:33 volumio volumio[21245]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 13:59:33 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 28 13:59:33 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 28 13:59:33 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 28 13:59:33 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 28 13:59:33 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 28 13:59:33 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 28 13:59:33 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 28 13:59:33 volumio volumio[21245]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 28 13:59:33 volumio volumio[21245]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 13:59:33 volumio volumio[21245]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 13:59:33 volumio volumio[21245]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 28 13:59:33 volumio volumio[21245]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 13:59:33 volumio volumio[21245]: info: [1769583573731] CoreMusicLibrary::Adding element Last_100 Jan 28 13:59:33 volumio volumio[21245]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 13:59:33 volumio volumio[21245]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 13:59:33 volumio volumio[21245]: info: [1769583573752] CoreMusicLibrary::Adding element Webradio Jan 28 13:59:33 volumio volumio[21245]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 13:59:33 volumio volumio[21245]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 28 13:59:33 volumio volumio[21245]: info: Initializing BBC Radios Jan 28 13:59:33 volumio volumio[21245]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 28 13:59:33 volumio volumio[21245]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 13:59:34 volumio volumio[21245]: info: Creating Spotify config file Jan 28 13:59:34 volumio volumio[21245]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 13:59:34 volumio sudo[21450]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 28 13:59:34 volumio sudo[21450]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jan 28 13:59:34 volumio sudo[21450]: pam_unix(sudo:session): session closed for user root Jan 28 13:59:34 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 13:59:34 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 13:59:34 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 13:59:34 volumio volumio[21375]: Starting albumart workers Jan 28 13:59:35 volumio volumio[21377]: Starting albumart workers Jan 28 13:59:35 volumio volumio[21245]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 13:59:35 volumio volumio[21245]: info: [1769583575174] CoreMusicLibrary::Adding element YouTube Music Jan 28 13:59:35 volumio volumio[21245]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 13:59:35 volumio volumio[21245]: Cannot find translation for source YouTube Music Jan 28 13:59:35 volumio volumio[21245]: info: Volumio Calling Home Jan 28 13:59:35 volumio sudo[21472]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Jan 28 13:59:35 volumio sudo[21472]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 13:59:35 volumio volumio[21376]: Starting albumart workers Jan 28 13:59:35 volumio sudo[21472]: pam_unix(sudo:session): session closed for user root Jan 28 13:59:35 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Jan 28 13:59:35 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 13:59:35 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 13:59:35 volumio go-librespot[21477]: go-librespot daemon starting... Jan 28 13:59:35 volumio go-librespot[21478]: time="2026-01-28T13:59:35+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 13:59:36 volumio volumio[21245]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Jan 28 13:59:36 volumio volumio[21245]: info: Discovery: Found device Volumio Jan 28 13:59:36 volumio volumio[21245]: info: CoreCommandRouter::volumioGetState Jan 28 13:59:36 volumio volumio[21245]: info: CorePlayQueue::getTrack 0 Jan 28 13:59:36 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 13:59:36 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 13:59:36 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 13:59:36 volumio volumio[21245]: info: MPD Permissions set Jan 28 13:59:36 volumio volumio[21245]: info: MPD Permissions set Jan 28 13:59:36 volumio volumio[21245]: info: Upmpdcli Daemon Started Jan 28 13:59:36 volumio volumio[21245]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Jan 28 13:59:36 volumio volumio[21245]: info: Discovery: Found device Volumio Jan 28 13:59:36 volumio volumio[21245]: info: CoreCommandRouter::volumioGetState Jan 28 13:59:36 volumio volumio[21245]: info: CorePlayQueue::getTrack 0 Jan 28 13:59:36 volumio go-librespot[21478]: time="2026-01-28T13:59:36+07:00" level=info msg="zeroconf server listening on port 40853" Jan 28 13:59:36 volumio volumio[21245]: info: Volumio called home Jan 28 13:59:36 volumio volumio[21245]: info: Spotify config file written Jan 28 13:59:36 volumio sudo[21486]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jan 28 13:59:36 volumio sudo[21486]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 13:59:37 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Jan 28 13:59:37 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Jan 28 13:59:37 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 13:59:37 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 13:59:37 volumio go-librespot[21495]: go-librespot daemon starting... Jan 28 13:59:37 volumio sudo[21486]: pam_unix(sudo:session): session closed for user root Jan 28 13:59:37 volumio go-librespot[21497]: time="2026-01-28T13:59:37+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 13:59:37 volumio go-librespot[21497]: time="2026-01-28T13:59:37+07:00" level=debug msg="app state loaded" Jan 28 13:59:37 volumio go-librespot[21497]: time="2026-01-28T13:59:37+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 13:59:37 volumio volumio[21245]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Jan 28 13:59:37 volumio volumio[21245]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 13:59:37 volumio volumio[21245]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 13:59:37 volumio volumio[21245]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 13:59:37 volumio volumio[21245]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 13:59:37 volumio volumio[21245]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 13:59:37 volumio volumio[21245]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 13:59:37 volumio volumio[21245]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 13:59:37 volumio volumio[21245]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 13:59:37 volumio volumio[21245]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 13:59:37 volumio volumio[21245]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 13:59:37 volumio volumio[21245]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 13:59:37 volumio volumio[21245]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 13:59:37 volumio volumio[21245]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 13:59:37 volumio volumio[21245]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 13:59:37 volumio volumio[21245]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 13:59:37 volumio volumio[21245]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 13:59:37 volumio volumio[21245]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 13:59:37 volumio volumio[21245]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 13:59:37 volumio volumio[21245]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 13:59:37 volumio volumio[21245]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 13:59:37 volumio volumio[21245]: info: No need to fix Spotify hosts Jan 28 13:59:37 volumio go-librespot[21497]: time="2026-01-28T13:59:37+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]" Jan 28 13:59:37 volumio go-librespot[21497]: time="2026-01-28T13:59:37+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]" Jan 28 13:59:37 volumio go-librespot[21497]: time="2026-01-28T13:59:37+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]" Jan 28 13:59:37 volumio go-librespot[21497]: time="2026-01-28T13:59:37+07:00" level=info msg="zeroconf server listening on port 45487" Jan 28 13:59:38 volumio go-librespot[21497]: time="2026-01-28T13:59:38+07:00" level=debug msg="obtained new client token: AADGLNNzMv0g8eJwh7S8ep6MPN8rcmPMw1ZqAYZxaNcAstVgcwzfVGS9zlM7DNMAaKPUtfqWU23+baiZfE7vFkGUhmgsqaRdYP8znyq1R8EH2UOYOgmSuIvakPymGAAMfX9YU+ODW4Z63ptbvTemwus29pYjfeIKp1dqWLDNlrBB/K7xQd0rT8CDMemJcYFU8WTck4WrZb7ycDxPGN2sq51HShZ6YGXRhwjyUMAXny1njUpmC3P2RKFj" Jan 28 13:59:38 volumio go-librespot[21497]: time="2026-01-28T13:59:38+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 13:59:38 volumio volumio[21245]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 28 13:59:38 volumio volumio[21245]: SPOTIFY: BQCe_zPTN5JwhdgLgAWNHpLl7QLS7gzHk1mITgagkjhQlg-xL5g_2ZvfcyIoED2c7JvnCB4oWnu4Y989w3EJ_L6pVogNDqQD6H-exjBRkjiNoWceQCUm04AQvWdkpAXSlqOAtXeBy9QRaSvq893_CEYYiK3DxgJRMSdG5tuGSe75Y9WFyFHoInteQq7Y_JCcEIVlcmJQFMHGnXu4yiV09nB7zEyNXC_4U3Rc0ehcx52iL1TRsuSzAUEj6i34wYp4HVxz-Tq3HbLRb4CDTzbf6cgXFsuW8i-LcDqkW7n4yDtcNliClOtfOLfe Jan 28 13:59:38 volumio volumio[21245]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 28 13:59:38 volumio volumio[21245]: info: New Spotify access token = BQCe_zPTN5JwhdgLgAWNHpLl7QLS7gzHk1mITgagkjhQlg-xL5g_2ZvfcyIoED2c7JvnCB4oWnu4Y989w3EJ_L6pVogNDqQD6H-exjBRkjiNoWceQCUm04AQvWdkpAXSlqOAtXeBy9QRaSvq893_CEYYiK3DxgJRMSdG5tuGSe75Y9WFyFHoInteQq7Y_JCcEIVlcmJQFMHGnXu4yiV09nB7zEyNXC_4U3Rc0ehcx52iL1TRsuSzAUEj6i34wYp4HVxz-Tq3HbLRb4CDTzbf6cgXFsuW8i-LcDqkW7n4yDtcNliClOtfOLfe Jan 28 13:59:38 volumio volumio[21245]: info: Spotify credentials grant success - running version from March 24, 2019 Jan 28 13:59:38 volumio volumio[21245]: info: Starting Shairport Sync Jan 28 13:59:38 volumio volumio[21245]: info: Starting Shairport Sync Jan 28 13:59:38 volumio volumio[21245]: info: Starting Shairport Sync Jan 28 13:59:38 volumio go-librespot[21497]: time="2026-01-28T13:59:38+07:00" level=debug msg="completed keyexchange" Jan 28 13:59:38 volumio go-librespot[21497]: time="2026-01-28T13:59:38+07:00" level=debug msg="completed challenge" Jan 28 13:59:38 volumio sudo[21525]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 28 13:59:38 volumio sudo[21525]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 13:59:38 volumio sudo[21527]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 28 13:59:38 volumio sudo[21527]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 13:59:38 volumio sudo[21529]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 28 13:59:38 volumio sudo[21529]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 13:59:38 volumio go-librespot[21497]: time="2026-01-28T13:59:38+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 " Jan 28 13:59:38 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 13:59:38 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 13:59:38 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 13:59:38 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 13:59:38 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 13:59:38 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 28 13:59:38 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Jan 28 13:59:38 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 28 13:59:38 volumio systemd[1]: shairport-sync.service: Consumed 2.296s CPU time. Jan 28 13:59:38 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 28 13:59:38 volumio sudo[21525]: pam_unix(sudo:session): session closed for user root Jan 28 13:59:38 volumio sudo[21527]: pam_unix(sudo:session): session closed for user root Jan 28 13:59:38 volumio sudo[21529]: pam_unix(sudo:session): session closed for user root Jan 28 13:59:38 volumio volumio[21245]: info: Shairport-Sync Started Jan 28 13:59:39 volumio volumio[21245]: Error adding Membership: Error: addMembership EINVAL Jan 28 13:59:39 volumio volumio[21245]: info: Shairport-Sync Started Jan 28 13:59:39 volumio volumio[21245]: info: Shairport-Sync Started Jan 28 13:59:39 volumio volumio[21245]: info: CoreCommandRouter::volumioGetState Jan 28 13:59:39 volumio volumio[21245]: info: CorePlayQueue::getTrack 0 Jan 28 13:59:39 volumio volumio[21245]: 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"} Jan 28 13:59:39 volumio volumio[21245]: info: Spotify Successfully logged in Jan 28 13:59:39 volumio volumio[21245]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 13:59:39 volumio volumio[21245]: info: [1769583579290] CoreMusicLibrary::Adding element Spotify Jan 28 13:59:39 volumio volumio[21245]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 13:59:39 volumio volumio[21245]: Cannot find translation for source YouTube Music Jan 28 13:59:39 volumio volumio[21245]: Cannot find translation for source Spotify Jan 28 13:59:39 volumio volumio[21245]: info: [yt-cast-receiver] DIAL server listening on port 8098 Jan 28 13:59:40 volumio volumio[21245]: info: CoreCommandRouter::volumioRetrievevolume Jan 28 13:59:40 volumio volumio[21245]: info: VolumeController:: Volume=100 Mute =false Jan 28 13:59:40 volumio volumio[21245]: info: CoreCommandRouter::volumioGetState Jan 28 13:59:40 volumio volumio[21245]: info: CorePlayQueue::getTrack 0 Jan 28 13:59:40 volumio volumio[21245]: info: CoreStateMachine::pushState Jan 28 13:59:40 volumio volumio[21245]: info: CorePlayQueue::getTrack 0 Jan 28 13:59:40 volumio volumio[21245]: info: CoreCommandRouter::volumioPushState Jan 28 13:59:40 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 13:59:40 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 13:59:40 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 13:59:41 volumio volumio[21245]: info: go-librespot daemon successfully initialized Jan 28 13:59:41 volumio mpd[21469]: 2026-01-28T13:59:41 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 28 13:59:41 volumio systemd[1]: Started mpd.service - Music Player Daemon. Jan 28 13:59:41 volumio sudo[21430]: pam_unix(sudo:session): session closed for user root Jan 28 13:59:41 volumio sudo[21440]: pam_unix(sudo:session): session closed for user root Jan 28 13:59:41 volumio volumio[21245]: error: MPD error: The expression evaluated to a falsy value: Jan 28 13:59:41 volumio volumio[21245]: assert.ok(self.idling) Jan 28 13:59:41 volumio volumio[21245]: error: The expression evaluated to a falsy value: Jan 28 13:59:41 volumio volumio[21245]: assert.ok(self.idling) Jan 28 13:59:41 volumio volumio[21245]: error: updateQueue error: null Jan 28 13:59:41 volumio volumio[21245]: info: MPD running with PID21469 Jan 28 13:59:41 volumio volumio[21245]: ,establishing connection Jan 28 13:59:41 volumio volumio[21245]: info: Completed starting Core Plugins Jan 28 13:59:41 volumio volumio[21245]: info: ------------------------------------------- Jan 28 13:59:41 volumio volumio[21245]: info: ----- MyVolumio plugins startup ---- Jan 28 13:59:41 volumio volumio[21245]: info: ------------------------------------------- Jan 28 13:59:41 volumio volumio[21245]: info: [MyVolumio PluginManager] Fetching plans data.... Jan 28 13:59:41 volumio volumio[21245]: error: updateQueue error: null Jan 28 13:59:41 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Jan 28 13:59:41 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 13:59:41 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 13:59:41 volumio go-librespot[21569]: go-librespot daemon starting... Jan 28 13:59:41 volumio go-librespot[21570]: time="2026-01-28T13:59:41+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 13:59:41 volumio go-librespot[21570]: time="2026-01-28T13:59:41+07:00" level=debug msg="app state loaded" Jan 28 13:59:41 volumio go-librespot[21570]: time="2026-01-28T13:59:41+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 13:59:42 volumio go-librespot[21570]: time="2026-01-28T13:59:42+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]" Jan 28 13:59:42 volumio go-librespot[21570]: time="2026-01-28T13:59:42+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]" Jan 28 13:59:42 volumio go-librespot[21570]: time="2026-01-28T13:59:42+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]" Jan 28 13:59:42 volumio go-librespot[21570]: time="2026-01-28T13:59:42+07:00" level=info msg="zeroconf server listening on port 35295" Jan 28 13:59:42 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 13:59:42 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 13:59:42 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 13:59:42 volumio go-librespot[21570]: time="2026-01-28T13:59:42+07:00" level=debug msg="obtained new client token: AADCfpT66YYPz9J3opdVcnytqdQxA20i8V9cq6rzyfoXdpBiITARS2MA9R7gbMvhYVfgpXWy61hSz9sIQSVawcnYuxtlta6/tpWYe46bi07WhfD45TfiWz49nWSNPfPXMrZNFnG3iVUZ3w+xXhdvugceHgfdSBRq4ln04H2pc9TCrogfNsgaPGVGqd76cwW/q4/cVyTi3EB2wqSbtw8d7sFKs3KVufM7UjxHhXMzR0shyGHTx3tAVCiQIME=" Jan 28 13:59:42 volumio go-librespot[21570]: time="2026-01-28T13:59:42+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 13:59:42 volumio go-librespot[21570]: time="2026-01-28T13:59:42+07:00" level=debug msg="completed keyexchange" Jan 28 13:59:42 volumio go-librespot[21570]: time="2026-01-28T13:59:42+07:00" level=debug msg="completed challenge" Jan 28 13:59:42 volumio go-librespot[21570]: time="2026-01-28T13:59:42+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 13:59:42 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 13:59:42 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 13:59:44 volumio volumio[21245]: info: Initializing connection to go-librespot Websocket Jan 28 13:59:44 volumio volumio[21245]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 28 13:59:44 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 13:59:44 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 13:59:44 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 13:59:46 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Jan 28 13:59:46 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 13:59:46 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 13:59:46 volumio go-librespot[21577]: go-librespot daemon starting... Jan 28 13:59:46 volumio go-librespot[21578]: time="2026-01-28T13:59:46+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 13:59:46 volumio go-librespot[21578]: time="2026-01-28T13:59:46+07:00" level=debug msg="app state loaded" Jan 28 13:59:46 volumio go-librespot[21578]: time="2026-01-28T13:59:46+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 13:59:46 volumio volumio[21245]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Jan 28 13:59:46 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 13:59:46 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 13:59:46 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 13:59:46 volumio go-librespot[21578]: time="2026-01-28T13:59:46+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 13:59:46 volumio go-librespot[21578]: time="2026-01-28T13:59:46+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 28 13:59:46 volumio go-librespot[21578]: time="2026-01-28T13:59:46+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 28 13:59:46 volumio go-librespot[21578]: time="2026-01-28T13:59:46+07:00" level=info msg="zeroconf server listening on port 37169" Jan 28 13:59:47 volumio go-librespot[21578]: time="2026-01-28T13:59:47+07:00" level=debug msg="obtained new client token: AAAnteDQTWjhFwDMAl1Z1n1+qLd5mnYP1t5luVDo+Ep/Ctfnhbp/MRewjyZBfDtobz0GXLtq8eYknghOle6zWheG+3+J8IokhRub/3yZZHtEOgoUniHzfpj5/sprKlyVl3fWG3maCaRtGfOqZupj8vc2+/F9uAc563cyhWH5aUPpKy3YaDPWuge8lEqOUFVyLpMI7/9a+Yc22B5ftFayI1Jw2e9ugDRmMsn4G8Oy2n4K7TsQMaNs25yf" Jan 28 13:59:47 volumio go-librespot[21578]: time="2026-01-28T13:59:47+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 13:59:47 volumio volumio[21245]: info: Initializing connection to go-librespot Websocket Jan 28 13:59:47 volumio go-librespot[21578]: time="2026-01-28T13:59:47+07:00" level=debug msg="new websocket client" Jan 28 13:59:47 volumio volumio[21245]: info: Connection to go-librespot Websocket established Jan 28 13:59:47 volumio go-librespot[21578]: time="2026-01-28T13:59:47+07:00" level=debug msg="completed keyexchange" Jan 28 13:59:47 volumio go-librespot[21578]: time="2026-01-28T13:59:47+07:00" level=debug msg="completed challenge" Jan 28 13:59:47 volumio go-librespot[21578]: time="2026-01-28T13:59:47+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 " Jan 28 13:59:47 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 13:59:47 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 13:59:47 volumio volumio[21245]: info: Connection to go-librespot Websocket closed Jan 28 13:59:48 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 13:59:48 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 13:59:48 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 13:59:50 volumio volumio[21245]: info: Getting Spotify volume Jan 28 13:59:50 volumio volumio[21245]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 28 13:59:50 volumio volumio[21245]: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 28 13:59:50 volumio volumio[21245]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Jan 28 13:59:50 volumio volumio[21245]: errno: -111, Jan 28 13:59:50 volumio volumio[21245]: code: 'ECONNREFUSED', Jan 28 13:59:50 volumio volumio[21245]: syscall: 'connect', Jan 28 13:59:50 volumio volumio[21245]: address: '127.0.0.1', Jan 28 13:59:50 volumio volumio[21245]: port: 9879, Jan 28 13:59:50 volumio volumio[21245]: response: undefined Jan 28 13:59:50 volumio volumio[21245]: } Jan 28 13:59:50 volumio volumio[21245]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 28 13:59:50 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Jan 28 13:59:50 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 13:59:50 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 13:59:50 volumio go-librespot[21597]: go-librespot daemon starting... Jan 28 13:59:50 volumio go-librespot[21598]: time="2026-01-28T13:59:50+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 13:59:50 volumio go-librespot[21598]: time="2026-01-28T13:59:50+07:00" level=debug msg="app state loaded" Jan 28 13:59:50 volumio go-librespot[21598]: time="2026-01-28T13:59:50+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 13:59:50 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 13:59:50 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 13:59:50 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 13:59:51 volumio go-librespot[21598]: time="2026-01-28T13:59:51+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 28 13:59:51 volumio go-librespot[21598]: time="2026-01-28T13:59:51+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]" Jan 28 13:59:51 volumio go-librespot[21598]: time="2026-01-28T13:59:51+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]" Jan 28 13:59:51 volumio go-librespot[21598]: time="2026-01-28T13:59:51+07:00" level=info msg="zeroconf server listening on port 39997" Jan 28 13:59:51 volumio go-librespot[21598]: time="2026-01-28T13:59:51+07:00" level=debug msg="obtained new client token: AAAkkXY6UAK5djW7+t62qIo1wVI8ciDTWVXosyGcdR93DubN3rjgBSVn7XS2prxDT+i7oo6d19ofAPhsv4CxkfiPIyBz7WCeQxwKDK97i338Flmnw4Z2ARLB+pTQuwvVLdBwSkW4Du8wD3pYRzkKjcsmrvtnqvJ4E2h6bqlbFD78/AyKVzfnpld8hUm1vkzImQIC8B0OKr3M1j1EQxiY1AKI/ZPPEdauy81BeHfGbG8E2RsFXXV6jQ94sZg=" Jan 28 13:59:51 volumio go-librespot[21598]: time="2026-01-28T13:59:51+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 13:59:51 volumio go-librespot[21598]: time="2026-01-28T13:59:51+07:00" level=debug msg="completed keyexchange" Jan 28 13:59:51 volumio go-librespot[21598]: time="2026-01-28T13:59:51+07:00" level=debug msg="completed challenge" Jan 28 13:59:51 volumio go-librespot[21598]: time="2026-01-28T13:59:51+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 13:59:51 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 13:59:51 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 13:59:51 volumio sudo[21622]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-01-28 13:58' Jan 28 13:59:51 volumio sudo[21622]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) PRETTY_NAME="Raspbian GNU/Linux 12 (bookworm)" NAME="Raspbian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="b05a530ca81d05eb9a84d0acf82089f0a60b8ee6" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="4ad85e2147d972f0b838d33c21382d2d813b2ae8" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu Dec 25 09:13:19 UTC 2025" VOLUMIO_VERSION="4.084" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="792f09af7488531aecd1aadcaa9b175e"