Jan 27 20:05:00 volumio volumio[16493]: info: Applying required configuration parameters for plugin RoonBridge Jan 27 20:05:00 volumio volumio[16493]: info: Loading i18n strings for locale en Jan 27 20:05:00 volumio volumio[16493]: Updating browse sources language Jan 27 20:05:00 volumio volumio[16493]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 27 20:05:00 volumio volumio[16604]: Forking 3 albumart workers Jan 27 20:05:00 volumio volumio[16493]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 27 20:05:00 volumio volumio[16493]: info: CoreCommandRouter::initPlayerControls Jan 27 20:05:00 volumio volumio[16493]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 20:05:00 volumio volumio[16493]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 20:05:00 volumio volumio[16493]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 20:05:00 volumio volumio[16493]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 20:05:00 volumio volumio[16493]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 20:05:00 volumio volumio[16493]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 20:05:00 volumio volumio[16493]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 20:05:00 volumio volumio[16493]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 20:05:00 volumio volumio[16493]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 27 20:05:00 volumio volumio[16493]: Express server listening on port 3000 Jan 27 20:05:00 volumio volumio[16493]: [Metrics] WebUI: 16s 148.81ms Jan 27 20:05:00 volumio volumio[16493]: info: CoreStateMachine::resetVolumioState Jan 27 20:05:00 volumio volumio[16493]: info: CoreStateMachine::getcurrentVolume Jan 27 20:05:00 volumio volumio[16493]: info: CoreCommandRouter::volumioRetrievevolume Jan 27 20:05:00 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 16. Jan 27 20:05:00 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 20:05:00 volumio sudo[16647]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 27 20:05:00 volumio sudo[16647]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 20:05:00 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 20:05:00 volumio go-librespot[16650]: go-librespot daemon starting... Jan 27 20:05:00 volumio sudo[16647]: pam_unix(sudo:session): session closed for user root Jan 27 20:05:00 volumio sudo[16649]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 27 20:05:00 volumio sudo[16649]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 20:05:00 volumio go-librespot[16654]: time="2026-01-27T20:05:00+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 20:05:00 volumio go-librespot[16654]: time="2026-01-27T20:05:00+07:00" level=debug msg="app state loaded" Jan 27 20:05:00 volumio sudo[16649]: pam_unix(sudo:session): session closed for user root Jan 27 20:05:00 volumio go-librespot[16654]: time="2026-01-27T20:05:00+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 20:05:00 volumio volumio[16493]: info: Volumio Network Manager: Network status updated: 1 Jan 27 20:05:01 volumio volumio[16493]: info: VolumeController:: Volume=100 Mute =false Jan 27 20:05:01 volumio volumio[16493]: info: CoreStateMachine::pushState Jan 27 20:05:01 volumio volumio[16493]: info: CorePlayQueue::getTrack 0 Jan 27 20:05:01 volumio volumio[16493]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 27 20:05:01 volumio volumio[16493]: info: CoreCommandRouter::volumioPushState Jan 27 20:05:01 volumio volumio[16493]: info: CoreStateMachine::updateTrackBlock Jan 27 20:05:01 volumio volumio[16493]: info: CorePlayQueue::getTrackBlock Jan 27 20:05:01 volumio volumio[16493]: info: CoreCommandRouter::volumioRetrievevolume Jan 27 20:05:01 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 20:05:01 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 20:05:01 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 20:05:01 volumio volumio-remote-updater[628]: [2026-01-27 20:05:01] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1769519099 101 Jan 27 20:05:01 volumio volumio[16493]: 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 27 20:05:01 volumio go-librespot[16654]: time="2026-01-27T20:05:01+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 27 20:05:01 volumio go-librespot[16654]: time="2026-01-27T20:05:01+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 27 20:05:01 volumio go-librespot[16654]: time="2026-01-27T20:05:01+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 27 20:05:01 volumio go-librespot[16654]: time="2026-01-27T20:05:01+07:00" level=info msg="zeroconf server listening on port 44487" Jan 27 20:05:01 volumio volumio[16493]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 20:05:01 volumio volumio[16493]: info: Reloading queue from file Jan 27 20:05:01 volumio volumio[16493]: info: CoreStateMachine::setRepeat null single undefined Jan 27 20:05:01 volumio volumio[16493]: info: CoreStateMachine::pushState Jan 27 20:05:01 volumio volumio[16493]: info: CorePlayQueue::getTrack 0 Jan 27 20:05:01 volumio volumio[16493]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 27 20:05:01 volumio volumio[16493]: info: CoreCommandRouter::volumioPushState Jan 27 20:05:01 volumio volumio[16493]: info: CoreStateMachine::setRandom null Jan 27 20:05:01 volumio volumio[16493]: info: CoreStateMachine::pushState Jan 27 20:05:01 volumio volumio[16493]: info: CorePlayQueue::getTrack 0 Jan 27 20:05:01 volumio volumio[16493]: info: CoreCommandRouter::volumioPushState Jan 27 20:05:01 volumio volumio[16493]: info: Setting Device type: Raspberry PI Jan 27 20:05:01 volumio volumio[16493]: info: Completed loading Core Plugins Jan 27 20:05:01 volumio volumio[16493]: info: Preparing to generate the ALSA configuration file Jan 27 20:05:01 volumio volumio[16493]: info: VolumeController:: Volume=100 Mute =false Jan 27 20:05:01 volumio volumio[16493]: info: CoreStateMachine::pushState Jan 27 20:05:01 volumio volumio[16493]: info: CorePlayQueue::getTrack 0 Jan 27 20:05:01 volumio volumio[16493]: info: CoreCommandRouter::volumioPushState Jan 27 20:05:01 volumio go-librespot[16654]: time="2026-01-27T20:05:01+07:00" level=debug msg="obtained new client token: AADfV9colsMyVZPwux5q4TzYv2+bZXdFXudsH2JZSU9uxzpeOGNuKliLQKX6Njv2dNT80NogM8WTRLuspAl2MtqjQTgrtQ7WherjhlKA+1bklA7CXLjf0S+dNXbQhNcbKIA/si3RTJDB3AcNNSsc/T9orDpLHi6ALH0tZcpwNzSswx/FxqXrEYmdEVwcxIPKDrKLeZk6Nl8Z5gtmSphidpP+MA2BBvKw+vHzv4RpVAGjZ3HYoeU+SEuEqiM=" Jan 27 20:05:01 volumio volumio[16493]: info: Asound.conf file unchanged, so no further update is needed Jan 27 20:05:01 volumio volumio[16493]: info: Output device has changed, restarting MPD Jan 27 20:05:01 volumio go-librespot[16654]: time="2026-01-27T20:05:01+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 20:05:02 volumio volumio[16493]: info: Output device has changed, restarting Shairport Sync Jan 27 20:05:02 volumio volumio[16493]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 20:05:02 volumio volumio[16493]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 20:05:02 volumio sudo[16672]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Jan 27 20:05:02 volumio sudo[16672]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 20:05:02 volumio sudo[16674]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 27 20:05:02 volumio sudo[16674]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 20:05:02 volumio sudo[16676]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 27 20:05:02 volumio sudo[16676]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 20:05:02 volumio sudo[16674]: pam_unix(sudo:session): session closed for user root Jan 27 20:05:02 volumio go-librespot[16654]: time="2026-01-27T20:05:02+07:00" level=debug msg="completed keyexchange" Jan 27 20:05:02 volumio go-librespot[16654]: time="2026-01-27T20:05:02+07:00" level=debug msg="completed challenge" Jan 27 20:05:02 volumio volumio[16493]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 27 20:05:02 volumio volumio[16493]: info: ___________ START PLUGINS ___________ Jan 27 20:05:02 volumio go-librespot[16654]: time="2026-01-27T20:05: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 27 20:05:02 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 20:05:02 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 20:05:02 volumio volumio[16493]: info: ControllerMpd::onStart: Initializing MPD Jan 27 20:05:02 volumio sudo[16672]: pam_unix(sudo:session): session closed for user root Jan 27 20:05:02 volumio volumio[16493]: info: Creating MPD Configuration file Jan 27 20:05:02 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Jan 27 20:05:02 volumio volumio[16493]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 27 20:05:02 volumio volumio[16493]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 27 20:05:02 volumio volumio[16493]: info: [1769519102298] CoreMusicLibrary::Adding element Media Servers Jan 27 20:05:02 volumio volumio[16493]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 27 20:05:02 volumio volumio[16493]: info: UPNP Browser: Client initialized successfully Jan 27 20:05:02 volumio volumio[16493]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 20:05:02 volumio volumio[16493]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 20:05:02 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 27 20:05:02 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 27 20:05:02 volumio systemd[1]: mpd.service: Consumed 7.171s CPU time. Jan 27 20:05:02 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 27 20:05:02 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 27 20:05:02 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 27 20:05:02 volumio sudo[16686]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 27 20:05:02 volumio sudo[16686]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 20:05:02 volumio sudo[16687]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 27 20:05:02 volumio sudo[16687]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 20:05:02 volumio volumio[16493]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 27 20:05:02 volumio sudo[16687]: pam_unix(sudo:session): session closed for user root Jan 27 20:05:02 volumio volumio[16493]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 20:05:02 volumio volumio[16493]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 20:05:02 volumio volumio[16493]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 27 20:05:02 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 27 20:05:02 volumio volumio[16493]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 27 20:05:02 volumio volumio[16493]: info: [1769519102554] CoreMusicLibrary::Adding element Last_100 Jan 27 20:05:02 volumio volumio[16493]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 27 20:05:02 volumio volumio[16493]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 27 20:05:02 volumio volumio[16493]: info: [1769519102564] CoreMusicLibrary::Adding element Webradio Jan 27 20:05:02 volumio volumio[16493]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 27 20:05:02 volumio volumio[16493]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 27 20:05:02 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 27 20:05:02 volumio volumio[16493]: info: Initializing BBC Radios Jan 27 20:05:02 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 27 20:05:02 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 27 20:05:02 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 27 20:05:02 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 27 20:05:02 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 27 20:05:02 volumio volumio[16493]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 27 20:05:02 volumio volumio[16493]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 20:05:02 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 27 20:05:02 volumio volumio[16493]: info: Creating Spotify config file Jan 27 20:05:02 volumio volumio[16493]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 20:05:02 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 27 20:05:03 volumio sudo[16714]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 27 20:05:03 volumio sudo[16714]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jan 27 20:05:03 volumio sudo[16714]: pam_unix(sudo:session): session closed for user root Jan 27 20:05:03 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 20:05:03 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 20:05:03 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 20:05:03 volumio volumio[16615]: Starting albumart workers Jan 27 20:05:03 volumio volumio[16614]: Starting albumart workers Jan 27 20:05:03 volumio volumio[16616]: Starting albumart workers Jan 27 20:05:03 volumio volumio[16493]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 27 20:05:03 volumio volumio[16493]: info: [1769519103955] CoreMusicLibrary::Adding element YouTube Music Jan 27 20:05:03 volumio volumio[16493]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 27 20:05:03 volumio volumio[16493]: Cannot find translation for source YouTube Music Jan 27 20:05:04 volumio volumio[16493]: info: Volumio Calling Home Jan 27 20:05:04 volumio sudo[16718]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Jan 27 20:05:04 volumio sudo[16718]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 20:05:04 volumio sudo[16718]: pam_unix(sudo:session): session closed for user root Jan 27 20:05:04 volumio volumio[16493]: info: MPD Permissions set Jan 27 20:05:04 volumio volumio[16493]: info: MPD Permissions set Jan 27 20:05:04 volumio volumio[16493]: info: Upmpdcli Daemon Started Jan 27 20:05:04 volumio volumio[16493]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Jan 27 20:05:04 volumio volumio[16493]: info: Discovery: Found device Volumio Jan 27 20:05:04 volumio volumio[16493]: info: CoreCommandRouter::volumioGetState Jan 27 20:05:04 volumio volumio[16493]: info: CorePlayQueue::getTrack 0 Jan 27 20:05:05 volumio volumio[16493]: info: Volumio called home Jan 27 20:05:05 volumio volumio[16493]: info: Spotify config file written Jan 27 20:05:05 volumio volumio[16493]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Jan 27 20:05:05 volumio volumio[16493]: info: Discovery: Found device Volumio Jan 27 20:05:05 volumio volumio[16493]: info: CoreCommandRouter::volumioGetState Jan 27 20:05:05 volumio volumio[16493]: info: CorePlayQueue::getTrack 0 Jan 27 20:05:05 volumio sudo[16724]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jan 27 20:05:05 volumio sudo[16724]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 20:05:05 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 17. Jan 27 20:05:05 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 20:05:05 volumio volumio[16493]: 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 27 20:05:05 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 20:05:05 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 20:05:05 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 20:05:05 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 20:05:05 volumio go-librespot[16726]: go-librespot daemon starting... Jan 27 20:05:05 volumio volumio[16493]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 20:05:05 volumio volumio[16493]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 20:05:05 volumio volumio[16493]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 20:05:05 volumio volumio[16493]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 20:05:05 volumio volumio[16493]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 20:05:05 volumio volumio[16493]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 20:05:05 volumio volumio[16493]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 20:05:05 volumio volumio[16493]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 20:05:05 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Jan 27 20:05:05 volumio systemd[1]: go-librespot-daemon.service: Killing process 16731 (go-librespot) with signal SIGKILL. Jan 27 20:05:05 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Jan 27 20:05:05 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 20:05:05 volumio volumio[16493]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 20:05:05 volumio volumio[16493]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 20:05:05 volumio volumio[16493]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 20:05:05 volumio volumio[16493]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 20:05:05 volumio volumio[16493]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 20:05:05 volumio volumio[16493]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 20:05:05 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 20:05:05 volumio volumio[16493]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 20:05:05 volumio volumio[16493]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 20:05:05 volumio go-librespot[16739]: go-librespot daemon starting... Jan 27 20:05:05 volumio volumio[16493]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 20:05:05 volumio volumio[16493]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 20:05:05 volumio sudo[16724]: pam_unix(sudo:session): session closed for user root Jan 27 20:05:05 volumio go-librespot[16740]: time="2026-01-27T20:05:05+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 20:05:05 volumio go-librespot[16740]: time="2026-01-27T20:05:05+07:00" level=debug msg="app state loaded" Jan 27 20:05:05 volumio volumio[16493]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 20:05:05 volumio go-librespot[16740]: time="2026-01-27T20:05:05+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 20:05:05 volumio volumio[16493]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 20:05:05 volumio volumio[16493]: info: No need to fix Spotify hosts Jan 27 20:05:06 volumio go-librespot[16740]: time="2026-01-27T20:05: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 27 20:05:06 volumio go-librespot[16740]: time="2026-01-27T20:05: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 27 20:05:06 volumio go-librespot[16740]: time="2026-01-27T20:05: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 27 20:05:06 volumio go-librespot[16740]: time="2026-01-27T20:05:06+07:00" level=info msg="zeroconf server listening on port 40477" Jan 27 20:05:06 volumio go-librespot[16740]: time="2026-01-27T20:05:06+07:00" level=debug msg="obtained new client token: AABfA9LeVLS+Gw7W68dMquAmK3AHyK6z6OUnrS7MIatKMXmsPOme6zc3vfqNP6Le/zTQFE4L+LnZSmT47wVTcElBvUXjEpvQaq4yvDJ+K2OeaJBoAoJja2U3V92YAPakX4rB/XQleRg7sTR6SJr75uZBvK5rLWIh54cqEPmEBKvmii10brOzr3Gp0ckI9QfUJEFrSzFsv1HL2dGNjNz7D5W61Qi1GgLz4jtBap2Ta7JyapEzdqN9WjLaBgQ=" Jan 27 20:05:06 volumio go-librespot[16740]: time="2026-01-27T20:05:06+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 20:05:06 volumio volumio[16493]: info: Starting Shairport Sync Jan 27 20:05:06 volumio volumio[16493]: info: Starting Shairport Sync Jan 27 20:05:06 volumio volumio[16493]: info: Starting Shairport Sync Jan 27 20:05:06 volumio sudo[16771]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 27 20:05:06 volumio sudo[16771]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 20:05:06 volumio volumio[16493]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 27 20:05:06 volumio volumio[16493]: SPOTIFY: BQA42KqVepqQtmzAOi_xLq4jSrz1SSDjvgHOXtkA7XTpmxTG1T3NX0TZOC_8f26K-uJbCmrOTjjmgI7cfXEsN938BiGWf_Tt2O7dVdw_g0MQonjPu9CoB8yBmWUjs3UZmCqSE0XjQgEwuMVGP8I4Bak83kzsUu1RmhZBYizm57CwnnKWfpXCb3fHdOduQmmvoBlv1gHClkOKr97rzRQfAI_ObONgF1nltkwVL601vNGY6WzpgufDsrReZ3mqaZIOp95tPKd_I3HjoO4z7gp2aa_royVcxAi501zvfPy_7TDVfaPAmpWmVCOv Jan 27 20:05:06 volumio volumio[16493]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 27 20:05:06 volumio volumio[16493]: info: New Spotify access token = BQA42KqVepqQtmzAOi_xLq4jSrz1SSDjvgHOXtkA7XTpmxTG1T3NX0TZOC_8f26K-uJbCmrOTjjmgI7cfXEsN938BiGWf_Tt2O7dVdw_g0MQonjPu9CoB8yBmWUjs3UZmCqSE0XjQgEwuMVGP8I4Bak83kzsUu1RmhZBYizm57CwnnKWfpXCb3fHdOduQmmvoBlv1gHClkOKr97rzRQfAI_ObONgF1nltkwVL601vNGY6WzpgufDsrReZ3mqaZIOp95tPKd_I3HjoO4z7gp2aa_royVcxAi501zvfPy_7TDVfaPAmpWmVCOv Jan 27 20:05:06 volumio volumio[16493]: info: Spotify credentials grant success - running version from March 24, 2019 Jan 27 20:05:06 volumio sudo[16773]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 27 20:05:06 volumio sudo[16773]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 20:05:06 volumio sudo[16775]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 27 20:05:06 volumio sudo[16775]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 20:05:07 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 27 20:05:07 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Jan 27 20:05:07 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 27 20:05:07 volumio systemd[1]: shairport-sync.service: Consumed 2.217s CPU time. Jan 27 20:05:07 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 27 20:05:07 volumio sudo[16771]: pam_unix(sudo:session): session closed for user root Jan 27 20:05:07 volumio sudo[16773]: pam_unix(sudo:session): session closed for user root Jan 27 20:05:07 volumio sudo[16775]: pam_unix(sudo:session): session closed for user root Jan 27 20:05:07 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 20:05:07 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 20:05:07 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 20:05:07 volumio go-librespot[16740]: time="2026-01-27T20:05:07+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: read tcp 192.168.1.107:39514->104.199.241.202:4070: read: connection reset by peer" Jan 27 20:05:07 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 20:05:07 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 20:05:07 volumio volumio[16493]: info: Shairport-Sync Started Jan 27 20:05:07 volumio volumio[16493]: Error adding Membership: Error: addMembership EINVAL Jan 27 20:05:07 volumio volumio[16493]: info: Shairport-Sync Started Jan 27 20:05:07 volumio volumio[16493]: info: Shairport-Sync Started Jan 27 20:05:07 volumio volumio[16493]: info: CoreCommandRouter::volumioGetState Jan 27 20:05:07 volumio volumio[16493]: info: CorePlayQueue::getTrack 0 Jan 27 20:05:07 volumio volumio[16493]: 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 27 20:05:07 volumio volumio[16493]: info: Spotify Successfully logged in Jan 27 20:05:07 volumio volumio[16493]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 27 20:05:07 volumio volumio[16493]: info: [1769519107748] CoreMusicLibrary::Adding element Spotify Jan 27 20:05:07 volumio volumio[16493]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 27 20:05:07 volumio volumio[16493]: Cannot find translation for source YouTube Music Jan 27 20:05:07 volumio volumio[16493]: Cannot find translation for source Spotify Jan 27 20:05:08 volumio volumio[16493]: info: [yt-cast-receiver] DIAL server listening on port 8098 Jan 27 20:05:08 volumio volumio[16493]: info: CoreCommandRouter::volumioRetrievevolume Jan 27 20:05:08 volumio volumio[16493]: info: VolumeController:: Volume=100 Mute =false Jan 27 20:05:08 volumio volumio[16493]: info: CoreCommandRouter::volumioGetState Jan 27 20:05:08 volumio volumio[16493]: info: CorePlayQueue::getTrack 0 Jan 27 20:05:08 volumio volumio[16493]: info: CoreStateMachine::pushState Jan 27 20:05:08 volumio volumio[16493]: info: CorePlayQueue::getTrack 0 Jan 27 20:05:08 volumio volumio[16493]: info: CoreCommandRouter::volumioPushState Jan 27 20:05:09 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 20:05:09 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 20:05:09 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 20:05:09 volumio volumio[16493]: info: go-librespot daemon successfully initialized Jan 27 20:05:10 volumio mpd[16716]: 2026-01-27T20:05:10 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 27 20:05:10 volumio systemd[1]: Started mpd.service - Music Player Daemon. Jan 27 20:05:10 volumio sudo[16676]: pam_unix(sudo:session): session closed for user root Jan 27 20:05:10 volumio sudo[16686]: pam_unix(sudo:session): session closed for user root Jan 27 20:05:10 volumio volumio[16493]: error: MPD error: The expression evaluated to a falsy value: Jan 27 20:05:10 volumio volumio[16493]: assert.ok(self.idling) Jan 27 20:05:10 volumio volumio[16493]: error: The expression evaluated to a falsy value: Jan 27 20:05:10 volumio volumio[16493]: assert.ok(self.idling) Jan 27 20:05:10 volumio volumio[16493]: info: MPD running with PID16716 Jan 27 20:05:10 volumio volumio[16493]: ,establishing connection Jan 27 20:05:10 volumio volumio[16493]: error: updateQueue error: null Jan 27 20:05:10 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Jan 27 20:05:10 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 20:05:10 volumio volumio[16493]: info: Completed starting Core Plugins Jan 27 20:05:10 volumio volumio[16493]: info: ------------------------------------------- Jan 27 20:05:10 volumio volumio[16493]: info: ----- MyVolumio plugins startup ---- Jan 27 20:05:10 volumio volumio[16493]: info: ------------------------------------------- Jan 27 20:05:10 volumio volumio[16493]: info: [MyVolumio PluginManager] Fetching plans data.... Jan 27 20:05:10 volumio volumio[16493]: error: updateQueue error: null Jan 27 20:05:10 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 20:05:10 volumio go-librespot[16816]: go-librespot daemon starting... Jan 27 20:05:10 volumio go-librespot[16817]: time="2026-01-27T20:05:10+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 20:05:10 volumio go-librespot[16817]: time="2026-01-27T20:05:10+07:00" level=debug msg="app state loaded" Jan 27 20:05:10 volumio go-librespot[16817]: time="2026-01-27T20:05:10+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 20:05:11 volumio go-librespot[16817]: time="2026-01-27T20:05: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-gew1.spotify.com:80]" Jan 27 20:05:11 volumio go-librespot[16817]: time="2026-01-27T20:05:11+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 27 20:05:11 volumio go-librespot[16817]: time="2026-01-27T20:05:11+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 27 20:05:11 volumio go-librespot[16817]: time="2026-01-27T20:05:11+07:00" level=info msg="zeroconf server listening on port 36107" Jan 27 20:05:11 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 20:05:11 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 20:05:11 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 20:05:11 volumio go-librespot[16817]: time="2026-01-27T20:05:11+07:00" level=debug msg="obtained new client token: AACvJACpq6/nMNiTSPU76xA0XfGh6RbIKx3HgNaS0zoy/Kh/2Cy0BCnA6iHe0o1wkRXSLJHmSuEMwKZyInWgu0MVt6S386oY/1ZVW0tDQqITMH2hzPrLImY8YyWBylOZUUpUSHzMPfTBu3r4z9pwzprrD31iqRXbDrG7rXKcFeo2UFV8oAVTnzUZmjfRXKGwmxpY3I3we3h9LCJSPeFNptL/WlXaD67nAglwwNuCaIndJQlW7Jgh2ObTSu4=" Jan 27 20:05:11 volumio go-librespot[16817]: time="2026-01-27T20:05:11+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 20:05:11 volumio go-librespot[16817]: time="2026-01-27T20:05:11+07:00" level=debug msg="completed keyexchange" Jan 27 20:05:11 volumio go-librespot[16817]: time="2026-01-27T20:05:11+07:00" level=debug msg="completed challenge" Jan 27 20:05:11 volumio go-librespot[16817]: time="2026-01-27T20:05:11+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 27 20:05:11 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 20:05:11 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 20:05:12 volumio volumio[16493]: info: Initializing connection to go-librespot Websocket Jan 27 20:05:12 volumio volumio[16493]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 27 20:05:13 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 20:05:13 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 20:05:13 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 20:05:14 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Jan 27 20:05:14 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 20:05:14 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 20:05:14 volumio go-librespot[16824]: go-librespot daemon starting... Jan 27 20:05:14 volumio go-librespot[16825]: time="2026-01-27T20:05:14+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 20:05:14 volumio go-librespot[16825]: time="2026-01-27T20:05:14+07:00" level=debug msg="app state loaded" Jan 27 20:05:14 volumio go-librespot[16825]: time="2026-01-27T20:05:14+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 20:05:15 volumio volumio[16493]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Jan 27 20:05:15 volumio go-librespot[16825]: time="2026-01-27T20:05:15+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 27 20:05:15 volumio go-librespot[16825]: time="2026-01-27T20:05:15+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 27 20:05:15 volumio go-librespot[16825]: time="2026-01-27T20:05:15+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 27 20:05:15 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 20:05:15 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 20:05:15 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 20:05:15 volumio go-librespot[16825]: time="2026-01-27T20:05:15+07:00" level=info msg="zeroconf server listening on port 41793" Jan 27 20:05:15 volumio go-librespot[16825]: time="2026-01-27T20:05:15+07:00" level=debug msg="obtained new client token: AAB7Lp4MI9qLj7Sd0BSj5ROIDV3UzF4n8oouwJGlCesembNiVLDWgXVDXiOcjqwvVGmfe6kxahRTFyuDT5zDwjP25/3JB84lF5KCyyHyZMU6zT0HLCgf+yLg4px9JDAs6mrwCN1NpRnaUkjTUJ3fh1L7QZOX47hnfLtnwnMtkE68H8njzSTwCdcsghBx6MyR2XpMKxy6JnWj31buA15dlONxl0W+AOX+G1bVYGv0MBPsoGocWxsaRnmMNWA=" Jan 27 20:05:15 volumio go-librespot[16825]: time="2026-01-27T20:05:15+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 20:05:15 volumio go-librespot[16825]: time="2026-01-27T20:05:15+07:00" level=debug msg="completed keyexchange" Jan 27 20:05:15 volumio go-librespot[16825]: time="2026-01-27T20:05:15+07:00" level=debug msg="completed challenge" Jan 27 20:05:15 volumio volumio[16493]: info: Initializing connection to go-librespot Websocket Jan 27 20:05:15 volumio go-librespot[16825]: time="2026-01-27T20:05:15+07:00" level=debug msg="new websocket client" Jan 27 20:05:15 volumio volumio[16493]: info: Connection to go-librespot Websocket established Jan 27 20:05:15 volumio go-librespot[16825]: time="2026-01-27T20:05: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 27 20:05:15 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 20:05:15 volumio volumio[16493]: info: Connection to go-librespot Websocket closed Jan 27 20:05:15 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 20:05:17 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 20:05:17 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 20:05:17 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 20:05:18 volumio volumio[16493]: info: Getting Spotify volume Jan 27 20:05:18 volumio volumio[16493]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 27 20:05:18 volumio volumio[16493]: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 27 20:05:18 volumio volumio[16493]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Jan 27 20:05:18 volumio volumio[16493]: errno: -111, Jan 27 20:05:18 volumio volumio[16493]: code: 'ECONNREFUSED', Jan 27 20:05:18 volumio volumio[16493]: syscall: 'connect', Jan 27 20:05:18 volumio volumio[16493]: address: '127.0.0.1', Jan 27 20:05:18 volumio volumio[16493]: port: 9879, Jan 27 20:05:18 volumio volumio[16493]: response: undefined Jan 27 20:05:18 volumio volumio[16493]: } Jan 27 20:05:18 volumio volumio[16493]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 27 20:05:18 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Jan 27 20:05:18 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 20:05:19 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 20:05:19 volumio go-librespot[16842]: go-librespot daemon starting... Jan 27 20:05:19 volumio go-librespot[16844]: time="2026-01-27T20:05:19+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 20:05:19 volumio go-librespot[16844]: time="2026-01-27T20:05:19+07:00" level=debug msg="app state loaded" Jan 27 20:05:19 volumio go-librespot[16844]: time="2026-01-27T20:05:19+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 20:05:19 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 20:05:19 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 20:05:19 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 20:05:19 volumio go-librespot[16844]: time="2026-01-27T20:05:19+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 27 20:05:19 volumio go-librespot[16844]: time="2026-01-27T20:05:19+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Jan 27 20:05:19 volumio go-librespot[16844]: time="2026-01-27T20:05:19+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Jan 27 20:05:19 volumio go-librespot[16844]: time="2026-01-27T20:05:19+07:00" level=info msg="zeroconf server listening on port 33399" Jan 27 20:05:19 volumio go-librespot[16844]: time="2026-01-27T20:05:19+07:00" level=debug msg="obtained new client token: AACI8w9bvM/WFhT/an9C+yXIjalqWZrUQo2FM/t5445J/JvmNW6qbHxB1MRgv7ctRs8AspdbmvCi8AJGF1VAtRusvdx8+2WplloXI3o8CEjW9lJYmC1zb5e6XXVJ4/5uQIxg9xFxpWxTw8MNs2+CrdCSWOwjqqntLU83yJTOmoaBLq0rz2LyEUAhvi29qcHNzhTN5QQk0ZbcW4TMo62mY2z3vcs3kvbC2taWhjB7K3fO/RNismi4f0sHV2E=" Jan 27 20:05:20 volumio go-librespot[16844]: time="2026-01-27T20:05:20+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 27 20:05:20 volumio go-librespot[16844]: time="2026-01-27T20:05:20+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Jan 27 20:05:20 volumio go-librespot[16844]: time="2026-01-27T20:05:20+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Jan 27 20:05:20 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 20:05:20 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 20:05:20 volumio sudo[16868]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-01-27 20:04' Jan 27 20:05:20 volumio sudo[16868]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 20:05:20 volumio sudo[16868]: pam_unix(sudo:session): session closed for user root Jan 27 20:05:20 volumio volumio-remote-updater[628]: [2026-01-27 20:05:20] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Jan 27 20:05:20 volumio volumio-remote-updater[628]: [2026-01-27 20:05:20] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Jan 27 20:05:20 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Jan 27 20:05:20 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Jan 27 20:05:20 volumio systemd[1]: volumio.service: Consumed 49.862s CPU time. Jan 27 20:05:20 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 27 20:05:21 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Jan 27 20:05:21 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 9059. Jan 27 20:05:21 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 27 20:05:21 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Jan 27 20:05:21 volumio systemd[1]: volumio.service: Consumed 49.862s CPU time. Jan 27 20:05:21 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Jan 27 20:05:21 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Jan 27 20:05:21 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 20:05:21 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 20:05:21 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 20:05:23 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Jan 27 20:05:23 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 20:05:23 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 20:05:23 volumio go-librespot[16895]: go-librespot daemon starting... Jan 27 20:05:23 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 20:05:23 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 20:05:23 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 20:05:23 volumio go-librespot[16896]: time="2026-01-27T20:05:23+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 20:05:23 volumio go-librespot[16896]: time="2026-01-27T20:05:23+07:00" level=debug msg="app state loaded" Jan 27 20:05:23 volumio go-librespot[16896]: time="2026-01-27T20:05:23+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 20:05:23 volumio go-librespot[16896]: time="2026-01-27T20:05:23+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 27 20:05:23 volumio go-librespot[16896]: time="2026-01-27T20:05:23+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 27 20:05:23 volumio go-librespot[16896]: time="2026-01-27T20:05:23+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 27 20:05:23 volumio go-librespot[16896]: time="2026-01-27T20:05:23+07:00" level=info msg="zeroconf server listening on port 34303" Jan 27 20:05:24 volumio go-librespot[16896]: time="2026-01-27T20:05:24+07:00" level=debug msg="obtained new client token: AADsaCbOJOoLpfZSUttKzbVWp+cv2JMhh1g7eDVGlbjsNxx8c1tAipAC6kEcpsTtT3IfAd3GkDqK33Z0IR1tE256ZOPBRCNZExQrcKZLlIea2ebAlauBQ127o9FIbnCxqlbHDYfMKs3Om8YCxlBme2IonLg2ttHXCUio3JTZDY/Lc3l9H9xom/4aUfnse1ud5r7/IM5Fy6xVBr0NVSTsB9EjkNAESA6qDWxPDPzwqS/o325+gxzUWoow" Jan 27 20:05:24 volumio go-librespot[16896]: time="2026-01-27T20:05:24+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 20:05:24 volumio go-librespot[16896]: time="2026-01-27T20:05:24+07:00" level=debug msg="completed keyexchange" Jan 27 20:05:24 volumio go-librespot[16896]: time="2026-01-27T20:05:24+07:00" level=debug msg="completed challenge" Jan 27 20:05:24 volumio go-librespot[16896]: time="2026-01-27T20:05:24+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 27 20:05:24 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 20:05:24 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 20:05:24 volumio volumio[16880]: info: ------------------------------------------- Jan 27 20:05:24 volumio volumio[16880]: info: ----- Volumio3 ---- Jan 27 20:05:24 volumio volumio[16880]: info: ------------------------------------------- Jan 27 20:05:24 volumio volumio[16880]: info: ----- System startup ---- Jan 27 20:05:24 volumio volumio[16880]: info: ------------------------------------------- Jan 27 20:05:25 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 20:05:25 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 20:05:25 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 20:05:25 volumio volumio-remote-updater[628]: [2026-01-27 20:05:25] [connect] Successful connection Jan 27 20:05:26 volumio volumio[16880]: info: MYVOLUMIO Environment detected Jan 27 20:05:26 volumio volumio[16880]: info: Plugin folders cleanup Jan 27 20:05:26 volumio volumio[16880]: info: Scanning into folder /volumio/app/plugins/ Jan 27 20:05:26 volumio volumio[16880]: info: Scanning category audio_interface Jan 27 20:05:26 volumio volumio[16880]: info: Scanning category miscellanea Jan 27 20:05:26 volumio volumio[16880]: info: Scanning category music_service Jan 27 20:05:26 volumio volumio[16880]: info: Scanning category plugins.json Jan 27 20:05:26 volumio volumio[16880]: info: Scanning category system_controller Jan 27 20:05:26 volumio volumio[16880]: info: Scanning category user_interface Jan 27 20:05:26 volumio volumio[16880]: info: Scanning into folder /data/plugins/ Jan 27 20:05:26 volumio volumio[16880]: info: Scanning category music_service Jan 27 20:05:26 volumio volumio[16880]: info: Plugin folders cleanup completed Jan 27 20:05:26 volumio volumio[16880]: info: ------------------------------------------- Jan 27 20:05:26 volumio volumio[16880]: info: ----- Core plugins startup ---- Jan 27 20:05:26 volumio volumio[16880]: info: ------------------------------------------- Jan 27 20:05:26 volumio volumio[16880]: info: Loading plugins from folder /volumio/app/plugins/ Jan 27 20:05:26 volumio volumio[16880]: info: Adding plugin upnp to MyMusic Plugins Jan 27 20:05:26 volumio volumio[16880]: info: Adding plugin airplay_emulation to MyMusic Plugins Jan 27 20:05:26 volumio volumio[16880]: info: Adding plugin upnp_browser to MyMusic Plugins Jan 27 20:05:26 volumio volumio[16880]: info: Loading plugins from folder /data/plugins/ Jan 27 20:05:26 volumio volumio[16880]: info: Loading plugin "system"... Jan 27 20:05:26 volumio volumio[16880]: info: Loading plugin "appearance"... Jan 27 20:05:27 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 20:05:27 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 20:05:27 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 20:05:27 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Jan 27 20:05:27 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 20:05:27 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 20:05:27 volumio go-librespot[16918]: go-librespot daemon starting... Jan 27 20:05:27 volumio go-librespot[16919]: time="2026-01-27T20:05:27+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 20:05:27 volumio go-librespot[16919]: time="2026-01-27T20:05:27+07:00" level=debug msg="app state loaded" Jan 27 20:05:27 volumio go-librespot[16919]: time="2026-01-27T20:05:27+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 20:05:28 volumio go-librespot[16919]: time="2026-01-27T20:05: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 27 20:05:28 volumio go-librespot[16919]: time="2026-01-27T20:05: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 27 20:05:28 volumio go-librespot[16919]: time="2026-01-27T20:05: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 27 20:05:28 volumio go-librespot[16919]: time="2026-01-27T20:05:28+07:00" level=info msg="zeroconf server listening on port 42669" Jan 27 20:05:28 volumio volumio[16880]: info: Loading plugin "network"... Jan 27 20:05:28 volumio volumio[16880]: info: Refreshing Cached IP Addresses Jan 27 20:05:28 volumio sudo[16929]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 27 20:05:28 volumio sudo[16929]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 20:05:28 volumio sudo[16927]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 27 20:05:28 volumio sudo[16929]: pam_unix(sudo:session): session closed for user root Jan 27 20:05:28 volumio volumio[16880]: info: Loading plugin "services"... Jan 27 20:05:28 volumio sudo[16927]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 20:05:28 volumio volumio[16880]: info: Loading plugin "alsa_controller"... Jan 27 20:05:28 volumio sudo[16927]: pam_unix(sudo:session): session closed for user root Jan 27 20:05:28 volumio sudo[16936]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Jan 27 20:05:28 volumio sudo[16936]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 20:05:28 volumio go-librespot[16919]: time="2026-01-27T20:05:28+07:00" level=debug msg="obtained new client token: AABdbzZZwVGFHebobsoN7VFWSDAy9hw6rAGrDh44p2Nl0NxtUYAsU0weAIRZPvlZu+7WkZKP9SiT3QnMAqLKTmco1ODxeHMK2GaSzxhGxjWatpFDD4clnHj7S9b4wwKctJDpdZ26uJd2K00WNiMnu5JWvheP4GRtwb1Z58tOqQBsumfdcEupjMCs413s+joRaIUcUC5zOfJ7rwx86g0tnl6ORNHHWLGbuWMw1fghIQ/WHLcNY8U7Nalzx+s=" Jan 27 20:05:28 volumio volumio[16880]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 27 20:05:28 volumio volumio[16880]: info: Loading plugin "wizard"... Jan 27 20:05:28 volumio volumio[16880]: info: Loading plugin "networkfs"... Jan 27 20:05:28 volumio go-librespot[16919]: time="2026-01-27T20:05:28+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 20:05:28 volumio volumio[16880]: info: Starting Udev Watcher for removable devices Jan 27 20:05:28 volumio go-librespot[16919]: time="2026-01-27T20:05:28+07:00" level=debug msg="completed keyexchange" Jan 27 20:05:28 volumio go-librespot[16919]: time="2026-01-27T20:05:28+07:00" level=debug msg="completed challenge" Jan 27 20:05:28 volumio volumio[16880]: info: Ignoring mount for partition: boot Jan 27 20:05:28 volumio volumio[16880]: info: Ignoring mount for partition: volumio Jan 27 20:05:28 volumio volumio[16880]: info: Ignoring mount for partition: volumio_data Jan 27 20:05:28 volumio volumio[16880]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 27 20:05:28 volumio volumio[16880]: info: Loading plugin "volumio_command_line_client"... Jan 27 20:05:28 volumio volumio[16880]: info: Loading plugin "upnp"... Jan 27 20:05:28 volumio volumio[16880]: info: [1769519128650] Starting Upmpd Daemon Jan 27 20:05:28 volumio volumio[16880]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 27 20:05:28 volumio volumio[16880]: info: Loading plugin "my_music"... Jan 27 20:05:28 volumio volumio[16880]: info: Loading plugin "mpd"... Jan 27 20:05:28 volumio go-librespot[16919]: time="2026-01-27T20:05: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 27 20:05:28 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 20:05:28 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 20:05:29 volumio volumio[16880]: info: Loading plugin "upnp_browser"... Jan 27 20:05:29 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 20:05:29 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 20:05:29 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 20:05:31 volumio sudo[16936]: pam_unix(sudo:session): session closed for user root Jan 27 20:05:31 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 20:05:31 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 20:05:31 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 20:05:31 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Jan 27 20:05:31 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 20:05:31 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 20:05:31 volumio go-librespot[16960]: go-librespot daemon starting... Jan 27 20:05:31 volumio go-librespot[16961]: time="2026-01-27T20:05:31+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 20:05:31 volumio go-librespot[16961]: time="2026-01-27T20:05:31+07:00" level=debug msg="app state loaded" Jan 27 20:05:31 volumio go-librespot[16961]: time="2026-01-27T20:05:31+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 20:05:32 volumio volumio[16880]: info: Starting UPNP Browser Jan 27 20:05:32 volumio volumio[16880]: info: Loading plugin "alarm-clock"... Jan 27 20:05:32 volumio go-librespot[16961]: time="2026-01-27T20:05:32+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 27 20:05:32 volumio go-librespot[16961]: time="2026-01-27T20:05:32+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 27 20:05:32 volumio go-librespot[16961]: time="2026-01-27T20:05:32+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 27 20:05:32 volumio go-librespot[16961]: time="2026-01-27T20:05:32+07:00" level=info msg="zeroconf server listening on port 36361" Jan 27 20:05:32 volumio go-librespot[16961]: time="2026-01-27T20:05:32+07:00" level=debug msg="obtained new client token: AABhLkAKtueT8n4tUyDgCZ6INlYHED6N1V8PHkf6palI3hZWY1ErBGvnYwBVMVj3wTg8WCpGCVrpE/JC88MpzIxJougq6CejooRzXtHDELPefFSwsv8M/QJeRPdHy1X6kekmx8aHrTATplzMHPbOoGW1qOJR4v++Q5PyZrvWTl+EmTFM9jvMP7hYqm0dqviZFyJHYKS8FyICpULbmKj4qg33ozu+w0OWf9LmAuHsqvy4KokeK1MShdGL0xo=" Jan 27 20:05:32 volumio volumio[16880]: info: Loading plugin "airplay_emulation"... Jan 27 20:05:32 volumio volumio[16880]: info: Starting Shairport Sync Jan 27 20:05:32 volumio volumio[16880]: info: Loading plugin "last_100"... Jan 27 20:05:32 volumio volumio[16880]: info: Loading plugin "webradio"... Jan 27 20:05:32 volumio go-librespot[16961]: time="2026-01-27T20:05:32+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 20:05:32 volumio go-librespot[16961]: time="2026-01-27T20:05:32+07:00" level=debug msg="completed keyexchange" Jan 27 20:05:32 volumio go-librespot[16961]: time="2026-01-27T20:05:32+07:00" level=debug msg="completed challenge" Jan 27 20:05:32 volumio volumio[16880]: info: Loading plugin "i2s_dacs"... Jan 27 20:05:32 volumio volumio[16880]: info: Loading plugin "volumiodiscovery"... Jan 27 20:05:32 volumio go-librespot[16961]: time="2026-01-27T20:05: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 27 20:05:32 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 20:05:32 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 20:05:32 volumio volumio[16880]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 27 20:05:32 volumio volumio[16880]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 27 20:05:32 volumio volumio[16880]: *** WARNING *** For more information see Jan 27 20:05:32 volumio volumio[16880]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 27 20:05:32 volumio volumio[16880]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 27 20:05:32 volumio volumio[16880]: *** WARNING *** For more information see Jan 27 20:05:32 volumio node[16880]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 27 20:05:32 volumio node[16880]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 27 20:05:32 volumio node[16880]: *** WARNING *** For more information see Jan 27 20:05:32 volumio node[16880]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 27 20:05:32 volumio node[16880]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 27 20:05:32 volumio node[16880]: *** WARNING *** For more information see Jan 27 20:05:32 volumio volumio[16880]: info: Applying required configuration parameters for plugin volumiodiscovery Jan 27 20:05:32 volumio volumio[16880]: info: Discovery: Started advertising with name: Volumio Jan 27 20:05:33 volumio volumio[16880]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 27 20:05:33 volumio volumio[16880]: info: Loading plugin "spop"... Jan 27 20:05:33 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 20:05:33 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 20:05:33 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 20:05:34 volumio volumio[16880]: info: Loading plugin "ytcr"... Jan 27 20:05:35 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 20:05:35 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 20:05:35 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 20:05:35 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Jan 27 20:05:35 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 20:05:36 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 20:05:36 volumio go-librespot[16970]: go-librespot daemon starting... Jan 27 20:05:36 volumio go-librespot[16971]: time="2026-01-27T20:05:36+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 20:05:36 volumio go-librespot[16971]: time="2026-01-27T20:05:36+07:00" level=debug msg="app state loaded" Jan 27 20:05:36 volumio go-librespot[16971]: time="2026-01-27T20:05:36+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 20:05:36 volumio go-librespot[16971]: time="2026-01-27T20:05:36+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 27 20:05:36 volumio go-librespot[16971]: time="2026-01-27T20:05:36+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 27 20:05:36 volumio go-librespot[16971]: time="2026-01-27T20:05:36+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 27 20:05:36 volumio go-librespot[16971]: time="2026-01-27T20:05:36+07:00" level=info msg="zeroconf server listening on port 35583" Jan 27 20:05:36 volumio go-librespot[16971]: time="2026-01-27T20:05:36+07:00" level=debug msg="obtained new client token: AADhtmilpsm8AF5EBeK6p46dp3WSq/AMId6U8I49R5TOeupgGu96/uWz/IElF37GEaGXghgUMvouxg9sL3RBUblIezBcse3wyBHj5JYXGGK3fBtYi1y230+1tPO9jqPRgq/kXmq1EQYf4+466/fm4+trBUBpMSvhfljdW9EiJRP1nuocbNg76Wwvd4eBEVl2LpxwyyrOsiLjyMwxZ4pF3RxivcUkQTk29NaMLJaORaVhGjBokVOst9PkrJo=" Jan 27 20:05:36 volumio go-librespot[16971]: time="2026-01-27T20:05:36+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 20:05:37 volumio go-librespot[16971]: time="2026-01-27T20:05:37+07:00" level=debug msg="completed keyexchange" Jan 27 20:05:37 volumio go-librespot[16971]: time="2026-01-27T20:05:37+07:00" level=debug msg="completed challenge" Jan 27 20:05:37 volumio go-librespot[16971]: time="2026-01-27T20:05:37+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 27 20:05:37 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 20:05:37 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 20:05:37 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 20:05:37 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 20:05:37 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 20:05:37 volumio volumio[16880]: info: Loading plugin "ytmusic"... Jan 27 20:05:38 volumio volumio-remote-updater[628]: [2026-01-27 20:05:38] [connect] Successful connection Jan 27 20:05:38 volumio volumio[16880]: info: Loading plugin "outputs"... Jan 27 20:05:38 volumio volumio[16880]: info: Loading plugin "albumart"... Jan 27 20:05:38 volumio volumio[16880]: info: Plugin example_plugin is not enabled Jan 27 20:05:38 volumio volumio[16880]: info: Loading plugin "inputs"... Jan 27 20:05:38 volumio volumio[16880]: info: Loading plugin "updater_comm"... Jan 27 20:05:38 volumio volumio[16880]: info: Plugin mpdemulation is not enabled Jan 27 20:05:38 volumio volumio[16880]: info: Loading plugin "rest_api"... Jan 27 20:05:38 volumio volumio[16880]: info: Loading plugin "websocket"... Jan 27 20:05:39 volumio volumio[16880]: info: Starting Socket.io Server version 1.7.4 Jan 27 20:05:39 volumio volumio[16880]: info: Loading plugin "RoonBridge"... Jan 27 20:05:39 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 20:05:39 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 20:05:39 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 20:05:39 volumio volumio[16880]: info: Applying required configuration parameters for plugin RoonBridge Jan 27 20:05:39 volumio volumio[16880]: info: Loading i18n strings for locale en Jan 27 20:05:39 volumio volumio[16880]: Updating browse sources language Jan 27 20:05:39 volumio volumio[16880]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 27 20:05:39 volumio volumio[16880]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 27 20:05:39 volumio volumio[16880]: info: CoreCommandRouter::initPlayerControls Jan 27 20:05:39 volumio volumio[16880]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 20:05:39 volumio volumio[16880]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 20:05:39 volumio volumio[16880]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 20:05:39 volumio volumio[16880]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 20:05:39 volumio volumio[16880]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 20:05:39 volumio volumio[16880]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 20:05:39 volumio volumio[16880]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 20:05:39 volumio volumio[16880]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 20:05:39 volumio volumio[16880]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 27 20:05:39 volumio volumio[16880]: Express server listening on port 3000 Jan 27 20:05:39 volumio volumio[16880]: [Metrics] WebUI: 15s 964.09ms Jan 27 20:05:39 volumio volumio[16996]: Forking 3 albumart workers Jan 27 20:05:39 volumio volumio[16880]: info: CoreStateMachine::resetVolumioState Jan 27 20:05:39 volumio volumio[16880]: info: CoreStateMachine::getcurrentVolume Jan 27 20:05:39 volumio volumio[16880]: info: CoreCommandRouter::volumioRetrievevolume Jan 27 20:05:39 volumio sudo[17014]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 27 20:05:39 volumio sudo[17014]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 20:05:39 volumio sudo[17026]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 27 20:05:39 volumio sudo[17014]: pam_unix(sudo:session): session closed for user root Jan 27 20:05:39 volumio sudo[17026]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 20:05:40 volumio sudo[17026]: pam_unix(sudo:session): session closed for user root Jan 27 20:05:40 volumio volumio[16880]: info: Volumio Network Manager: Network status updated: 1 Jan 27 20:05:40 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Jan 27 20:05:40 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 20:05:40 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 20:05:40 volumio go-librespot[17049]: go-librespot daemon starting... Jan 27 20:05:40 volumio volumio[16880]: info: VolumeController:: Volume=100 Mute =false Jan 27 20:05:40 volumio volumio[16880]: info: CoreStateMachine::pushState Jan 27 20:05:40 volumio volumio[16880]: info: CorePlayQueue::getTrack 0 Jan 27 20:05:40 volumio volumio[16880]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 27 20:05:40 volumio go-librespot[17050]: time="2026-01-27T20:05:40+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 20:05:40 volumio go-librespot[17050]: time="2026-01-27T20:05:40+07:00" level=debug msg="app state loaded" Jan 27 20:05:40 volumio go-librespot[17050]: time="2026-01-27T20:05:40+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 20:05:40 volumio volumio[16880]: info: CoreCommandRouter::volumioPushState Jan 27 20:05:40 volumio volumio[16880]: info: CoreStateMachine::updateTrackBlock Jan 27 20:05:40 volumio volumio[16880]: info: CorePlayQueue::getTrackBlock Jan 27 20:05:40 volumio volumio[16880]: info: CoreCommandRouter::volumioRetrievevolume Jan 27 20:05:40 volumio volumio-remote-updater[628]: [2026-01-27 20:05:40] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1769519138 101 Jan 27 20:05:40 volumio volumio[16880]: 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 27 20:05:40 volumio volumio[16880]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 20:05:40 volumio volumio[16880]: info: Reloading queue from file Jan 27 20:05:40 volumio volumio[16880]: info: CoreStateMachine::setRepeat null single undefined Jan 27 20:05:40 volumio volumio[16880]: info: CoreStateMachine::pushState Jan 27 20:05:40 volumio volumio[16880]: info: CorePlayQueue::getTrack 0 Jan 27 20:05:40 volumio volumio[16880]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 27 20:05:40 volumio volumio[16880]: info: CoreCommandRouter::volumioPushState Jan 27 20:05:40 volumio volumio[16880]: info: CoreStateMachine::setRandom null Jan 27 20:05:40 volumio volumio[16880]: info: CoreStateMachine::pushState Jan 27 20:05:40 volumio volumio[16880]: info: CorePlayQueue::getTrack 0 Jan 27 20:05:40 volumio volumio[16880]: info: CoreCommandRouter::volumioPushState Jan 27 20:05:40 volumio volumio[16880]: info: Setting Device type: Raspberry PI Jan 27 20:05:40 volumio volumio[16880]: info: Completed loading Core Plugins Jan 27 20:05:40 volumio volumio[16880]: info: Preparing to generate the ALSA configuration file Jan 27 20:05:40 volumio volumio[16880]: info: VolumeController:: Volume=100 Mute =false Jan 27 20:05:40 volumio volumio[16880]: info: CoreStateMachine::pushState Jan 27 20:05:40 volumio volumio[16880]: info: CorePlayQueue::getTrack 0 Jan 27 20:05:40 volumio volumio[16880]: info: CoreCommandRouter::volumioPushState Jan 27 20:05:40 volumio go-librespot[17050]: time="2026-01-27T20:05:40+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 27 20:05:40 volumio go-librespot[17050]: time="2026-01-27T20:05:40+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 27 20:05:40 volumio go-librespot[17050]: time="2026-01-27T20:05:40+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 27 20:05:40 volumio go-librespot[17050]: time="2026-01-27T20:05:40+07:00" level=info msg="zeroconf server listening on port 44153" Jan 27 20:05:40 volumio volumio[16880]: info: Asound.conf file unchanged, so no further update is needed Jan 27 20:05:40 volumio volumio[16880]: info: Output device has changed, restarting MPD Jan 27 20:05:40 volumio sudo[17066]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Jan 27 20:05:41 volumio sudo[17066]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 20:05:41 volumio volumio[16880]: info: Output device has changed, restarting Shairport Sync Jan 27 20:05:41 volumio volumio[16880]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 20:05:41 volumio volumio[16880]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 20:05:41 volumio volumio[16880]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 27 20:05:41 volumio sudo[17069]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 27 20:05:41 volumio volumio[16880]: info: ___________ START PLUGINS ___________ Jan 27 20:05:41 volumio sudo[17069]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 20:05:41 volumio sudo[17071]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 27 20:05:41 volumio sudo[17069]: pam_unix(sudo:session): session closed for user root Jan 27 20:05:41 volumio volumio[16880]: info: ControllerMpd::onStart: Initializing MPD Jan 27 20:05:41 volumio volumio[16880]: info: Creating MPD Configuration file Jan 27 20:05:41 volumio sudo[17066]: pam_unix(sudo:session): session closed for user root Jan 27 20:05:41 volumio sudo[17071]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 20:05:41 volumio go-librespot[17050]: time="2026-01-27T20:05:41+07:00" level=debug msg="obtained new client token: AABEd1Rl2qAcMNrnNhh/v4ofZjPJhhV8FRHMmzxd6QkSB4UwoVTkRBICuSczY9RHIZyvUXIQH830elYDSEKqN3S3ITAPCGFHDf3yAtjdKcvBOVQwo4E8YJQKB2rLfJ1SCCHAllvFvxBNsytwHBUc8C14oAZCFEz9l670KP5MYtZF0dciu2N5imREAMrx7WrLTRpEOSr1HOBOCsgCmlrDtjxMOE05oMXBR0yNa2tvoOitMNXzoGK23qvL" Jan 27 20:05:41 volumio volumio[16880]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 27 20:05:41 volumio volumio[16880]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 27 20:05:41 volumio volumio[16880]: info: [1769519141244] CoreMusicLibrary::Adding element Media Servers Jan 27 20:05:41 volumio volumio[16880]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 27 20:05:41 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Jan 27 20:05:41 volumio volumio[16880]: info: UPNP Browser: Client initialized successfully Jan 27 20:05:41 volumio go-librespot[17050]: time="2026-01-27T20:05:41+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 27 20:05:41 volumio sudo[17079]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 27 20:05:41 volumio sudo[17079]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 20:05:41 volumio sudo[17079]: pam_unix(sudo:session): session closed for user root Jan 27 20:05:41 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 20:05:41 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 20:05:41 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 20:05:41 volumio sudo[17081]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 27 20:05:41 volumio sudo[17081]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 20:05:41 volumio go-librespot[17050]: time="2026-01-27T20:05:41+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Jan 27 20:05:41 volumio volumio[16880]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 20:05:41 volumio volumio[16880]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 20:05:41 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 27 20:05:41 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 27 20:05:41 volumio systemd[1]: mpd.service: Consumed 7.109s CPU time. Jan 27 20:05:41 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 27 20:05:41 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 27 20:05:41 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 27 20:05:41 volumio go-librespot[17050]: time="2026-01-27T20:05:41+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Jan 27 20:05:41 volumio volumio[16880]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 27 20:05:41 volumio volumio[16880]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 20:05:41 volumio volumio[16880]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 20:05:41 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 27 20:05:41 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 27 20:05:41 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 20:05:41 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 20:05:41 volumio volumio[16880]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 27 20:05:41 volumio volumio[16880]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 27 20:05:41 volumio volumio[16880]: info: [1769519141583] CoreMusicLibrary::Adding element Last_100 Jan 27 20:05:41 volumio volumio[16880]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 27 20:05:41 volumio volumio[16880]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 27 20:05:41 volumio volumio[16880]: info: [1769519141591] CoreMusicLibrary::Adding element Webradio Jan 27 20:05:41 volumio volumio[16880]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 27 20:05:41 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 27 20:05:41 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 27 20:05:41 volumio volumio[16880]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 27 20:05:41 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 27 20:05:41 volumio volumio[16880]: info: Initializing BBC Radios Jan 27 20:05:41 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 27 20:05:41 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 27 20:05:41 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 27 20:05:41 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 27 20:05:41 volumio volumio[16880]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 27 20:05:41 volumio volumio[16880]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 20:05:41 volumio volumio[16880]: info: Creating Spotify config file Jan 27 20:05:41 volumio volumio[16880]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 20:05:42 volumio sudo[17103]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 27 20:05:42 volumio sudo[17103]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jan 27 20:05:42 volumio sudo[17103]: pam_unix(sudo:session): session closed for user root Jan 27 20:05:43 volumio volumio[16880]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 27 20:05:43 volumio volumio[16880]: info: [1769519143152] CoreMusicLibrary::Adding element YouTube Music Jan 27 20:05:43 volumio volumio[16880]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 27 20:05:43 volumio volumio[16880]: Cannot find translation for source YouTube Music Jan 27 20:05:43 volumio volumio[17010]: Starting albumart workers Jan 27 20:05:43 volumio volumio[16880]: info: Volumio Calling Home Jan 27 20:05:43 volumio sudo[17112]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Jan 27 20:05:43 volumio sudo[17112]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 20:05:43 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 20:05:43 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 20:05:43 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 20:05:43 volumio volumio[17011]: Starting albumart workers Jan 27 20:05:43 volumio sudo[17112]: pam_unix(sudo:session): session closed for user root Jan 27 20:05:43 volumio volumio[17013]: Starting albumart workers Jan 27 20:05:44 volumio volumio[16880]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Jan 27 20:05:44 volumio volumio[16880]: info: Discovery: Found device Volumio Jan 27 20:05:44 volumio volumio[16880]: info: CoreCommandRouter::volumioGetState Jan 27 20:05:44 volumio volumio[16880]: info: CorePlayQueue::getTrack 0 Jan 27 20:05:44 volumio volumio[16880]: info: MPD Permissions set Jan 27 20:05:44 volumio volumio[16880]: info: MPD Permissions set Jan 27 20:05:44 volumio volumio[16880]: info: Upmpdcli Daemon Started Jan 27 20:05:44 volumio volumio[16880]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Jan 27 20:05:44 volumio volumio[16880]: info: Discovery: Found device Volumio Jan 27 20:05:44 volumio volumio[16880]: info: CoreCommandRouter::volumioGetState Jan 27 20:05:44 volumio volumio[16880]: info: CorePlayQueue::getTrack 0 Jan 27 20:05:44 volumio volumio[16880]: info: Spotify config file written Jan 27 20:05:44 volumio sudo[17118]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jan 27 20:05:44 volumio sudo[17118]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 20:05:44 volumio volumio[16880]: 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 27 20:05:44 volumio volumio[16880]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 20:05:44 volumio volumio[16880]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 20:05:44 volumio volumio[16880]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 20:05:44 volumio volumio[16880]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 20:05:44 volumio volumio[16880]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 20:05:44 volumio volumio[16880]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 20:05:44 volumio volumio[16880]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 20:05:44 volumio volumio[16880]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 20:05:44 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Jan 27 20:05:44 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 20:05:44 volumio volumio[16880]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 20:05:44 volumio volumio[16880]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 20:05:44 volumio volumio[16880]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 20:05:44 volumio volumio[16880]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 20:05:44 volumio volumio[16880]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 20:05:44 volumio volumio[16880]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 20:05:44 volumio volumio[16880]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 20:05:44 volumio volumio[16880]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 20:05:44 volumio volumio[16880]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 20:05:44 volumio volumio[16880]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 20:05:44 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 20:05:44 volumio go-librespot[17125]: go-librespot daemon starting... Jan 27 20:05:44 volumio volumio[16880]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 20:05:44 volumio volumio[16880]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 20:05:44 volumio volumio[16880]: info: No need to fix Spotify hosts Jan 27 20:05:44 volumio sudo[17118]: pam_unix(sudo:session): session closed for user root Jan 27 20:05:44 volumio go-librespot[17131]: time="2026-01-27T20:05:44+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 20:05:44 volumio go-librespot[17131]: time="2026-01-27T20:05:44+07:00" level=debug msg="app state loaded" Jan 27 20:05:44 volumio go-librespot[17131]: time="2026-01-27T20:05:44+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 20:05:45 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 20:05:45 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 20:05:45 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 20:05:45 volumio go-librespot[17131]: time="2026-01-27T20:05:45+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 27 20:05:45 volumio go-librespot[17131]: time="2026-01-27T20:05:45+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 27 20:05:45 volumio go-librespot[17131]: time="2026-01-27T20:05:45+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 27 20:05:45 volumio go-librespot[17131]: time="2026-01-27T20:05:45+07:00" level=info msg="zeroconf server listening on port 37671" Jan 27 20:05:45 volumio go-librespot[17131]: time="2026-01-27T20:05:45+07:00" level=debug msg="obtained new client token: AAABkbyJGFX+fdHaCLQC0rrmg/RAZNENBqR8C1OpOhhhr16L0Nb9+l9SS4T+l+0cPz3otigktI4IbcPf4rz7vsyGEIYPGqJZPXGqnw3Jnlhfg5bPArM7O9jTZxlJw2CwYIEYW4KRbPQgT1Mte4V+ouGIIHmWuOYELYr0ucWMGw3/PyQbZR8kOcVnNlRPbViBZ1xj9a1K0S+YspDstM52AKzRVl1SRcOWWrFf/JV0PJkXyXd1KN4/EQcBAu4=" Jan 27 20:05:45 volumio go-librespot[17131]: time="2026-01-27T20:05:45+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 20:05:45 volumio go-librespot[17131]: time="2026-01-27T20:05:45+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Jan 27 20:05:45 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 20:05:45 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 20:05:46 volumio volumio[16880]: info: Volumio called home Jan 27 20:05:46 volumio volumio[16880]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 27 20:05:46 volumio volumio[16880]: SPOTIFY: BQAOzWazLm4LKsyTGGUHucWAH4qgCF2Wys-iMPp7ZMuhFQ2zyitmGv4ZdZ-RKCDDrjxBwENpu0mAHzdvrQ7FvvGINiVl58mapYeGUXbmUK2jgR7Xackyq5RwhRD67LoBsA2zBpPyIbaoywdBDWQerVjErzuQy6cixeHR4ajrVnNOhCfs0BRHi1vjkW-6ycH9dwEidtnr2CP67K_QzK7jUrplJhy9wrBKAfrltE0JweRm-M3I4KtP-2wEROKeHwh5xVSJ-Xp5dYOuQJkED-Tbm6z6WbNkcSj8z2tAvmo9I7r30Sp2--rLS5mO Jan 27 20:05:46 volumio volumio[16880]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 27 20:05:46 volumio volumio[16880]: info: New Spotify access token = BQAOzWazLm4LKsyTGGUHucWAH4qgCF2Wys-iMPp7ZMuhFQ2zyitmGv4ZdZ-RKCDDrjxBwENpu0mAHzdvrQ7FvvGINiVl58mapYeGUXbmUK2jgR7Xackyq5RwhRD67LoBsA2zBpPyIbaoywdBDWQerVjErzuQy6cixeHR4ajrVnNOhCfs0BRHi1vjkW-6ycH9dwEidtnr2CP67K_QzK7jUrplJhy9wrBKAfrltE0JweRm-M3I4KtP-2wEROKeHwh5xVSJ-Xp5dYOuQJkED-Tbm6z6WbNkcSj8z2tAvmo9I7r30Sp2--rLS5mO Jan 27 20:05:46 volumio volumio[16880]: info: Spotify credentials grant success - running version from March 24, 2019 Jan 27 20:05:46 volumio volumio[16880]: info: Starting Shairport Sync Jan 27 20:05:46 volumio volumio[16880]: info: Starting Shairport Sync Jan 27 20:05:46 volumio volumio[16880]: info: Starting Shairport Sync Jan 27 20:05:46 volumio sudo[17160]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 27 20:05:46 volumio sudo[17160]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 20:05:46 volumio sudo[17164]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 27 20:05:46 volumio sudo[17162]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 27 20:05:46 volumio sudo[17164]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 20:05:46 volumio sudo[17162]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 20:05:46 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 27 20:05:46 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Jan 27 20:05:46 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 27 20:05:46 volumio systemd[1]: shairport-sync.service: Consumed 2.260s CPU time. Jan 27 20:05:46 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 27 20:05:46 volumio sudo[17160]: pam_unix(sudo:session): session closed for user root Jan 27 20:05:46 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 27 20:05:46 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Jan 27 20:05:46 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 27 20:05:46 volumio volumio[16880]: info: Shairport-Sync Started Jan 27 20:05:46 volumio volumio[16880]: Error adding Membership: Error: addMembership EINVAL Jan 27 20:05:46 volumio volumio[16880]: info: CoreCommandRouter::volumioGetState Jan 27 20:05:46 volumio volumio[16880]: info: CorePlayQueue::getTrack 0 Jan 27 20:05:46 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 27 20:05:46 volumio sudo[17164]: pam_unix(sudo:session): session closed for user root Jan 27 20:05:46 volumio sudo[17162]: pam_unix(sudo:session): session closed for user root Jan 27 20:05:46 volumio volumio[16880]: info: Shairport-Sync Started Jan 27 20:05:46 volumio volumio[16880]: info: Shairport-Sync Started Jan 27 20:05:46 volumio volumio[16880]: 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 27 20:05:46 volumio volumio[16880]: info: Spotify Successfully logged in Jan 27 20:05:46 volumio volumio[16880]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 27 20:05:46 volumio volumio[16880]: info: [1769519146986] CoreMusicLibrary::Adding element Spotify Jan 27 20:05:46 volumio volumio[16880]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 27 20:05:46 volumio volumio[16880]: Cannot find translation for source YouTube Music Jan 27 20:05:46 volumio volumio[16880]: Cannot find translation for source Spotify Jan 27 20:05:47 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 20:05:47 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 20:05:47 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 20:05:47 volumio volumio[16880]: info: [yt-cast-receiver] DIAL server listening on port 8098 Jan 27 20:05:47 volumio volumio[16880]: info: CoreCommandRouter::volumioRetrievevolume Jan 27 20:05:47 volumio volumio[16880]: info: VolumeController:: Volume=100 Mute =false Jan 27 20:05:47 volumio volumio[16880]: info: CoreCommandRouter::volumioGetState Jan 27 20:05:47 volumio volumio[16880]: info: CorePlayQueue::getTrack 0 Jan 27 20:05:47 volumio volumio[16880]: info: CoreStateMachine::pushState Jan 27 20:05:47 volumio volumio[16880]: info: CorePlayQueue::getTrack 0 Jan 27 20:05:47 volumio volumio[16880]: info: CoreCommandRouter::volumioPushState Jan 27 20:05:48 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Jan 27 20:05:48 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 20:05:49 volumio volumio[16880]: info: go-librespot daemon successfully initialized Jan 27 20:05:49 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 20:05:49 volumio go-librespot[17200]: go-librespot daemon starting... Jan 27 20:05:49 volumio go-librespot[17201]: time="2026-01-27T20:05:49+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 20:05:49 volumio go-librespot[17201]: time="2026-01-27T20:05:49+07:00" level=debug msg="app state loaded" Jan 27 20:05:49 volumio go-librespot[17201]: time="2026-01-27T20:05:49+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 20:05:49 volumio mpd[17110]: 2026-01-27T20:05:49 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 27 20:05:49 volumio systemd[1]: Started mpd.service - Music Player Daemon. Jan 27 20:05:49 volumio sudo[17081]: pam_unix(sudo:session): session closed for user root Jan 27 20:05:49 volumio sudo[17071]: pam_unix(sudo:session): session closed for user root Jan 27 20:05:49 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 20:05:49 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 20:05:49 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 20:05:49 volumio volumio[16880]: error: MPD error: The expression evaluated to a falsy value: Jan 27 20:05:49 volumio volumio[16880]: assert.ok(self.idling) Jan 27 20:05:49 volumio volumio[16880]: error: The expression evaluated to a falsy value: Jan 27 20:05:49 volumio volumio[16880]: assert.ok(self.idling) Jan 27 20:05:49 volumio volumio[16880]: error: updateQueue error: null Jan 27 20:05:49 volumio volumio[16880]: info: MPD running with PID17110 Jan 27 20:05:49 volumio volumio[16880]: ,establishing connection Jan 27 20:05:49 volumio go-librespot[17201]: time="2026-01-27T20:05:49+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 27 20:05:49 volumio go-librespot[17201]: time="2026-01-27T20:05:49+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 27 20:05:49 volumio go-librespot[17201]: time="2026-01-27T20:05:49+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 27 20:05:49 volumio go-librespot[17201]: time="2026-01-27T20:05:49+07:00" level=info msg="zeroconf server listening on port 36653" Jan 27 20:05:49 volumio volumio[16880]: info: Completed starting Core Plugins Jan 27 20:05:49 volumio volumio[16880]: info: ------------------------------------------- Jan 27 20:05:49 volumio volumio[16880]: info: ----- MyVolumio plugins startup ---- Jan 27 20:05:49 volumio volumio[16880]: info: ------------------------------------------- Jan 27 20:05:49 volumio volumio[16880]: info: [MyVolumio PluginManager] Fetching plans data.... Jan 27 20:05:49 volumio volumio[16880]: error: updateQueue error: null Jan 27 20:05:49 volumio go-librespot[17201]: time="2026-01-27T20:05:49+07:00" level=debug msg="obtained new client token: AACdAVq4Uh9KeH7f3W+wlr/0AdI9lUbR9w8rnhzoRH+dSJ1mGiipFvAIzZLedn8iztZe4aTnPquemjGIh+vPfJmXuilZDDiCqFGVmE9fHCPvwnn4XjqlTTTuLRo4yU0QN1oePNlU/kN8x1Vs3c0sB/ESaacWE29uXvD5UX+jc+wAlTEl3d3kMCPMWZpVUCCvINgMxLsgql/kG1lTVwOrImtmp85zYR8xFJUeqXhTvUh2BX5bHs8U3RJLaWw=" Jan 27 20:05:50 volumio go-librespot[17201]: time="2026-01-27T20:05:50+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 20:05:50 volumio go-librespot[17201]: time="2026-01-27T20:05:50+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Jan 27 20:05:50 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 20:05:50 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 20:05:51 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 20:05:51 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 20:05:51 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 20:05:52 volumio volumio[16880]: info: Initializing connection to go-librespot Websocket Jan 27 20:05:52 volumio volumio[16880]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 27 20:05:53 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 11. Jan 27 20:05:53 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 20:05:53 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 20:05:53 volumio go-librespot[17215]: go-librespot daemon starting... Jan 27 20:05:53 volumio go-librespot[17216]: time="2026-01-27T20:05:53+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 20:05:53 volumio go-librespot[17216]: time="2026-01-27T20:05:53+07:00" level=debug msg="app state loaded" Jan 27 20:05:53 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 20:05:53 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 20:05:53 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 20:05:53 volumio go-librespot[17216]: time="2026-01-27T20:05:53+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 20:05:53 volumio go-librespot[17216]: time="2026-01-27T20:05:53+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 27 20:05:53 volumio go-librespot[17216]: time="2026-01-27T20:05:53+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 27 20:05:53 volumio go-librespot[17216]: time="2026-01-27T20:05:53+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 27 20:05:53 volumio go-librespot[17216]: time="2026-01-27T20:05:53+07:00" level=info msg="zeroconf server listening on port 44693" Jan 27 20:05:54 volumio go-librespot[17216]: time="2026-01-27T20:05:54+07:00" level=debug msg="obtained new client token: AABlY1S1eXhEhmbfVwNLXJ+UeoTh8ar3HtungMSHx9XzLKy2++EqwgDX5vwVqpAyQLvAjlYRyKShRVjDXZJiYfJJKFPddIJvwT2apINUg5CrobSUJBSC7fy3o91hJPklYVhVg4quj01jcCZwrfKHRU9pEsG2vpU8oDkFGGp4N1w4VD0axdlj5HgmGAHgq2DDgXFnJVVvJG+wltnN3unDU7HMjqbjZyQNBRtSvDP+zFdS/n+KH2xolpjX" Jan 27 20:05:54 volumio go-librespot[17216]: time="2026-01-27T20:05:54+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 20:05:54 volumio go-librespot[17216]: time="2026-01-27T20:05:54+07:00" level=debug msg="completed keyexchange" Jan 27 20:05:54 volumio go-librespot[17216]: time="2026-01-27T20:05:54+07:00" level=debug msg="completed challenge" Jan 27 20:05:54 volumio go-librespot[17216]: time="2026-01-27T20:05:54+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 27 20:05:54 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 20:05:54 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 20:05:54 volumio volumio[16880]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Jan 27 20:05:55 volumio volumio[16880]: info: Initializing connection to go-librespot Websocket Jan 27 20:05:55 volumio volumio[16880]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 27 20:05:55 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 20:05:55 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 20:05:55 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 20:05:57 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 20:05:57 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 20:05:57 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 20:05:57 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 12. Jan 27 20:05:57 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 20:05:57 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 20:05:57 volumio go-librespot[17224]: go-librespot daemon starting... Jan 27 20:05:57 volumio go-librespot[17225]: time="2026-01-27T20:05:57+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 20:05:57 volumio go-librespot[17225]: time="2026-01-27T20:05:57+07:00" level=debug msg="app state loaded" Jan 27 20:05:57 volumio go-librespot[17225]: time="2026-01-27T20:05:57+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 20:05:58 volumio volumio[16880]: info: Initializing connection to go-librespot Websocket Jan 27 20:05:58 volumio go-librespot[17225]: time="2026-01-27T20:05:58+07:00" level=debug msg="new websocket client" Jan 27 20:05:58 volumio volumio[16880]: info: Connection to go-librespot Websocket established Jan 27 20:05:58 volumio go-librespot[17225]: time="2026-01-27T20:05:58+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 27 20:05:58 volumio go-librespot[17225]: time="2026-01-27T20:05:58+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 27 20:05:58 volumio go-librespot[17225]: time="2026-01-27T20:05:58+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 27 20:05:58 volumio go-librespot[17225]: time="2026-01-27T20:05:58+07:00" level=info msg="zeroconf server listening on port 45247" Jan 27 20:05:58 volumio go-librespot[17225]: time="2026-01-27T20:05:58+07:00" level=debug msg="obtained new client token: AADQTg6yJ1zXUwzkcGZTbnYxkox9s8rDySZTvTyZxpegP7VBiVqc8dMiE6+YCXfW6APrX6jlUSgEfNgFoUwuf3oe8q2TJkgJzj8HzuMonInwaQxZz7xAK/sGALGZn0KI3RkSTYAFGHiJKNaUXKjw2aE6YPfQIt0RMn+6pJRrPc0ESqg5tOrJCaM659wwN8Jx9B8iQWsmwhTIHATYE8DgvtEY/owbXnCCJTDLsOlWCgHQ4g7/gvswqhYPfTc=" Jan 27 20:05:58 volumio go-librespot[17225]: time="2026-01-27T20:05:58+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 20:05:58 volumio go-librespot[17225]: time="2026-01-27T20:05:58+07:00" level=debug msg="completed keyexchange" Jan 27 20:05:58 volumio go-librespot[17225]: time="2026-01-27T20:05:58+07:00" level=debug msg="completed challenge" Jan 27 20:05:58 volumio go-librespot[17225]: time="2026-01-27T20:05: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 27 20:05:58 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 20:05:58 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 20:05:58 volumio volumio[16880]: info: Connection to go-librespot Websocket closed Jan 27 20:05:58 volumio volumio[16880]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Jan 27 20:05:58 volumio volumio[16880]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Jan 27 20:05:58 volumio volumio[16880]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Jan 27 20:05:58 volumio volumio[16880]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Jan 27 20:05:58 volumio volumio[16880]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Jan 27 20:05:58 volumio volumio[16880]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Jan 27 20:05:58 volumio volumio[16880]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Jan 27 20:05:58 volumio volumio[16880]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Jan 27 20:05:58 volumio volumio[16880]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Jan 27 20:05:58 volumio volumio[16880]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Jan 27 20:05:58 volumio volumio[16880]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Jan 27 20:05:58 volumio volumio[16880]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Jan 27 20:05:58 volumio volumio[16880]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Jan 27 20:05:58 volumio volumio[16880]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Jan 27 20:05:58 volumio volumio[16880]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Jan 27 20:05:58 volumio volumio[16880]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Jan 27 20:05:58 volumio volumio[16880]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Jan 27 20:05:58 volumio volumio[16880]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Jan 27 20:05:58 volumio volumio[16880]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Jan 27 20:05:58 volumio volumio[16880]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Jan 27 20:05:58 volumio volumio[16880]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Jan 27 20:05:58 volumio volumio[16880]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Jan 27 20:05:58 volumio volumio[16880]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Jan 27 20:05:58 volumio volumio[16880]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Jan 27 20:05:58 volumio volumio[16880]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Jan 27 20:05:58 volumio volumio[16880]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Jan 27 20:05:58 volumio volumio[16880]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Jan 27 20:05:58 volumio volumio[16880]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Jan 27 20:05:58 volumio volumio[16880]: info: Adding plugin bluetooth to MyMusic Plugins Jan 27 20:05:58 volumio volumio[16880]: info: Adding plugin multiroom to MyMusic Plugins Jan 27 20:05:58 volumio volumio[16880]: info: Adding plugin metavolumio to MyMusic Plugins Jan 27 20:05:58 volumio volumio[16880]: info: Adding plugin cd_controller to MyMusic Plugins Jan 27 20:05:58 volumio volumio[16880]: info: Adding plugin qobuzconnect to MyMusic Plugins Jan 27 20:05:58 volumio volumio[16880]: info: Adding plugin smart_inputs to MyMusic Plugins Jan 27 20:05:58 volumio volumio[16880]: info: Adding plugin tidalconnect to MyMusic Plugins Jan 27 20:05:58 volumio volumio[16880]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Jan 27 20:05:59 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 20:05:59 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 20:05:59 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 20:06:00 volumio volumio[16880]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Jan 27 20:06:00 volumio volumio[16880]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Jan 27 20:06:00 volumio volumio[16880]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 20:06:00 volumio volumio[16880]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 20:06:00 volumio volumio[16880]: info: Starting MyVolumio Remote Streaming Endpoints Jan 27 20:06:00 volumio volumio[16880]: info: MyVolumio login type: Token Jan 27 20:06:00 volumio volumio[16880]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Jan 27 20:06:00 volumio volumio[16880]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Jan 27 20:06:01 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 20:06:01 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 20:06:01 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 20:06:01 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 13. Jan 27 20:06:01 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 20:06:01 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 20:06:01 volumio go-librespot[17248]: go-librespot daemon starting... Jan 27 20:06:01 volumio go-librespot[17249]: time="2026-01-27T20:06:01+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 20:06:01 volumio go-librespot[17249]: time="2026-01-27T20:06:01+07:00" level=debug msg="app state loaded" Jan 27 20:06:01 volumio go-librespot[17249]: time="2026-01-27T20:06:01+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 20:06:02 volumio go-librespot[17249]: time="2026-01-27T20:06:02+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 27 20:06:02 volumio go-librespot[17249]: time="2026-01-27T20:06:02+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 27 20:06:02 volumio go-librespot[17249]: time="2026-01-27T20:06:02+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 27 20:06:02 volumio volumio[16880]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Jan 27 20:06:02 volumio volumio[16880]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Jan 27 20:06:02 volumio volumio[16880]: info: Streaming services startup Jan 27 20:06:02 volumio volumio[16880]: info: Starting Streaming Daemon Jan 27 20:06:02 volumio go-librespot[17249]: time="2026-01-27T20:06:02+07:00" level=info msg="zeroconf server listening on port 37513" Jan 27 20:06:02 volumio sudo[17258]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jan 27 20:06:02 volumio volumio[16880]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Jan 27 20:06:02 volumio sudo[17258]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 20:06:02 volumio sudo[17258]: pam_unix(sudo:session): session closed for user root Jan 27 20:06:02 volumio volumio[16880]: info: Getting Spotify volume Jan 27 20:06:02 volumio volumio[16880]: info: Initializing connection to go-librespot Websocket Jan 27 20:06:02 volumio volumio[16880]: error: Cannot start Volumio Streaming Daemon Jan 27 20:06:02 volumio volumio[16880]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Jan 27 20:06:02 volumio volumio[16880]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Jan 27 20:06:02 volumio go-librespot[17249]: time="2026-01-27T20:06:02+07:00" level=debug msg="obtained new client token: AACGXHHY6BAgOTaggS+xrnCPsxsjAwruasPBHsBSQ3HEcctFko1XWr/N9RbjosZa1ihQ/QfzXqJwpQbbiBmfKQ1HJX4e8jCoYKysfmdPiTGdeCDv1od4f7P18CFkVALx7MqYyrRxKnDrRvC3w2pueebvAiR5/Sf8/ur1x/qHbcWjITPQTzlh5R67BQNFajuiXK/iChKbP4ww4OtqfgUwbfMZ0AZzIx1NAD0rhRE3zE2Z8QiHvPnt2naTSc0=" Jan 27 20:06:02 volumio go-librespot[17249]: time="2026-01-27T20:06:02+07:00" level=debug msg="new websocket client" Jan 27 20:06:02 volumio volumio[16880]: 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 27 20:06:02 volumio volumio[16880]: info: Connection to go-librespot Websocket established Jan 27 20:06:02 volumio go-librespot[17249]: time="2026-01-27T20:06:02+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 20:06:02 volumio go-librespot[17249]: time="2026-01-27T20:06:02+07:00" level=debug msg="completed keyexchange" Jan 27 20:06:02 volumio go-librespot[17249]: time="2026-01-27T20:06:02+07:00" level=debug msg="completed challenge" Jan 27 20:06:02 volumio volumio[16880]: info: CoreCommandRouter::volumioGetState Jan 27 20:06:02 volumio volumio[16880]: info: CorePlayQueue::getTrack 0 Jan 27 20:06:02 volumio volumio[16880]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jan 27 20:06:02 volumio volumio[16880]: SPOTIFY: SPOTIFY VOLUME undefined Jan 27 20:06:02 volumio volumio[16880]: SPOTIFY: VOLUMIO VOLUME 100 Jan 27 20:06:02 volumio volumio[16880]: info: Aligning Spotify Volume to Volumio Volume Jan 27 20:06:02 volumio volumio[16880]: info: CoreCommandRouter::volumioGetState Jan 27 20:06:02 volumio volumio[16880]: info: CorePlayQueue::getTrack 0 Jan 27 20:06:02 volumio volumio[16880]: info: Setting Spotify Volume from Volumio: 100 Jan 27 20:06:02 volumio go-librespot[17249]: time="2026-01-27T20:06: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 27 20:06:03 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 20:06:03 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 20:06:03 volumio volumio[16880]: info: Connection to go-librespot Websocket closed Jan 27 20:06:03 volumio volumio[16880]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 27 20:06:03 volumio volumio[16880]: Error: socket hang up Jan 27 20:06:03 volumio volumio[16880]: at connResetException (node:internal/errors:720:14) Jan 27 20:06:03 volumio volumio[16880]: at Socket.socketOnEnd (node:_http_client:519:23) Jan 27 20:06:03 volumio volumio[16880]: at Socket.emit (node:events:526:35) Jan 27 20:06:03 volumio volumio[16880]: at endReadableNT (node:internal/streams/readable:1376:12) Jan 27 20:06:03 volumio volumio[16880]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Jan 27 20:06:03 volumio volumio[16880]: code: 'ECONNRESET', Jan 27 20:06:03 volumio volumio[16880]: response: undefined Jan 27 20:06:03 volumio volumio[16880]: } Jan 27 20:06:03 volumio volumio[16880]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 27 20:06:03 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 20:06:03 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 20:06:03 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 20:06:04 volumio sudo[17278]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-01-27 20:05' Jan 27 20:06:04 volumio sudo[17278]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 20:06:04 volumio sudo[17278]: pam_unix(sudo:session): session closed for user root Jan 27 20:06:05 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 20:06:05 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 20:06:05 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 20:06:06 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 14. Jan 27 20:06:06 volumio volumio-remote-updater[628]: [2026-01-27 20:06:06] [error] handle_read_frame error: asio.system:104 (Connection reset by peer) Jan 27 20:06:06 volumio volumio-remote-updater[628]: [2026-01-27 20:06:06] [disconnect] Disconnect close local:[1006,Connection reset by peer] remote:[1006] Jan 27 20:06:06 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Jan 27 20:06:06 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 20:06:06 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 20:06:06 volumio go-librespot[17286]: go-librespot daemon starting... Jan 27 20:06:06 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Jan 27 20:06:06 volumio systemd[1]: volumio.service: Consumed 55.939s CPU time. Jan 27 20:06:06 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 27 20:06:06 volumio go-librespot[17287]: time="2026-01-27T20:06:06+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 20:06:06 volumio go-librespot[17287]: time="2026-01-27T20:06:06+07:00" level=debug msg="app state loaded" Jan 27 20:06:06 volumio go-librespot[17287]: time="2026-01-27T20:06:06+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 20:06:06 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Jan 27 20:06:06 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 9060. Jan 27 20:06:06 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 27 20:06:06 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Jan 27 20:06:06 volumio systemd[1]: volumio.service: Consumed 55.939s CPU time. Jan 27 20:06:06 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Jan 27 20:06:06 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Jan 27 20:06:06 volumio go-librespot[17287]: time="2026-01-27T20:06: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 27 20:06:06 volumio go-librespot[17287]: time="2026-01-27T20:06: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 27 20:06:06 volumio go-librespot[17287]: time="2026-01-27T20:06: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 27 20:06:06 volumio go-librespot[17287]: time="2026-01-27T20:06:06+07:00" level=info msg="zeroconf server listening on port 32931" Jan 27 20:06:07 volumio go-librespot[17287]: time="2026-01-27T20:06:07+07:00" level=debug msg="obtained new client token: AADdJLByK6ybkslDvngv0C/gS04ka7eaWux+dImZmDv6mCtTzsZhs/T3OZ7c9pjJFb9tA3LnZgwGNJZozmoiwwgVWaCE0pDQD+Y3zWNJb8lkt1rfLl1qxPGfoDLjiIksQWFZVbPbf33Q3sNhmMNTtPTbbkmLelH1mE+IVpMcuMOP0U+/6RsfcmI4QoAa5RKx2A/CzipNGZzfcYNsEknKlW7tFGUm7KpYOr1rnFu7scKPy75uVXBf7nP/" Jan 27 20:06:07 volumio go-librespot[17287]: time="2026-01-27T20:06:07+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 20:06:07 volumio go-librespot[17287]: time="2026-01-27T20:06:07+07:00" level=debug msg="completed keyexchange" Jan 27 20:06:07 volumio go-librespot[17287]: time="2026-01-27T20:06:07+07:00" level=debug msg="completed challenge" Jan 27 20:06:07 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 20:06:07 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 20:06:07 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 20:06:07 volumio go-librespot[17287]: time="2026-01-27T20:06: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 27 20:06:07 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 20:06:07 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 20:06:09 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 20:06:09 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 20:06:09 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 20:06:10 volumio volumio[17300]: info: ------------------------------------------- Jan 27 20:06:10 volumio volumio[17300]: info: ----- Volumio3 ---- Jan 27 20:06:10 volumio volumio[17300]: info: ------------------------------------------- Jan 27 20:06:10 volumio volumio[17300]: info: ----- System startup ---- Jan 27 20:06:10 volumio volumio[17300]: info: ------------------------------------------- Jan 27 20:06:10 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 15. Jan 27 20:06:10 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 20:06:10 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 20:06:10 volumio go-librespot[17322]: go-librespot daemon starting... Jan 27 20:06:10 volumio go-librespot[17323]: time="2026-01-27T20:06:10+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 20:06:10 volumio go-librespot[17323]: time="2026-01-27T20:06:10+07:00" level=debug msg="app state loaded" Jan 27 20:06:10 volumio go-librespot[17323]: time="2026-01-27T20:06:10+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 20:06:11 volumio go-librespot[17323]: time="2026-01-27T20:06:11+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 27 20:06:11 volumio go-librespot[17323]: time="2026-01-27T20:06:11+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 27 20:06:11 volumio go-librespot[17323]: time="2026-01-27T20:06:11+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 27 20:06:11 volumio go-librespot[17323]: time="2026-01-27T20:06:11+07:00" level=info msg="zeroconf server listening on port 35345" Jan 27 20:06:11 volumio volumio-remote-updater[628]: [2026-01-27 20:06:11] [connect] Successful connection Jan 27 20:06:11 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 20:06:11 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 20:06:11 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 20:06:11 volumio go-librespot[17323]: time="2026-01-27T20:06:11+07:00" level=debug msg="obtained new client token: AADgqERuIFhPS1kDknJ2Rku4qP9MsGT/YIupvcW99hdmoJQKU8WSwDSNGbPSqDehv4KMvMkHUZGU1O/+ps8zeBEaUH6L2OBA3eS14Sr+1rO0sRdUukNbVW7JuSzYuD3S56nsRlv01pvlxr6qaJES+NTB8n1FTdMu+rq9yKTmpmctEo1Ne5kJp8IMsr3a2xNIzK3hWha2rPm1JQfw11UWFqnj6NellRc5Q7AmzMxwW7u0oxB9xX4ALn0gBzc=" Jan 27 20:06:11 volumio go-librespot[17323]: time="2026-01-27T20:06:11+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 20:06:11 volumio go-librespot[17323]: time="2026-01-27T20:06:11+07:00" level=debug msg="completed keyexchange" Jan 27 20:06:11 volumio go-librespot[17323]: time="2026-01-27T20:06:11+07:00" level=debug msg="completed challenge" Jan 27 20:06:11 volumio volumio[17300]: info: MYVOLUMIO Environment detected Jan 27 20:06:11 volumio go-librespot[17323]: time="2026-01-27T20:06:11+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 27 20:06:11 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 20:06:11 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 20:06:11 volumio volumio[17300]: info: Plugin folders cleanup Jan 27 20:06:11 volumio volumio[17300]: info: Scanning into folder /volumio/app/plugins/ Jan 27 20:06:11 volumio volumio[17300]: info: Scanning category audio_interface Jan 27 20:06:11 volumio volumio[17300]: info: Scanning category miscellanea Jan 27 20:06:11 volumio volumio[17300]: info: Scanning category music_service Jan 27 20:06:11 volumio volumio[17300]: info: Scanning category plugins.json Jan 27 20:06:11 volumio volumio[17300]: info: Scanning category system_controller Jan 27 20:06:11 volumio volumio[17300]: info: Scanning category user_interface Jan 27 20:06:11 volumio volumio[17300]: info: Scanning into folder /data/plugins/ Jan 27 20:06:11 volumio volumio[17300]: info: Scanning category music_service Jan 27 20:06:11 volumio volumio[17300]: info: Plugin folders cleanup completed Jan 27 20:06:11 volumio volumio[17300]: info: ------------------------------------------- Jan 27 20:06:11 volumio volumio[17300]: info: ----- Core plugins startup ---- Jan 27 20:06:11 volumio volumio[17300]: info: ------------------------------------------- Jan 27 20:06:11 volumio volumio[17300]: info: Loading plugins from folder /volumio/app/plugins/ Jan 27 20:06:11 volumio volumio[17300]: info: Adding plugin upnp to MyMusic Plugins Jan 27 20:06:11 volumio volumio[17300]: info: Adding plugin airplay_emulation to MyMusic Plugins Jan 27 20:06:11 volumio volumio[17300]: info: Adding plugin upnp_browser to MyMusic Plugins Jan 27 20:06:11 volumio volumio[17300]: info: Loading plugins from folder /data/plugins/ Jan 27 20:06:11 volumio volumio[17300]: info: Loading plugin "system"... Jan 27 20:06:11 volumio volumio[17300]: info: Loading plugin "appearance"... Jan 27 20:06:13 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 20:06:13 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 20:06:13 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 20:06:13 volumio volumio[17300]: info: Loading plugin "network"... Jan 27 20:06:13 volumio volumio[17300]: info: Refreshing Cached IP Addresses Jan 27 20:06:13 volumio sudo[17339]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 27 20:06:13 volumio sudo[17339]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 20:06:13 volumio volumio[17300]: info: Loading plugin "services"... Jan 27 20:06:13 volumio sudo[17341]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 27 20:06:13 volumio sudo[17341]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 20:06:13 volumio volumio[17300]: info: Loading plugin "alsa_controller"... Jan 27 20:06:13 volumio sudo[17339]: pam_unix(sudo:session): session closed for user root Jan 27 20:06:13 volumio sudo[17341]: pam_unix(sudo:session): session closed for user root Jan 27 20:06:13 volumio sudo[17349]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Jan 27 20:06:13 volumio sudo[17349]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 20:06:14 volumio volumio[17300]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 27 20:06:14 volumio volumio[17300]: info: Loading plugin "wizard"... Jan 27 20:06:14 volumio volumio[17300]: info: Loading plugin "networkfs"... Jan 27 20:06:14 volumio volumio[17300]: info: Starting Udev Watcher for removable devices Jan 27 20:06:14 volumio volumio[17300]: info: Ignoring mount for partition: boot Jan 27 20:06:14 volumio volumio[17300]: info: Ignoring mount for partition: volumio Jan 27 20:06:14 volumio volumio[17300]: info: Ignoring mount for partition: volumio_data Jan 27 20:06:14 volumio volumio[17300]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 27 20:06:14 volumio volumio[17300]: info: Loading plugin "volumio_command_line_client"... Jan 27 20:06:14 volumio volumio[17300]: info: Loading plugin "upnp"... Jan 27 20:06:14 volumio volumio[17300]: info: [1769519174224] Starting Upmpd Daemon Jan 27 20:06:14 volumio volumio[17300]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 27 20:06:14 volumio volumio[17300]: info: Loading plugin "my_music"... Jan 27 20:06:14 volumio volumio[17300]: info: Loading plugin "mpd"... Jan 27 20:06:14 volumio volumio[17300]: info: Loading plugin "upnp_browser"... Jan 27 20:06:14 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 16. Jan 27 20:06:14 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 20:06:15 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 20:06:15 volumio go-librespot[17372]: go-librespot daemon starting... Jan 27 20:06:15 volumio go-librespot[17373]: time="2026-01-27T20:06:15+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 20:06:15 volumio go-librespot[17373]: time="2026-01-27T20:06:15+07:00" level=debug msg="app state loaded" Jan 27 20:06:15 volumio go-librespot[17373]: time="2026-01-27T20:06:15+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 20:06:15 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 20:06:15 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 20:06:15 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 20:06:15 volumio go-librespot[17373]: time="2026-01-27T20:06:15+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 27 20:06:15 volumio go-librespot[17373]: time="2026-01-27T20:06:15+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 27 20:06:15 volumio go-librespot[17373]: time="2026-01-27T20:06:15+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 27 20:06:15 volumio go-librespot[17373]: time="2026-01-27T20:06:15+07:00" level=info msg="zeroconf server listening on port 33149" Jan 27 20:06:15 volumio go-librespot[17373]: time="2026-01-27T20:06:15+07:00" level=debug msg="obtained new client token: AABxzjQDo9dg/lTcHJXiXKPSG+uXrNZP4y5wCSGJWqFtsc3SEIIJoEm0qQx0PEVR3h2KcaPAl67thM2K5aUBJ5K2Fp+7RIE5K6brws1Z7WKEz9ZARvCjVOotQ97t668MlkH7peuANO4IznwwIGQu77fBNWZ8WX9sz+6Ut6RAaO7mLcssEoWigToq6zj19y8IrOY4oo4GUOcK7VilUYlVil+qAYK/897DgHR3d7IPw3Xw4sqneEiSFV+FNQ0=" Jan 27 20:06:16 volumio go-librespot[17373]: time="2026-01-27T20:06:16+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 20:06:16 volumio go-librespot[17373]: time="2026-01-27T20:06:16+07:00" level=debug msg="completed keyexchange" Jan 27 20:06:16 volumio go-librespot[17373]: time="2026-01-27T20:06:16+07:00" level=debug msg="completed challenge" Jan 27 20:06:16 volumio go-librespot[17373]: time="2026-01-27T20:06: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 27 20:06:16 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 20:06:16 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 20:06:16 volumio sudo[17349]: pam_unix(sudo:session): session closed for user root Jan 27 20:06:17 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 20:06:17 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 20:06:17 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 20:06:17 volumio volumio[17300]: info: Starting UPNP Browser Jan 27 20:06:17 volumio volumio[17300]: info: Loading plugin "alarm-clock"... Jan 27 20:06:18 volumio volumio[17300]: info: Loading plugin "airplay_emulation"... Jan 27 20:06:18 volumio volumio[17300]: info: Starting Shairport Sync Jan 27 20:06:18 volumio volumio[17300]: info: Loading plugin "last_100"... Jan 27 20:06:18 volumio volumio[17300]: info: Loading plugin "webradio"... Jan 27 20:06:18 volumio volumio[17300]: info: Loading plugin "i2s_dacs"... Jan 27 20:06:18 volumio volumio[17300]: info: Loading plugin "volumiodiscovery"... Jan 27 20:06:18 volumio volumio[17300]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 27 20:06:18 volumio node[17300]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 27 20:06:18 volumio volumio[17300]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 27 20:06:18 volumio volumio[17300]: *** WARNING *** For more information see Jan 27 20:06:18 volumio volumio[17300]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 27 20:06:18 volumio volumio[17300]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 27 20:06:18 volumio volumio[17300]: *** WARNING *** For more information see Jan 27 20:06:18 volumio node[17300]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 27 20:06:18 volumio node[17300]: *** WARNING *** For more information see Jan 27 20:06:18 volumio node[17300]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 27 20:06:18 volumio node[17300]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 27 20:06:18 volumio node[17300]: *** WARNING *** For more information see Jan 27 20:06:18 volumio volumio[17300]: info: Applying required configuration parameters for plugin volumiodiscovery Jan 27 20:06:18 volumio volumio[17300]: info: Discovery: Started advertising with name: Volumio Jan 27 20:06:18 volumio volumio[17300]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 27 20:06:18 volumio volumio[17300]: info: Loading plugin "spop"... Jan 27 20:06:19 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 17. Jan 27 20:06:19 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 20:06:19 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 20:06:19 volumio go-librespot[17382]: go-librespot daemon starting... Jan 27 20:06:19 volumio go-librespot[17383]: time="2026-01-27T20:06:19+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 20:06:19 volumio go-librespot[17383]: time="2026-01-27T20:06:19+07:00" level=debug msg="app state loaded" Jan 27 20:06:19 volumio go-librespot[17383]: time="2026-01-27T20:06:19+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 20:06:19 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 20:06:19 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 20:06:19 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 20:06:19 volumio go-librespot[17383]: time="2026-01-27T20:06:19+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 27 20:06:19 volumio go-librespot[17383]: time="2026-01-27T20:06:19+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 27 20:06:19 volumio go-librespot[17383]: time="2026-01-27T20:06:19+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 27 20:06:19 volumio go-librespot[17383]: time="2026-01-27T20:06:19+07:00" level=info msg="zeroconf server listening on port 34633" Jan 27 20:06:20 volumio go-librespot[17383]: time="2026-01-27T20:06:20+07:00" level=debug msg="obtained new client token: AABb3hWXePXXfISNiBhLAtNTBkG/MO3KoEoeG/a3S3ZNKDubnn8bVSg8795YDvLtq5ot5kvZ4lqZqqwYQxvYwaH2Oc/JK9My0+L+zD2LhDaX7cQITsS7iqQdjAoe6qpwpYv6l91jQHjqPL5sQc2+14Vf3TxctOlvafveEEoiGhrD3THa/rRapEQXu1YURLYyaluIO9yQETw2PB6cn9knpubP0rCWzGOMHDfe/OxxSCq3spehG61qt3Ga" Jan 27 20:06:20 volumio go-librespot[17383]: time="2026-01-27T20:06:20+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 27 20:06:20 volumio go-librespot[17383]: time="2026-01-27T20:06:20+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Jan 27 20:06:20 volumio go-librespot[17383]: time="2026-01-27T20:06:20+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Jan 27 20:06:20 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 20:06:20 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 20:06:20 volumio volumio[17300]: info: Loading plugin "ytcr"... Jan 27 20:06:21 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 20:06:21 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 20:06:21 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 20:06:23 volumio volumio[17300]: info: Loading plugin "ytmusic"... Jan 27 20:06:23 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 20:06:23 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 20:06:23 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 20:06:23 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 18. Jan 27 20:06:23 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 20:06:23 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 20:06:23 volumio go-librespot[17391]: go-librespot daemon starting... Jan 27 20:06:23 volumio go-librespot[17392]: time="2026-01-27T20:06:23+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 20:06:23 volumio go-librespot[17392]: time="2026-01-27T20:06:23+07:00" level=debug msg="app state loaded" Jan 27 20:06:23 volumio go-librespot[17392]: time="2026-01-27T20:06:23+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 20:06:23 volumio volumio-remote-updater[628]: [2026-01-27 20:06:23] [connect] Successful connection Jan 27 20:06:24 volumio volumio[17300]: info: Loading plugin "outputs"... Jan 27 20:06:24 volumio volumio[17300]: info: Loading plugin "albumart"... Jan 27 20:06:24 volumio volumio[17300]: info: Plugin example_plugin is not enabled Jan 27 20:06:24 volumio volumio[17300]: info: Loading plugin "inputs"... Jan 27 20:06:24 volumio volumio[17300]: info: Loading plugin "updater_comm"... Jan 27 20:06:24 volumio go-librespot[17392]: time="2026-01-27T20:06: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-gew4.spotify.com:80]" Jan 27 20:06:24 volumio go-librespot[17392]: time="2026-01-27T20:06:24+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 27 20:06:24 volumio go-librespot[17392]: time="2026-01-27T20:06:24+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 27 20:06:24 volumio go-librespot[17392]: time="2026-01-27T20:06:24+07:00" level=info msg="zeroconf server listening on port 39613" Jan 27 20:06:24 volumio volumio[17300]: info: Plugin mpdemulation is not enabled Jan 27 20:06:24 volumio volumio[17300]: info: Loading plugin "rest_api"... Jan 27 20:06:24 volumio volumio[17300]: info: Loading plugin "websocket"... Jan 27 20:06:24 volumio go-librespot[17392]: time="2026-01-27T20:06:24+07:00" level=debug msg="obtained new client token: AAA4tYDJhxgBj0E/amTLf9p/KUVKXQYuI5/XiikGoxSOYoZAXkzcXZgfhpa2JRrirdJutZxdaLTJS9667lnkEMLPY+mONo/4gT9A67SCRdtO+W/yOKJl32fremcdafjMJZub7ASfo8ijIWSLajA7qOGnO0wtjYJO3kv5ZeuzvOh+tDOSWAY0BDtairSKbqrJ9jdNY9VURoCanKF70/ms892KDBPzcgLBnxr4dzPo6rSWbsgpFvMzgyn1F/0=" Jan 27 20:06:24 volumio volumio[17300]: info: Starting Socket.io Server version 1.7.4 Jan 27 20:06:24 volumio volumio[17300]: info: Loading plugin "RoonBridge"... Jan 27 20:06:24 volumio go-librespot[17392]: time="2026-01-27T20:06:24+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 20:06:24 volumio go-librespot[17392]: time="2026-01-27T20:06:24+07:00" level=debug msg="completed keyexchange" Jan 27 20:06:24 volumio go-librespot[17392]: time="2026-01-27T20:06:24+07:00" level=debug msg="completed challenge" Jan 27 20:06:24 volumio go-librespot[17392]: time="2026-01-27T20:06:24+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 27 20:06:24 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 20:06:24 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 20:06:25 volumio volumio[17300]: info: Applying required configuration parameters for plugin RoonBridge Jan 27 20:06:25 volumio volumio[17300]: info: Loading i18n strings for locale en Jan 27 20:06:25 volumio volumio[17300]: Updating browse sources language Jan 27 20:06:25 volumio volumio[17300]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 27 20:06:25 volumio volumio[17300]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 27 20:06:25 volumio volumio[17300]: info: CoreCommandRouter::initPlayerControls Jan 27 20:06:25 volumio volumio[17300]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 20:06:25 volumio volumio[17300]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 20:06:25 volumio volumio[17300]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 20:06:25 volumio volumio[17300]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 20:06:25 volumio volumio[17300]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 20:06:25 volumio volumio[17300]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 20:06:25 volumio volumio[17300]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 20:06:25 volumio volumio[17300]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 20:06:25 volumio volumio[17300]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 27 20:06:25 volumio volumio[17300]: Express server listening on port 3000 Jan 27 20:06:25 volumio volumio[17300]: [Metrics] WebUI: 16s 78.73ms Jan 27 20:06:25 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 20:06:25 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 20:06:25 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 20:06:25 volumio volumio[17300]: info: CoreStateMachine::resetVolumioState Jan 27 20:06:25 volumio volumio[17300]: info: CoreStateMachine::getcurrentVolume Jan 27 20:06:25 volumio volumio[17300]: info: CoreCommandRouter::volumioRetrievevolume Jan 27 20:06:25 volumio volumio[17413]: Forking 3 albumart workers Jan 27 20:06:25 volumio sudo[17428]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 27 20:06:25 volumio sudo[17428]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 20:06:25 volumio sudo[17430]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 27 20:06:25 volumio sudo[17430]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 20:06:25 volumio sudo[17430]: pam_unix(sudo:session): session closed for user root Jan 27 20:06:25 volumio sudo[17428]: pam_unix(sudo:session): session closed for user root Jan 27 20:06:25 volumio volumio[17300]: info: Volumio Network Manager: Network status updated: 1 Jan 27 20:06:25 volumio volumio[17300]: info: VolumeController:: Volume=100 Mute =false Jan 27 20:06:25 volumio volumio[17300]: info: CoreStateMachine::pushState Jan 27 20:06:25 volumio volumio[17300]: info: CorePlayQueue::getTrack 0 Jan 27 20:06:25 volumio volumio[17300]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 27 20:06:25 volumio volumio[17300]: info: CoreCommandRouter::volumioPushState Jan 27 20:06:25 volumio volumio[17300]: info: CoreStateMachine::updateTrackBlock Jan 27 20:06:25 volumio volumio[17300]: info: CorePlayQueue::getTrackBlock Jan 27 20:06:25 volumio volumio[17300]: info: CoreCommandRouter::volumioRetrievevolume Jan 27 20:06:25 volumio volumio-remote-updater[628]: [2026-01-27 20:06:25] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1769519183 101 Jan 27 20:06:26 volumio volumio[17300]: 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 27 20:06:26 volumio volumio[17300]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 20:06:26 volumio volumio[17300]: info: Reloading queue from file Jan 27 20:06:26 volumio volumio[17300]: info: CoreStateMachine::setRepeat null single undefined Jan 27 20:06:26 volumio volumio[17300]: info: CoreStateMachine::pushState Jan 27 20:06:26 volumio volumio[17300]: info: CorePlayQueue::getTrack 0 Jan 27 20:06:26 volumio volumio[17300]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 27 20:06:26 volumio volumio[17300]: info: CoreCommandRouter::volumioPushState Jan 27 20:06:26 volumio volumio[17300]: info: CoreStateMachine::setRandom null Jan 27 20:06:26 volumio volumio[17300]: info: CoreStateMachine::pushState Jan 27 20:06:26 volumio volumio[17300]: info: CorePlayQueue::getTrack 0 Jan 27 20:06:26 volumio volumio[17300]: info: CoreCommandRouter::volumioPushState Jan 27 20:06:26 volumio volumio[17300]: info: Setting Device type: Raspberry PI Jan 27 20:06:26 volumio volumio[17300]: info: Completed loading Core Plugins Jan 27 20:06:26 volumio volumio[17300]: info: Preparing to generate the ALSA configuration file Jan 27 20:06:26 volumio volumio[17300]: info: VolumeController:: Volume=100 Mute =false Jan 27 20:06:26 volumio volumio[17300]: info: CoreStateMachine::pushState Jan 27 20:06:26 volumio volumio[17300]: info: CorePlayQueue::getTrack 0 Jan 27 20:06:26 volumio volumio[17300]: info: CoreCommandRouter::volumioPushState Jan 27 20:06:26 volumio volumio[17300]: info: Asound.conf file unchanged, so no further update is needed Jan 27 20:06:26 volumio volumio[17300]: info: Output device has changed, restarting MPD Jan 27 20:06:26 volumio volumio[17300]: info: Output device has changed, restarting Shairport Sync Jan 27 20:06:26 volumio volumio[17300]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 20:06:26 volumio volumio[17300]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 20:06:26 volumio sudo[17475]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Jan 27 20:06:26 volumio sudo[17475]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 20:06:26 volumio sudo[17477]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 27 20:06:26 volumio sudo[17479]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 27 20:06:26 volumio sudo[17479]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 20:06:26 volumio sudo[17477]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 20:06:26 volumio volumio[17300]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 27 20:06:26 volumio volumio[17300]: info: ___________ START PLUGINS ___________ Jan 27 20:06:26 volumio sudo[17477]: pam_unix(sudo:session): session closed for user root Jan 27 20:06:26 volumio volumio[17300]: info: ControllerMpd::onStart: Initializing MPD Jan 27 20:06:26 volumio volumio[17300]: info: Creating MPD Configuration file Jan 27 20:06:26 volumio volumio[17300]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 27 20:06:26 volumio volumio[17300]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 27 20:06:26 volumio volumio[17300]: info: [1769519186609] CoreMusicLibrary::Adding element Media Servers Jan 27 20:06:26 volumio volumio[17300]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 27 20:06:26 volumio volumio[17300]: info: UPNP Browser: Client initialized successfully Jan 27 20:06:26 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Jan 27 20:06:26 volumio sudo[17475]: pam_unix(sudo:session): session closed for user root Jan 27 20:06:26 volumio volumio[17300]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 20:06:26 volumio volumio[17300]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 20:06:26 volumio sudo[17488]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 27 20:06:26 volumio sudo[17488]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 20:06:26 volumio sudo[17488]: pam_unix(sudo:session): session closed for user root Jan 27 20:06:26 volumio sudo[17490]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 27 20:06:26 volumio sudo[17490]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 20:06:26 volumio volumio[17300]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 27 20:06:26 volumio volumio[17300]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 20:06:26 volumio volumio[17300]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 20:06:26 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 27 20:06:26 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 27 20:06:26 volumio systemd[1]: mpd.service: Consumed 7.253s CPU time. Jan 27 20:06:26 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 27 20:06:26 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 27 20:06:26 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 27 20:06:26 volumio volumio[17300]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 27 20:06:26 volumio volumio[17300]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 27 20:06:26 volumio volumio[17300]: info: [1769519186858] CoreMusicLibrary::Adding element Last_100 Jan 27 20:06:26 volumio volumio[17300]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 27 20:06:26 volumio volumio[17300]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 27 20:06:26 volumio volumio[17300]: info: [1769519186867] CoreMusicLibrary::Adding element Webradio Jan 27 20:06:26 volumio volumio[17300]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 27 20:06:26 volumio volumio[17300]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 27 20:06:26 volumio volumio[17300]: info: Initializing BBC Radios Jan 27 20:06:26 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 27 20:06:26 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 27 20:06:27 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 27 20:06:27 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 27 20:06:27 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 27 20:06:27 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 27 20:06:27 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 27 20:06:27 volumio volumio[17300]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 27 20:06:27 volumio volumio[17300]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 20:06:27 volumio volumio[17300]: info: Creating Spotify config file Jan 27 20:06:27 volumio volumio[17300]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 20:06:27 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 27 20:06:27 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 27 20:06:27 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 20:06:27 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 20:06:27 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 20:06:27 volumio sudo[17517]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 27 20:06:27 volumio sudo[17517]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jan 27 20:06:27 volumio sudo[17517]: pam_unix(sudo:session): session closed for user root Jan 27 20:06:27 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 19. Jan 27 20:06:28 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 20:06:28 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 20:06:28 volumio go-librespot[17520]: go-librespot daemon starting... Jan 27 20:06:28 volumio go-librespot[17521]: time="2026-01-27T20:06:28+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 20:06:28 volumio volumio[17300]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 27 20:06:28 volumio volumio[17300]: info: [1769519188385] CoreMusicLibrary::Adding element YouTube Music Jan 27 20:06:28 volumio volumio[17300]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 27 20:06:28 volumio volumio[17300]: Cannot find translation for source YouTube Music Jan 27 20:06:28 volumio volumio[17300]: info: Volumio Calling Home Jan 27 20:06:28 volumio sudo[17528]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Jan 27 20:06:28 volumio sudo[17528]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 20:06:28 volumio sudo[17528]: pam_unix(sudo:session): session closed for user root Jan 27 20:06:29 volumio go-librespot[17521]: time="2026-01-27T20:06:29+07:00" level=info msg="zeroconf server listening on port 36265" Jan 27 20:06:29 volumio volumio[17431]: Starting albumart workers Jan 27 20:06:29 volumio volumio[17435]: Starting albumart workers Jan 27 20:06:29 volumio volumio[17300]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Jan 27 20:06:29 volumio volumio[17300]: info: Discovery: Found device Volumio Jan 27 20:06:29 volumio volumio[17300]: info: CoreCommandRouter::volumioGetState Jan 27 20:06:29 volumio volumio[17300]: info: CorePlayQueue::getTrack 0 Jan 27 20:06:29 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 20:06:29 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 20:06:29 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 20:06:29 volumio volumio[17432]: Starting albumart workers Jan 27 20:06:29 volumio volumio[17300]: info: MPD Permissions set Jan 27 20:06:29 volumio volumio[17300]: info: MPD Permissions set Jan 27 20:06:29 volumio volumio[17300]: info: Upmpdcli Daemon Started Jan 27 20:06:29 volumio volumio[17300]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Jan 27 20:06:29 volumio volumio[17300]: info: Discovery: Found device Volumio Jan 27 20:06:29 volumio volumio[17300]: info: CoreCommandRouter::volumioGetState Jan 27 20:06:29 volumio volumio[17300]: info: CorePlayQueue::getTrack 0 Jan 27 20:06:29 volumio volumio[17300]: info: Volumio called home Jan 27 20:06:29 volumio volumio[17300]: info: Spotify config file written Jan 27 20:06:29 volumio sudo[17535]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jan 27 20:06:29 volumio sudo[17535]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 20:06:29 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Jan 27 20:06:29 volumio volumio[17300]: 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 27 20:06:29 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Jan 27 20:06:29 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 20:06:30 volumio volumio[17300]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 20:06:30 volumio volumio[17300]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 20:06:30 volumio volumio[17300]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 20:06:30 volumio volumio[17300]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 20:06:30 volumio volumio[17300]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 20:06:30 volumio volumio[17300]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 20:06:30 volumio volumio[17300]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 20:06:30 volumio volumio[17300]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 20:06:30 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 20:06:30 volumio go-librespot[17537]: go-librespot daemon starting... Jan 27 20:06:30 volumio sudo[17535]: pam_unix(sudo:session): session closed for user root Jan 27 20:06:30 volumio volumio[17300]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 20:06:30 volumio volumio[17300]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 20:06:30 volumio volumio[17300]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 20:06:30 volumio volumio[17300]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 20:06:30 volumio volumio[17300]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 20:06:30 volumio volumio[17300]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 20:06:30 volumio volumio[17300]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 20:06:30 volumio volumio[17300]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 20:06:30 volumio volumio[17300]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 20:06:30 volumio volumio[17300]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 20:06:30 volumio go-librespot[17540]: time="2026-01-27T20:06:30+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 20:06:30 volumio go-librespot[17540]: time="2026-01-27T20:06:30+07:00" level=debug msg="app state loaded" Jan 27 20:06:30 volumio go-librespot[17540]: time="2026-01-27T20:06:30+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 20:06:30 volumio volumio[17300]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 20:06:30 volumio volumio[17300]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 20:06:30 volumio volumio[17300]: info: No need to fix Spotify hosts Jan 27 20:06:30 volumio go-librespot[17540]: time="2026-01-27T20:06:30+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 27 20:06:30 volumio go-librespot[17540]: time="2026-01-27T20:06:30+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 27 20:06:30 volumio go-librespot[17540]: time="2026-01-27T20:06:30+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 27 20:06:30 volumio go-librespot[17540]: time="2026-01-27T20:06:30+07:00" level=info msg="zeroconf server listening on port 36353" Jan 27 20:06:31 volumio go-librespot[17540]: time="2026-01-27T20:06:31+07:00" level=debug msg="obtained new client token: AACBSmt3WLmjFvTkk3PW4TuNQInVI1/P8FRHmv+A8iSzuG13Y082qi+gRcLb21NNRxnX3a/W5fjuxJiLMxBkx+pw8/nfqXcE6ObAA5m6F88x+kA9R2gHB2eGcit1b8Ehn3USS8x2TBQaiPdw1NWd1Go84UOyrjQckuv1gvURdPGtL6/sb9G90oW+u6m7kb7HZLmyCLWOC11xUPzrn+AIWDquWU8A5jWoGDTp4zKLVJIqBaZ8JVg6LhQK" Jan 27 20:06:31 volumio go-librespot[17540]: time="2026-01-27T20:06:31+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 20:06:31 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 20:06:31 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 20:06:31 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 20:06:31 volumio go-librespot[17540]: time="2026-01-27T20:06:31+07:00" level=debug msg="completed keyexchange" Jan 27 20:06:31 volumio go-librespot[17540]: time="2026-01-27T20:06:31+07:00" level=debug msg="completed challenge" Jan 27 20:06:31 volumio volumio[17300]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 27 20:06:31 volumio volumio[17300]: SPOTIFY: BQC--b6IOlR2V0TGzzpOc7wJfntuU6LCw5rO8C6XQBIL8BbuUqVTN78oGr3NZy_NLac8TnqWs-rD4Ptm4j1zVKZkwPjPvxtZ28UEhAHYNpdmppCGfolezsVtUhmjqKemHUZTCr_8603Iof08xT_1Buws5EK9hg84rwCELnYH_3M0FJy-EpTZyRVUwVDDCIDwhRATLobUVChTSCog8swnT5qtREfXNAVHE7BL7jOyRp6RZ49vduDVomNi0lsURi1GlGLAUYU81YrySemAOIvudPdVpc_SBqHlqMVadmgv2rJtNDLoJO4tdegO Jan 27 20:06:31 volumio volumio[17300]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 27 20:06:31 volumio volumio[17300]: info: New Spotify access token = BQC--b6IOlR2V0TGzzpOc7wJfntuU6LCw5rO8C6XQBIL8BbuUqVTN78oGr3NZy_NLac8TnqWs-rD4Ptm4j1zVKZkwPjPvxtZ28UEhAHYNpdmppCGfolezsVtUhmjqKemHUZTCr_8603Iof08xT_1Buws5EK9hg84rwCELnYH_3M0FJy-EpTZyRVUwVDDCIDwhRATLobUVChTSCog8swnT5qtREfXNAVHE7BL7jOyRp6RZ49vduDVomNi0lsURi1GlGLAUYU81YrySemAOIvudPdVpc_SBqHlqMVadmgv2rJtNDLoJO4tdegO Jan 27 20:06:31 volumio volumio[17300]: info: Spotify credentials grant success - running version from March 24, 2019 Jan 27 20:06:31 volumio go-librespot[17540]: time="2026-01-27T20:06:31+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 27 20:06:31 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 20:06:31 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 20:06:31 volumio volumio[17300]: info: Starting Shairport Sync Jan 27 20:06:31 volumio volumio[17300]: info: Starting Shairport Sync Jan 27 20:06:31 volumio volumio[17300]: info: Starting Shairport Sync Jan 27 20:06:31 volumio sudo[17575]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 27 20:06:31 volumio sudo[17575]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 20:06:31 volumio sudo[17577]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 27 20:06:31 volumio sudo[17577]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 20:06:31 volumio sudo[17579]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 27 20:06:31 volumio sudo[17579]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 20:06:32 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 27 20:06:32 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Jan 27 20:06:32 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 27 20:06:32 volumio systemd[1]: shairport-sync.service: Consumed 2.299s CPU time. Jan 27 20:06:32 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 27 20:06:32 volumio sudo[17575]: pam_unix(sudo:session): session closed for user root Jan 27 20:06:32 volumio sudo[17577]: pam_unix(sudo:session): session closed for user root Jan 27 20:06:32 volumio sudo[17579]: pam_unix(sudo:session): session closed for user root Jan 27 20:06:32 volumio volumio[17300]: info: Shairport-Sync Started Jan 27 20:06:32 volumio volumio[17300]: Error adding Membership: Error: addMembership EINVAL Jan 27 20:06:32 volumio volumio[17300]: info: Shairport-Sync Started Jan 27 20:06:32 volumio volumio[17300]: info: Shairport-Sync Started Jan 27 20:06:32 volumio volumio[17300]: info: CoreCommandRouter::volumioGetState Jan 27 20:06:32 volumio volumio[17300]: info: CorePlayQueue::getTrack 0 Jan 27 20:06:32 volumio volumio[17300]: 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 27 20:06:32 volumio volumio[17300]: info: Spotify Successfully logged in Jan 27 20:06:32 volumio volumio[17300]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 27 20:06:32 volumio volumio[17300]: info: [1769519192591] CoreMusicLibrary::Adding element Spotify Jan 27 20:06:32 volumio volumio[17300]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 27 20:06:32 volumio volumio[17300]: Cannot find translation for source YouTube Music Jan 27 20:06:32 volumio volumio[17300]: Cannot find translation for source Spotify Jan 27 20:06:33 volumio volumio[17300]: info: [yt-cast-receiver] DIAL server listening on port 8098 Jan 27 20:06:33 volumio volumio[17300]: info: CoreCommandRouter::volumioRetrievevolume Jan 27 20:06:33 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 20:06:33 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 20:06:33 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 20:06:33 volumio volumio[17300]: info: VolumeController:: Volume=100 Mute =false Jan 27 20:06:33 volumio volumio[17300]: info: CoreCommandRouter::volumioGetState Jan 27 20:06:33 volumio volumio[17300]: info: CorePlayQueue::getTrack 0 Jan 27 20:06:33 volumio volumio[17300]: info: CoreStateMachine::pushState Jan 27 20:06:33 volumio volumio[17300]: info: CorePlayQueue::getTrack 0 Jan 27 20:06:33 volumio volumio[17300]: info: CoreCommandRouter::volumioPushState Jan 27 20:06:34 volumio volumio[17300]: info: go-librespot daemon successfully initialized Jan 27 20:06:34 volumio mpd[17519]: 2026-01-27T20:06:34 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 27 20:06:34 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Jan 27 20:06:34 volumio systemd[1]: Started mpd.service - Music Player Daemon. Jan 27 20:06:34 volumio sudo[17479]: pam_unix(sudo:session): session closed for user root Jan 27 20:06:34 volumio sudo[17490]: pam_unix(sudo:session): session closed for user root Jan 27 20:06:34 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 20:06:34 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 20:06:34 volumio go-librespot[17616]: go-librespot daemon starting... Jan 27 20:06:34 volumio go-librespot[17619]: time="2026-01-27T20:06:34+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 20:06:34 volumio go-librespot[17619]: time="2026-01-27T20:06:34+07:00" level=debug msg="app state loaded" Jan 27 20:06:34 volumio go-librespot[17619]: time="2026-01-27T20:06:34+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 20:06:34 volumio volumio[17300]: error: MPD error: The expression evaluated to a falsy value: Jan 27 20:06:34 volumio volumio[17300]: assert.ok(self.idling) Jan 27 20:06:34 volumio volumio[17300]: error: The expression evaluated to a falsy value: Jan 27 20:06:34 volumio volumio[17300]: assert.ok(self.idling) Jan 27 20:06:34 volumio volumio[17300]: info: MPD running with PID17519 Jan 27 20:06:34 volumio volumio[17300]: ,establishing connection Jan 27 20:06:34 volumio volumio[17300]: error: updateQueue error: null Jan 27 20:06:35 volumio volumio[17300]: info: Completed starting Core Plugins Jan 27 20:06:35 volumio volumio[17300]: info: ------------------------------------------- Jan 27 20:06:35 volumio volumio[17300]: info: ----- MyVolumio plugins startup ---- Jan 27 20:06:35 volumio volumio[17300]: info: ------------------------------------------- Jan 27 20:06:35 volumio volumio[17300]: info: [MyVolumio PluginManager] Fetching plans data.... Jan 27 20:06:35 volumio volumio[17300]: error: updateQueue error: null Jan 27 20:06:35 volumio go-librespot[17619]: time="2026-01-27T20:06:35+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 27 20:06:35 volumio go-librespot[17619]: time="2026-01-27T20:06:35+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 27 20:06:35 volumio go-librespot[17619]: time="2026-01-27T20:06:35+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 27 20:06:35 volumio go-librespot[17619]: time="2026-01-27T20:06:35+07:00" level=info msg="zeroconf server listening on port 34641" Jan 27 20:06:35 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 20:06:35 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 20:06:35 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 20:06:35 volumio go-librespot[17619]: time="2026-01-27T20:06:35+07:00" level=debug msg="obtained new client token: AACCNlw+rqVs5w+aqjzD0D9m02Wn33UzVXBh2wkRdoxmBk+gDil/9frQEjMU0o7k5/RAdJ0ucjItpgt60R1AgKH4VzCcbg2A6IWIHUvM3Y37ywjN9t03JOR9JAmzWo/bauDz60I/oRjblK9ySlQzXkVujXMWIGnPNYQc+d9anSGvuCi6r/eqjRC2xDH+Wk8vWbZRqK4PQJQ6T50XYMqvBaOACbnDx5ryoSY/W2W4VFu5QDvgM8abd4tib8Q=" Jan 27 20:06:35 volumio go-librespot[17619]: time="2026-01-27T20:06:35+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 20:06:35 volumio go-librespot[17619]: time="2026-01-27T20:06:35+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Jan 27 20:06:35 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 20:06:35 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 20:06:37 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 20:06:37 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 20:06:37 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 20:06:37 volumio volumio[17300]: info: Initializing connection to go-librespot Websocket Jan 27 20:06:37 volumio volumio[17300]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 27 20:06:38 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Jan 27 20:06:38 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 20:06:39 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 20:06:39 volumio go-librespot[17628]: go-librespot daemon starting... Jan 27 20:06:39 volumio go-librespot[17629]: time="2026-01-27T20:06:39+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 20:06:39 volumio go-librespot[17629]: time="2026-01-27T20:06:39+07:00" level=debug msg="app state loaded" Jan 27 20:06:39 volumio go-librespot[17629]: time="2026-01-27T20:06:39+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 20:06:39 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 20:06:39 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 20:06:39 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 20:06:39 volumio go-librespot[17629]: time="2026-01-27T20:06:39+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 27 20:06:39 volumio go-librespot[17629]: time="2026-01-27T20:06:39+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 27 20:06:39 volumio go-librespot[17629]: time="2026-01-27T20:06:39+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 27 20:06:39 volumio go-librespot[17629]: time="2026-01-27T20:06:39+07:00" level=info msg="zeroconf server listening on port 34567" Jan 27 20:06:39 volumio volumio[17300]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Jan 27 20:06:39 volumio go-librespot[17629]: time="2026-01-27T20:06:39+07:00" level=debug msg="obtained new client token: AAAEX7z9eQ189r7p85MQ8V/27yEcMgGz5nd2MQgsXrC44W2e6M3mMEPcTjK1gCmGIidcEK6ute5uFRN1Xo7L7OtTCzkulknVb6Qwwp/DG6N505nmRa623oXtpWkbzRX9y2awuWIHTr7bTrT2FErUYMvOvFleNAblVMTwjr/DSiJdBW4n1cOjltDKpRL9jR0dEh850VhroJgtst6gXq/iSBWJQQIMUejX0rC/EY9Fz57z5Lse3NHqJYMsnsQ=" Jan 27 20:06:40 volumio go-librespot[17629]: time="2026-01-27T20:06:40+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 20:06:40 volumio go-librespot[17629]: time="2026-01-27T20:06:40+07:00" level=debug msg="completed keyexchange" Jan 27 20:06:40 volumio go-librespot[17629]: time="2026-01-27T20:06:40+07:00" level=debug msg="completed challenge" Jan 27 20:06:40 volumio go-librespot[17629]: time="2026-01-27T20:06:40+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 27 20:06:40 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 20:06:40 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 20:06:40 volumio volumio[17300]: info: Initializing connection to go-librespot Websocket Jan 27 20:06:40 volumio volumio[17300]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 27 20:06:41 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 20:06:41 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 20:06:41 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 20:06:43 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Jan 27 20:06:43 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 20:06:43 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 20:06:43 volumio go-librespot[17637]: go-librespot daemon starting... Jan 27 20:06:43 volumio go-librespot[17638]: time="2026-01-27T20:06:43+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 20:06:43 volumio go-librespot[17638]: time="2026-01-27T20:06:43+07:00" level=debug msg="app state loaded" Jan 27 20:06:43 volumio go-librespot[17638]: time="2026-01-27T20:06:43+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 20:06:43 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 20:06:43 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 20:06:43 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 20:06:43 volumio volumio[17300]: info: Initializing connection to go-librespot Websocket Jan 27 20:06:43 volumio go-librespot[17638]: time="2026-01-27T20:06:43+07:00" level=debug msg="new websocket client" Jan 27 20:06:43 volumio volumio[17300]: info: Connection to go-librespot Websocket established Jan 27 20:06:43 volumio volumio[17300]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Jan 27 20:06:43 volumio volumio[17300]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Jan 27 20:06:43 volumio volumio[17300]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Jan 27 20:06:43 volumio volumio[17300]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Jan 27 20:06:43 volumio volumio[17300]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Jan 27 20:06:43 volumio volumio[17300]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Jan 27 20:06:43 volumio volumio[17300]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Jan 27 20:06:43 volumio volumio[17300]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Jan 27 20:06:43 volumio volumio[17300]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Jan 27 20:06:43 volumio volumio[17300]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Jan 27 20:06:43 volumio volumio[17300]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Jan 27 20:06:43 volumio volumio[17300]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Jan 27 20:06:43 volumio volumio[17300]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Jan 27 20:06:43 volumio volumio[17300]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Jan 27 20:06:43 volumio volumio[17300]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Jan 27 20:06:43 volumio volumio[17300]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Jan 27 20:06:43 volumio volumio[17300]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Jan 27 20:06:43 volumio volumio[17300]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Jan 27 20:06:43 volumio volumio[17300]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Jan 27 20:06:43 volumio volumio[17300]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Jan 27 20:06:43 volumio volumio[17300]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Jan 27 20:06:43 volumio volumio[17300]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Jan 27 20:06:43 volumio volumio[17300]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Jan 27 20:06:43 volumio volumio[17300]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Jan 27 20:06:43 volumio volumio[17300]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Jan 27 20:06:43 volumio volumio[17300]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Jan 27 20:06:43 volumio volumio[17300]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Jan 27 20:06:43 volumio volumio[17300]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Jan 27 20:06:43 volumio volumio[17300]: info: Adding plugin bluetooth to MyMusic Plugins Jan 27 20:06:43 volumio volumio[17300]: info: Adding plugin multiroom to MyMusic Plugins Jan 27 20:06:43 volumio volumio[17300]: info: Adding plugin metavolumio to MyMusic Plugins Jan 27 20:06:43 volumio volumio[17300]: info: Adding plugin cd_controller to MyMusic Plugins Jan 27 20:06:43 volumio volumio[17300]: info: Adding plugin qobuzconnect to MyMusic Plugins Jan 27 20:06:43 volumio volumio[17300]: info: Adding plugin smart_inputs to MyMusic Plugins Jan 27 20:06:43 volumio volumio[17300]: info: Adding plugin tidalconnect to MyMusic Plugins Jan 27 20:06:43 volumio volumio[17300]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Jan 27 20:06:43 volumio go-librespot[17638]: time="2026-01-27T20:06:43+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 27 20:06:43 volumio go-librespot[17638]: time="2026-01-27T20:06:43+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 27 20:06:43 volumio go-librespot[17638]: time="2026-01-27T20:06:43+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 27 20:06:43 volumio go-librespot[17638]: time="2026-01-27T20:06:43+07:00" level=info msg="zeroconf server listening on port 46743" Jan 27 20:06:44 volumio go-librespot[17638]: time="2026-01-27T20:06:44+07:00" level=debug msg="obtained new client token: AAAAQBWvvMkCtZoIMZnUY5LHxux8oCU0eqmiBVbpiC8PQ69S8duJA8g2V4uWmdJqrhq5uUOmRZYkJnEWuWocHNtyeJjWWb/dHOUa+dGZm1b3tAlq1tmCkrBqmdEv1bnZwthvBUFfohh8iJG3AtO7FxTu9Ua1cS6sZLTdDYm5TiL1oYlpwSkz7NFnuTEDnva0dfqH6oRxqalDc8Kj8CffGtzTwKZuh8VtJhbMckOiAlLUH2i6BP0W2E4+" Jan 27 20:06:44 volumio go-librespot[17638]: time="2026-01-27T20:06:44+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 20:06:44 volumio go-librespot[17638]: time="2026-01-27T20:06:44+07:00" level=debug msg="completed keyexchange" Jan 27 20:06:44 volumio go-librespot[17638]: time="2026-01-27T20:06:44+07:00" level=debug msg="completed challenge" Jan 27 20:06:44 volumio go-librespot[17638]: time="2026-01-27T20:06:44+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 27 20:06:44 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 20:06:44 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 20:06:45 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 20:06:45 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 20:06:45 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 20:06:45 volumio volumio[17300]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Jan 27 20:06:45 volumio volumio[17300]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Jan 27 20:06:45 volumio volumio[17300]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 20:06:45 volumio volumio[17300]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 20:06:45 volumio volumio[17300]: info: Starting MyVolumio Remote Streaming Endpoints Jan 27 20:06:45 volumio volumio[17300]: info: MyVolumio login type: Token Jan 27 20:06:45 volumio volumio[17300]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Jan 27 20:06:45 volumio volumio[17300]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Jan 27 20:06:47 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 20:06:47 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 20:06:47 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 20:06:47 volumio volumio[17300]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Jan 27 20:06:47 volumio volumio[17300]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Jan 27 20:06:47 volumio volumio[17300]: info: Streaming services startup Jan 27 20:06:47 volumio volumio[17300]: info: Starting Streaming Daemon Jan 27 20:06:47 volumio sudo[17661]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jan 27 20:06:47 volumio volumio[17300]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Jan 27 20:06:47 volumio sudo[17661]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 20:06:47 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Jan 27 20:06:47 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 20:06:47 volumio volumio[17300]: info: Getting Spotify volume Jan 27 20:06:47 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 20:06:47 volumio sudo[17661]: pam_unix(sudo:session): session closed for user root Jan 27 20:06:47 volumio go-librespot[17667]: go-librespot daemon starting... Jan 27 20:06:47 volumio volumio[17300]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 27 20:06:47 volumio volumio[17300]: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 27 20:06:47 volumio volumio[17300]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Jan 27 20:06:47 volumio volumio[17300]: errno: -111, Jan 27 20:06:47 volumio volumio[17300]: code: 'ECONNREFUSED', Jan 27 20:06:47 volumio volumio[17300]: syscall: 'connect', Jan 27 20:06:47 volumio volumio[17300]: address: '127.0.0.1', Jan 27 20:06:47 volumio volumio[17300]: port: 9879, Jan 27 20:06:47 volumio volumio[17300]: response: undefined Jan 27 20:06:47 volumio volumio[17300]: } Jan 27 20:06:47 volumio volumio[17300]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 27 20:06:47 volumio go-librespot[17668]: time="2026-01-27T20:06:47+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 20:06:47 volumio go-librespot[17668]: time="2026-01-27T20:06:47+07:00" level=debug msg="app state loaded" Jan 27 20:06:47 volumio go-librespot[17668]: time="2026-01-27T20:06:47+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 20:06:48 volumio go-librespot[17668]: time="2026-01-27T20:06:48+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 27 20:06:48 volumio go-librespot[17668]: time="2026-01-27T20:06:48+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 27 20:06:48 volumio go-librespot[17668]: time="2026-01-27T20:06:48+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 27 20:06:48 volumio go-librespot[17668]: time="2026-01-27T20:06:48+07:00" level=info msg="zeroconf server listening on port 32855" Jan 27 20:06:48 volumio go-librespot[17668]: time="2026-01-27T20:06:48+07:00" level=debug msg="obtained new client token: AACu/MEz3opTK0HckdMNEUNFIFm2CY0KIoNV1qsKAzJu0suXN90tewTqbYok35OV6N93LvfIsobupMDPeCC0vVcYV3nyYqlaBI4w3mVyQ0uLcFEtE0oYwsOsqPj+iTvcwetnvTMjN+ygeJoYB5DEvfcW/d+HQYJbijliY0PEqOvTEmzzWcuXhDefU76O4HSVcderLxG9z/vIkepM+R6jCjXseOHxcaReOncKxUv6xAZ8Jr7hntIr4KIRi6g=" Jan 27 20:06:48 volumio go-librespot[17668]: time="2026-01-27T20:06:48+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 20:06:48 volumio go-librespot[17668]: time="2026-01-27T20:06:48+07:00" level=debug msg="completed keyexchange" Jan 27 20:06:48 volumio go-librespot[17668]: time="2026-01-27T20:06:48+07:00" level=debug msg="completed challenge" Jan 27 20:06:48 volumio go-librespot[17668]: time="2026-01-27T20:06:48+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 27 20:06:48 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 20:06:48 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 20:06:49 volumio sudo[17690]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-01-27 20:05' Jan 27 20:06:49 volumio sudo[17690]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 20:06:49 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 20:06:49 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 20:06:49 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 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"