Jan 28 20:10:00 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 20:10:00 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 20:10:00 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 20:10:00 volumio volumio[26131]: info: Loading plugin "ytmusic"... Jan 28 20:10:01 volumio volumio-remote-updater[628]: [2026-01-28 20:10:01] [connect] Successful connection Jan 28 20:10:01 volumio volumio[26131]: info: Loading plugin "outputs"... Jan 28 20:10:01 volumio volumio[26131]: info: Loading plugin "albumart"... Jan 28 20:10:02 volumio volumio[26131]: info: Plugin example_plugin is not enabled Jan 28 20:10:02 volumio volumio[26131]: info: Loading plugin "inputs"... Jan 28 20:10:02 volumio volumio[26131]: info: Loading plugin "updater_comm"... Jan 28 20:10:02 volumio volumio[26131]: info: Plugin mpdemulation is not enabled Jan 28 20:10:02 volumio volumio[26131]: info: Loading plugin "rest_api"... Jan 28 20:10:02 volumio volumio[26131]: info: Loading plugin "websocket"... Jan 28 20:10:02 volumio volumio[26131]: info: Starting Socket.io Server version 1.7.4 Jan 28 20:10:02 volumio volumio[26131]: info: Loading plugin "RoonBridge"... Jan 28 20:10:02 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 19. Jan 28 20:10:02 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 20:10:02 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 20:10:02 volumio go-librespot[26252]: go-librespot daemon starting... Jan 28 20:10:02 volumio go-librespot[26253]: time="2026-01-28T20:10:02+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 20:10:02 volumio go-librespot[26253]: time="2026-01-28T20:10:02+07:00" level=debug msg="app state loaded" Jan 28 20:10:02 volumio go-librespot[26253]: time="2026-01-28T20:10:02+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 20:10:02 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 20:10:02 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 20:10:02 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 20:10:02 volumio volumio[26131]: info: Applying required configuration parameters for plugin RoonBridge Jan 28 20:10:02 volumio volumio[26131]: info: Loading i18n strings for locale en Jan 28 20:10:02 volumio volumio[26131]: Updating browse sources language Jan 28 20:10:02 volumio volumio[26131]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 20:10:03 volumio volumio[26242]: Forking 3 albumart workers Jan 28 20:10:03 volumio go-librespot[26253]: time="2026-01-28T20:10:03+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 20:10:03 volumio go-librespot[26253]: time="2026-01-28T20:10:03+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 28 20:10:03 volumio go-librespot[26253]: time="2026-01-28T20:10:03+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 28 20:10:03 volumio go-librespot[26253]: time="2026-01-28T20:10:03+07:00" level=info msg="zeroconf server listening on port 38227" Jan 28 20:10:03 volumio volumio[26131]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 28 20:10:03 volumio volumio[26131]: info: CoreCommandRouter::initPlayerControls Jan 28 20:10:03 volumio volumio[26131]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 20:10:03 volumio volumio[26131]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 20:10:03 volumio volumio[26131]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 20:10:03 volumio volumio[26131]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 20:10:03 volumio volumio[26131]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 20:10:03 volumio volumio[26131]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 20:10:03 volumio volumio[26131]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 20:10:03 volumio volumio[26131]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 20:10:03 volumio volumio[26131]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 28 20:10:03 volumio volumio[26131]: Express server listening on port 3000 Jan 28 20:10:03 volumio volumio[26131]: [Metrics] WebUI: 16s 138.97ms Jan 28 20:10:03 volumio volumio[26131]: info: CoreStateMachine::resetVolumioState Jan 28 20:10:03 volumio volumio[26131]: info: CoreStateMachine::getcurrentVolume Jan 28 20:10:03 volumio volumio[26131]: info: CoreCommandRouter::volumioRetrievevolume Jan 28 20:10:03 volumio go-librespot[26253]: time="2026-01-28T20:10:03+07:00" level=debug msg="obtained new client token: AADQBxM4pcmdx0iEK9QhLCfAe8y0Gi3w0ItP+cc72JHkS1Q6g51oFlvOdjQPRIc/54QMSiueQfqE7wBZKLGP8vTTP6e5RfKr0NqVPon2v7YqbinQgwy2CVZeHk4sSLfhwCdAZf16/e2VHsggYBsCXTQfwn/y0oBC/qUimKbkOGx6cojNAluq3Kn5kW89u5UchIxJWakm5Ne2Gta2gturiM+uslJ8T/BzkSNf6S9V50rJLo+iytRz/WUGD7A=" Jan 28 20:10:03 volumio go-librespot[26253]: time="2026-01-28T20:10:03+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 20:10:03 volumio sudo[26297]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 28 20:10:03 volumio sudo[26297]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 20:10:03 volumio sudo[26295]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 28 20:10:03 volumio sudo[26295]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 20:10:03 volumio sudo[26297]: pam_unix(sudo:session): session closed for user root Jan 28 20:10:03 volumio sudo[26295]: pam_unix(sudo:session): session closed for user root Jan 28 20:10:03 volumio volumio[26131]: info: Volumio Network Manager: Network status updated: 1 Jan 28 20:10:03 volumio go-librespot[26253]: time="2026-01-28T20:10:03+07:00" level=debug msg="completed keyexchange" Jan 28 20:10:03 volumio go-librespot[26253]: time="2026-01-28T20:10:03+07:00" level=debug msg="completed challenge" Jan 28 20:10:03 volumio go-librespot[26253]: time="2026-01-28T20:10:03+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 20:10:03 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 20:10:03 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 20:10:03 volumio volumio[26131]: info: VolumeController:: Volume=100 Mute =false Jan 28 20:10:03 volumio volumio[26131]: info: CoreStateMachine::pushState Jan 28 20:10:03 volumio volumio[26131]: info: CorePlayQueue::getTrack 0 Jan 28 20:10:03 volumio volumio[26131]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 28 20:10:04 volumio volumio[26131]: info: CoreCommandRouter::volumioPushState Jan 28 20:10:04 volumio volumio[26131]: info: CoreStateMachine::updateTrackBlock Jan 28 20:10:04 volumio volumio[26131]: info: CorePlayQueue::getTrackBlock Jan 28 20:10:04 volumio volumio[26131]: info: CoreCommandRouter::volumioRetrievevolume Jan 28 20:10:04 volumio volumio-remote-updater[628]: [2026-01-28 20:10:04] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1769605801 101 Jan 28 20:10:04 volumio volumio[26131]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 1 Jan 28 20:10:04 volumio volumio[26131]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 20:10:04 volumio volumio[26131]: info: Reloading queue from file Jan 28 20:10:04 volumio volumio[26131]: info: CoreStateMachine::setRepeat null single undefined Jan 28 20:10:04 volumio volumio[26131]: info: CoreStateMachine::pushState Jan 28 20:10:04 volumio volumio[26131]: info: CorePlayQueue::getTrack 0 Jan 28 20:10:04 volumio volumio[26131]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 28 20:10:04 volumio volumio[26131]: info: CoreCommandRouter::volumioPushState Jan 28 20:10:04 volumio volumio[26131]: info: CoreStateMachine::setRandom null Jan 28 20:10:04 volumio volumio[26131]: info: CoreStateMachine::pushState Jan 28 20:10:04 volumio volumio[26131]: info: CorePlayQueue::getTrack 0 Jan 28 20:10:04 volumio volumio[26131]: info: CoreCommandRouter::volumioPushState Jan 28 20:10:04 volumio volumio[26131]: info: Setting Device type: Raspberry PI Jan 28 20:10:04 volumio volumio[26131]: info: Completed loading Core Plugins Jan 28 20:10:04 volumio volumio[26131]: info: Preparing to generate the ALSA configuration file Jan 28 20:10:04 volumio volumio[26131]: info: VolumeController:: Volume=100 Mute =false Jan 28 20:10:04 volumio volumio[26131]: info: CoreStateMachine::pushState Jan 28 20:10:04 volumio volumio[26131]: info: CorePlayQueue::getTrack 0 Jan 28 20:10:04 volumio volumio[26131]: info: CoreCommandRouter::volumioPushState Jan 28 20:10:04 volumio volumio[26131]: info: Asound.conf file unchanged, so no further update is needed Jan 28 20:10:04 volumio volumio[26131]: info: Output device has changed, restarting MPD Jan 28 20:10:04 volumio volumio[26131]: info: Output device has changed, restarting Shairport Sync Jan 28 20:10:04 volumio volumio[26131]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 20:10:04 volumio volumio[26131]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 20:10:04 volumio sudo[26311]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Jan 28 20:10:04 volumio sudo[26311]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 20:10:04 volumio sudo[26313]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 28 20:10:04 volumio sudo[26313]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 20:10:04 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 20:10:04 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 20:10:04 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 20:10:04 volumio volumio[26131]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 28 20:10:04 volumio sudo[26313]: pam_unix(sudo:session): session closed for user root Jan 28 20:10:04 volumio volumio[26131]: info: ___________ START PLUGINS ___________ Jan 28 20:10:04 volumio sudo[26315]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 28 20:10:04 volumio volumio[26131]: info: ControllerMpd::onStart: Initializing MPD Jan 28 20:10:04 volumio volumio[26131]: info: Creating MPD Configuration file Jan 28 20:10:04 volumio sudo[26315]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 20:10:04 volumio volumio[26131]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 28 20:10:04 volumio volumio[26131]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 20:10:04 volumio volumio[26131]: info: [1769605804748] CoreMusicLibrary::Adding element Media Servers Jan 28 20:10:04 volumio volumio[26131]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 20:10:04 volumio sudo[26324]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 28 20:10:04 volumio sudo[26324]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 20:10:04 volumio sudo[26324]: pam_unix(sudo:session): session closed for user root Jan 28 20:10:04 volumio volumio[26131]: info: UPNP Browser: Client initialized successfully Jan 28 20:10:04 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Jan 28 20:10:04 volumio sudo[26326]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 28 20:10:04 volumio sudo[26311]: pam_unix(sudo:session): session closed for user root Jan 28 20:10:04 volumio sudo[26326]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 20:10:04 volumio volumio[26131]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 20:10:04 volumio volumio[26131]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 20:10:04 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 28 20:10:04 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 28 20:10:04 volumio systemd[1]: mpd.service: Consumed 7.484s CPU time. Jan 28 20:10:04 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 28 20:10:04 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 28 20:10:04 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 28 20:10:05 volumio volumio[26131]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 28 20:10:05 volumio volumio[26131]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 20:10:05 volumio volumio[26131]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 20:10:05 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 28 20:10:05 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 28 20:10:05 volumio volumio[26131]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 28 20:10:05 volumio volumio[26131]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 20:10:05 volumio volumio[26131]: info: [1769605805107] CoreMusicLibrary::Adding element Last_100 Jan 28 20:10:05 volumio volumio[26131]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 20:10:05 volumio volumio[26131]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 20:10:05 volumio volumio[26131]: info: [1769605805122] CoreMusicLibrary::Adding element Webradio Jan 28 20:10:05 volumio volumio[26131]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 20:10:05 volumio volumio[26131]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 28 20:10:05 volumio volumio[26131]: info: Initializing BBC Radios Jan 28 20:10:05 volumio volumio[26131]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 28 20:10:05 volumio volumio[26131]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 20:10:05 volumio volumio[26131]: info: Creating Spotify config file Jan 28 20:10:05 volumio volumio[26131]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 20:10:05 volumio sudo[26338]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 28 20:10:05 volumio sudo[26338]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jan 28 20:10:05 volumio sudo[26338]: pam_unix(sudo:session): session closed for user root Jan 28 20:10:06 volumio volumio[26260]: Starting albumart workers Jan 28 20:10:06 volumio volumio[26261]: Starting albumart workers Jan 28 20:10:06 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 20:10:06 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 20:10:06 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 20:10:06 volumio volumio[26262]: Starting albumart workers Jan 28 20:10:06 volumio volumio[26131]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 20:10:06 volumio volumio[26131]: info: [1769605806731] CoreMusicLibrary::Adding element YouTube Music Jan 28 20:10:06 volumio volumio[26131]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 20:10:06 volumio volumio[26131]: Cannot find translation for source YouTube Music Jan 28 20:10:06 volumio volumio[26131]: info: Volumio Calling Home Jan 28 20:10:06 volumio sudo[26355]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Jan 28 20:10:06 volumio sudo[26355]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 20:10:06 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 20. Jan 28 20:10:06 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 20:10:07 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 20:10:07 volumio go-librespot[26360]: go-librespot daemon starting... Jan 28 20:10:07 volumio sudo[26355]: pam_unix(sudo:session): session closed for user root Jan 28 20:10:07 volumio go-librespot[26361]: time="2026-01-28T20:10:07+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 20:10:07 volumio go-librespot[26361]: time="2026-01-28T20:10:07+07:00" level=info msg="zeroconf server listening on port 45235" Jan 28 20:10:08 volumio volumio[26131]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Jan 28 20:10:08 volumio volumio[26131]: info: Discovery: Found device Volumio Jan 28 20:10:08 volumio volumio[26131]: info: CoreCommandRouter::volumioGetState Jan 28 20:10:08 volumio volumio[26131]: info: CorePlayQueue::getTrack 0 Jan 28 20:10:08 volumio volumio[26131]: info: MPD Permissions set Jan 28 20:10:08 volumio volumio[26131]: info: MPD Permissions set Jan 28 20:10:08 volumio volumio[26131]: info: Upmpdcli Daemon Started Jan 28 20:10:08 volumio volumio[26131]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Jan 28 20:10:08 volumio volumio[26131]: info: Discovery: Found device Volumio Jan 28 20:10:08 volumio volumio[26131]: info: CoreCommandRouter::volumioGetState Jan 28 20:10:08 volumio volumio[26131]: info: CorePlayQueue::getTrack 0 Jan 28 20:10:08 volumio volumio[26131]: info: Volumio called home Jan 28 20:10:08 volumio volumio[26131]: info: Spotify config file written Jan 28 20:10:08 volumio sudo[26375]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jan 28 20:10:08 volumio sudo[26375]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 20:10:08 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Jan 28 20:10:08 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Jan 28 20:10:08 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 20:10:08 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 20:10:08 volumio go-librespot[26377]: go-librespot daemon starting... Jan 28 20:10:08 volumio sudo[26375]: pam_unix(sudo:session): session closed for user root Jan 28 20:10:08 volumio go-librespot[26378]: time="2026-01-28T20:10:08+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 20:10:08 volumio go-librespot[26378]: time="2026-01-28T20:10:08+07:00" level=debug msg="app state loaded" Jan 28 20:10:08 volumio go-librespot[26378]: time="2026-01-28T20:10:08+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 20:10:08 volumio volumio[26131]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Jan 28 20:10:08 volumio volumio[26131]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 20:10:08 volumio volumio[26131]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 20:10:08 volumio volumio[26131]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 20:10:08 volumio volumio[26131]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 20:10:08 volumio volumio[26131]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 20:10:08 volumio volumio[26131]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 20:10:08 volumio volumio[26131]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 20:10:08 volumio volumio[26131]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 20:10:08 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 20:10:08 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 20:10:08 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 20:10:08 volumio volumio[26131]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 20:10:08 volumio volumio[26131]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 20:10:08 volumio volumio[26131]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 20:10:08 volumio volumio[26131]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 20:10:08 volumio volumio[26131]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 20:10:08 volumio volumio[26131]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 20:10:08 volumio volumio[26131]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 20:10:08 volumio volumio[26131]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 20:10:08 volumio volumio[26131]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 20:10:08 volumio volumio[26131]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 20:10:08 volumio volumio[26131]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 20:10:08 volumio volumio[26131]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 20:10:08 volumio volumio[26131]: info: No need to fix Spotify hosts Jan 28 20:10:09 volumio go-librespot[26378]: time="2026-01-28T20:10:09+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 20:10:09 volumio go-librespot[26378]: time="2026-01-28T20:10:09+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 28 20:10:09 volumio go-librespot[26378]: time="2026-01-28T20:10:09+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 28 20:10:09 volumio go-librespot[26378]: time="2026-01-28T20:10:09+07:00" level=info msg="zeroconf server listening on port 44375" Jan 28 20:10:09 volumio go-librespot[26378]: time="2026-01-28T20:10:09+07:00" level=debug msg="obtained new client token: AAANXuW9CyJk1NoxUu23N6Kyr+8XK1sh03XMy+EZh72zZFQPvb+A9l5I0wpJSyVfJe6BOmqS84xcDV8iqGDYQkffyccJKdXQeR7dytwGFFKNgLhjCdmahgjCWyZCyn0KDQxTCJ9UskKs2/d7+ZskWPGPo9FggYH3foBJThlbJkfsrrz7QfPIlddtyQ1npQbVBCihsk1GOhIz6D4352smp0smz0w9apAtqjUDif/sK2HrkVrrTeviNVRViF4=" Jan 28 20:10:09 volumio volumio[26131]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 28 20:10:09 volumio volumio[26131]: SPOTIFY: BQBkDMlmooGuipRrVpkRbZd4h8WP_weN4nbVIADMW--AbOr3l7IqfopMxGHXGROkSwXORVfbK_4tXJI33hhMihGCcV1fFAPcrDAd7WIzKibkIPXHUW32FIZHBJ7XSbB9binUh0k2BKqVrnauNb6PNoiXR24GdtzNqb-GDpRmkDepaciEuOswssQhK1QsNh6BighV1LyefBROdiewlN7zT7ydgO-Th-3_BvWwGx9t2sMWARuEl9ZcUyuAxCD5AO_s3ai5jRFxaGFV2NE6AKtgktlqSz2ftu1KIJdmG8C7IagXsvbTH009oRsP Jan 28 20:10:09 volumio volumio[26131]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 28 20:10:09 volumio volumio[26131]: info: New Spotify access token = BQBkDMlmooGuipRrVpkRbZd4h8WP_weN4nbVIADMW--AbOr3l7IqfopMxGHXGROkSwXORVfbK_4tXJI33hhMihGCcV1fFAPcrDAd7WIzKibkIPXHUW32FIZHBJ7XSbB9binUh0k2BKqVrnauNb6PNoiXR24GdtzNqb-GDpRmkDepaciEuOswssQhK1QsNh6BighV1LyefBROdiewlN7zT7ydgO-Th-3_BvWwGx9t2sMWARuEl9ZcUyuAxCD5AO_s3ai5jRFxaGFV2NE6AKtgktlqSz2ftu1KIJdmG8C7IagXsvbTH009oRsP Jan 28 20:10:09 volumio volumio[26131]: info: Spotify credentials grant success - running version from March 24, 2019 Jan 28 20:10:09 volumio go-librespot[26378]: time="2026-01-28T20:10:09+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 20:10:09 volumio volumio[26131]: info: Starting Shairport Sync Jan 28 20:10:09 volumio go-librespot[26378]: time="2026-01-28T20:10:09+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 28 20:10:09 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 20:10:09 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 20:10:09 volumio volumio[26131]: info: Starting Shairport Sync Jan 28 20:10:09 volumio volumio[26131]: info: Starting Shairport Sync Jan 28 20:10:09 volumio sudo[26408]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 28 20:10:09 volumio sudo[26408]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 20:10:09 volumio sudo[26410]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 28 20:10:09 volumio sudo[26410]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 20:10:09 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 28 20:10:09 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Jan 28 20:10:09 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 28 20:10:09 volumio systemd[1]: shairport-sync.service: Consumed 2.403s CPU time. Jan 28 20:10:09 volumio sudo[26413]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 28 20:10:09 volumio sudo[26413]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 20:10:09 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 28 20:10:09 volumio sudo[26408]: pam_unix(sudo:session): session closed for user root Jan 28 20:10:10 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 28 20:10:10 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Jan 28 20:10:10 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 28 20:10:10 volumio volumio[26131]: info: Shairport-Sync Started Jan 28 20:10:10 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 28 20:10:10 volumio volumio[26131]: Error adding Membership: Error: addMembership EINVAL Jan 28 20:10:10 volumio sudo[26413]: pam_unix(sudo:session): session closed for user root Jan 28 20:10:10 volumio sudo[26410]: pam_unix(sudo:session): session closed for user root Jan 28 20:10:10 volumio volumio[26131]: info: CoreCommandRouter::volumioGetState Jan 28 20:10:10 volumio volumio[26131]: info: CorePlayQueue::getTrack 0 Jan 28 20:10:10 volumio volumio[26131]: info: Shairport-Sync Started Jan 28 20:10:10 volumio volumio[26131]: info: Shairport-Sync Started Jan 28 20:10:10 volumio volumio[26131]: SPOTIFY: User informations: {"country":"PK","display_name":"215mmgea6kss3jxeqsqdquvji","email":"linh.ngotran@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/215mmgea6kss3jxeqsqdquvji"},"followers":{"href":null,"total":1},"href":"https://api.spotify.com/v1/users/215mmgea6kss3jxeqsqdquvji","id":"215mmgea6kss3jxeqsqdquvji","images":[],"product":"premium","type":"user","uri":"spotify:user:215mmgea6kss3jxeqsqdquvji"} Jan 28 20:10:10 volumio volumio[26131]: info: Spotify Successfully logged in Jan 28 20:10:10 volumio volumio[26131]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 20:10:10 volumio volumio[26131]: info: [1769605810398] CoreMusicLibrary::Adding element Spotify Jan 28 20:10:10 volumio volumio[26131]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 20:10:10 volumio volumio[26131]: Cannot find translation for source YouTube Music Jan 28 20:10:10 volumio volumio[26131]: Cannot find translation for source Spotify Jan 28 20:10:10 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 20:10:10 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 20:10:10 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 20:10:12 volumio volumio[26131]: info: [yt-cast-receiver] DIAL server listening on port 8098 Jan 28 20:10:12 volumio volumio[26131]: info: CoreCommandRouter::volumioRetrievevolume Jan 28 20:10:12 volumio volumio[26131]: info: go-librespot daemon successfully initialized Jan 28 20:10:12 volumio volumio[26131]: info: VolumeController:: Volume=100 Mute =false Jan 28 20:10:12 volumio volumio[26131]: info: CoreCommandRouter::volumioGetState Jan 28 20:10:12 volumio volumio[26131]: info: CorePlayQueue::getTrack 0 Jan 28 20:10:12 volumio volumio[26131]: info: CoreStateMachine::pushState Jan 28 20:10:12 volumio volumio[26131]: info: CorePlayQueue::getTrack 0 Jan 28 20:10:12 volumio volumio[26131]: info: CoreCommandRouter::volumioPushState Jan 28 20:10:12 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 20:10:12 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 20:10:12 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 20:10:12 volumio mpd[26353]: 2026-01-28T20:10:12 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 28 20:10:12 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Jan 28 20:10:12 volumio systemd[1]: Started mpd.service - Music Player Daemon. Jan 28 20:10:12 volumio sudo[26315]: pam_unix(sudo:session): session closed for user root Jan 28 20:10:12 volumio sudo[26326]: pam_unix(sudo:session): session closed for user root Jan 28 20:10:12 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 20:10:12 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 20:10:12 volumio go-librespot[26463]: go-librespot daemon starting... Jan 28 20:10:12 volumio go-librespot[26466]: time="2026-01-28T20:10:12+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 20:10:12 volumio go-librespot[26466]: time="2026-01-28T20:10:12+07:00" level=debug msg="app state loaded" Jan 28 20:10:12 volumio go-librespot[26466]: time="2026-01-28T20:10:12+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 20:10:13 volumio volumio[26131]: error: MPD error: The expression evaluated to a falsy value: Jan 28 20:10:13 volumio volumio[26131]: assert.ok(self.idling) Jan 28 20:10:13 volumio volumio[26131]: error: The expression evaluated to a falsy value: Jan 28 20:10:13 volumio volumio[26131]: assert.ok(self.idling) Jan 28 20:10:13 volumio volumio[26131]: info: MPD running with PID26353 Jan 28 20:10:13 volumio volumio[26131]: ,establishing connection Jan 28 20:10:13 volumio volumio[26131]: error: updateQueue error: null Jan 28 20:10:13 volumio volumio[26131]: info: Completed starting Core Plugins Jan 28 20:10:13 volumio volumio[26131]: info: ------------------------------------------- Jan 28 20:10:13 volumio volumio[26131]: info: ----- MyVolumio plugins startup ---- Jan 28 20:10:13 volumio volumio[26131]: info: ------------------------------------------- Jan 28 20:10:13 volumio volumio[26131]: info: [MyVolumio PluginManager] Fetching plans data.... Jan 28 20:10:13 volumio volumio[26131]: error: updateQueue error: null Jan 28 20:10:13 volumio go-librespot[26466]: time="2026-01-28T20:10:13+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 28 20:10:13 volumio go-librespot[26466]: time="2026-01-28T20:10:13+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Jan 28 20:10:13 volumio go-librespot[26466]: time="2026-01-28T20:10:13+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Jan 28 20:10:13 volumio go-librespot[26466]: time="2026-01-28T20:10:13+07:00" level=info msg="zeroconf server listening on port 36261" Jan 28 20:10:13 volumio go-librespot[26466]: time="2026-01-28T20:10:13+07:00" level=debug msg="obtained new client token: AACXUaHwLYbg6j0HfejcjeH9SL4wSsbaNuhLl3FSLhoVWFysKhD+o0zaZJim4khI7FQMuaVgi6sbuHncX6SwK1CypCxkG/fspauNaBBHg1KueoB/iWQgESoxopg7ODiSrP9Qa3bWM6HEXTYvkPOa0Nc0Biqny1OcBFKdtAy78YGsQ5nxdQNaQWNz+NqScmCM9gKUNjwxz1EBBkyDAT/WIl/TPzpGWolgNkZ+VAdMB+jTDDzyWwFccONuyDg=" Jan 28 20:10:13 volumio go-librespot[26466]: time="2026-01-28T20:10:13+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 20:10:13 volumio go-librespot[26466]: time="2026-01-28T20:10:13+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Jan 28 20:10:13 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 20:10:13 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 20:10:14 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 20:10:14 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 20:10:14 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 20:10:15 volumio volumio[26131]: info: Initializing connection to go-librespot Websocket Jan 28 20:10:15 volumio volumio[26131]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 28 20:10:16 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 20:10:16 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 20:10:16 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 20:10:16 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Jan 28 20:10:16 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 20:10:17 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 20:10:17 volumio go-librespot[26473]: go-librespot daemon starting... Jan 28 20:10:17 volumio go-librespot[26474]: time="2026-01-28T20:10:17+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 20:10:17 volumio go-librespot[26474]: time="2026-01-28T20:10:17+07:00" level=debug msg="app state loaded" Jan 28 20:10:17 volumio go-librespot[26474]: time="2026-01-28T20:10:17+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 20:10:17 volumio go-librespot[26474]: time="2026-01-28T20:10:17+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 20:10:17 volumio go-librespot[26474]: time="2026-01-28T20:10:17+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 28 20:10:17 volumio go-librespot[26474]: time="2026-01-28T20:10:17+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 28 20:10:17 volumio go-librespot[26474]: time="2026-01-28T20:10:17+07:00" level=info msg="zeroconf server listening on port 43685" Jan 28 20:10:17 volumio go-librespot[26474]: time="2026-01-28T20:10:17+07:00" level=debug msg="obtained new client token: AABJbazl5v6JpFeTWq8+gzQKHns9memeNn4MBhXPs+jeYJdSYiQa7xoBHtpSV0VDhLal/SyvxxqDzLHKOjfiYXFvhubE0X8BYcNIvpvLHOuIAB8opHfFYpJvTh5WVfcEph+iyXI3B8xMpqa/Pi0X9sPsLohRPSwYn8DWKc6d2Hxr9hwMbGpk3WAxsLt9gn74OHMUJ0PsGb/bYPEThaU+FHzUDTvFPnTmgzidZnbYE52sXVOkY8nHHOYBCCs=" Jan 28 20:10:17 volumio volumio[26131]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Jan 28 20:10:17 volumio go-librespot[26474]: time="2026-01-28T20:10:17+07:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:4070, retrying with a different AP" error="dial tcp 104.199.241.202:4070: connect: connection refused" Jan 28 20:10:17 volumio go-librespot[26474]: time="2026-01-28T20:10:17+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Jan 28 20:10:18 volumio go-librespot[26474]: time="2026-01-28T20:10:18+07:00" level=debug msg="completed keyexchange" Jan 28 20:10:18 volumio go-librespot[26474]: time="2026-01-28T20:10:18+07:00" level=debug msg="completed challenge" Jan 28 20:10:18 volumio go-librespot[26474]: time="2026-01-28T20:10:18+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 20:10:18 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 20:10:18 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 20:10:18 volumio volumio[26131]: info: Initializing connection to go-librespot Websocket Jan 28 20:10:18 volumio volumio[26131]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 28 20:10:18 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 20:10:18 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 20:10:18 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 20:10:20 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 20:10:20 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 20:10:20 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 20:10:21 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Jan 28 20:10:21 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 20:10:21 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 20:10:21 volumio go-librespot[26484]: go-librespot daemon starting... Jan 28 20:10:21 volumio go-librespot[26485]: time="2026-01-28T20:10:21+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 20:10:21 volumio go-librespot[26485]: time="2026-01-28T20:10:21+07:00" level=debug msg="app state loaded" Jan 28 20:10:21 volumio go-librespot[26485]: time="2026-01-28T20:10:21+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 20:10:21 volumio volumio[26131]: info: Initializing connection to go-librespot Websocket Jan 28 20:10:21 volumio go-librespot[26485]: time="2026-01-28T20:10:21+07:00" level=debug msg="new websocket client" Jan 28 20:10:21 volumio volumio[26131]: info: Connection to go-librespot Websocket established Jan 28 20:10:21 volumio go-librespot[26485]: time="2026-01-28T20:10:21+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 20:10:21 volumio go-librespot[26485]: time="2026-01-28T20:10:21+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 28 20:10:21 volumio go-librespot[26485]: time="2026-01-28T20:10:21+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 28 20:10:21 volumio go-librespot[26485]: time="2026-01-28T20:10:21+07:00" level=info msg="zeroconf server listening on port 41957" Jan 28 20:10:21 volumio volumio[26131]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Jan 28 20:10:21 volumio volumio[26131]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Jan 28 20:10:21 volumio volumio[26131]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Jan 28 20:10:21 volumio volumio[26131]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Jan 28 20:10:21 volumio volumio[26131]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Jan 28 20:10:21 volumio volumio[26131]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Jan 28 20:10:21 volumio volumio[26131]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Jan 28 20:10:21 volumio volumio[26131]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Jan 28 20:10:21 volumio volumio[26131]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Jan 28 20:10:21 volumio volumio[26131]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Jan 28 20:10:21 volumio volumio[26131]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Jan 28 20:10:21 volumio volumio[26131]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Jan 28 20:10:21 volumio volumio[26131]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Jan 28 20:10:21 volumio volumio[26131]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Jan 28 20:10:21 volumio volumio[26131]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Jan 28 20:10:21 volumio volumio[26131]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Jan 28 20:10:21 volumio volumio[26131]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Jan 28 20:10:21 volumio volumio[26131]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Jan 28 20:10:21 volumio volumio[26131]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Jan 28 20:10:21 volumio volumio[26131]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Jan 28 20:10:21 volumio volumio[26131]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Jan 28 20:10:21 volumio volumio[26131]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Jan 28 20:10:21 volumio volumio[26131]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Jan 28 20:10:21 volumio volumio[26131]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Jan 28 20:10:21 volumio volumio[26131]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Jan 28 20:10:21 volumio volumio[26131]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Jan 28 20:10:21 volumio volumio[26131]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Jan 28 20:10:21 volumio volumio[26131]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Jan 28 20:10:21 volumio volumio[26131]: info: Adding plugin bluetooth to MyMusic Plugins Jan 28 20:10:21 volumio volumio[26131]: info: Adding plugin multiroom to MyMusic Plugins Jan 28 20:10:21 volumio volumio[26131]: info: Adding plugin metavolumio to MyMusic Plugins Jan 28 20:10:21 volumio volumio[26131]: info: Adding plugin cd_controller to MyMusic Plugins Jan 28 20:10:21 volumio volumio[26131]: info: Adding plugin qobuzconnect to MyMusic Plugins Jan 28 20:10:21 volumio volumio[26131]: info: Adding plugin smart_inputs to MyMusic Plugins Jan 28 20:10:21 volumio volumio[26131]: info: Adding plugin tidalconnect to MyMusic Plugins Jan 28 20:10:21 volumio volumio[26131]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Jan 28 20:10:22 volumio go-librespot[26485]: time="2026-01-28T20:10:22+07:00" level=debug msg="obtained new client token: AAAyb8/xmDloPK8s9gDPGPPa5YJKWrSU3QtYajFFIprcQ/9hUYQP+pzPJJNr2+ouAjh7+axLJJMXEZey/nMt/wpQ7onCTuM9SflTIFGgNdZ4TVrf8Gv90SyC75GBS0oO0NSpUFwPYtyB/iifdP2IoAoVskg6PlY9ssXMI6Ikfsn4I3eL/muqLuEd9I0j71v2YKwjGCfNBVGqhE3Ls2xpEejuIp8U+BDCI2gxpObw3Vw1BTk6WqC+yJde" Jan 28 20:10:22 volumio go-librespot[26485]: time="2026-01-28T20:10:22+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 20:10:22 volumio go-librespot[26485]: time="2026-01-28T20:10:22+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Jan 28 20:10:22 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 20:10:22 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 20:10:22 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 20:10:22 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 20:10:22 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 20:10:23 volumio volumio[26131]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Jan 28 20:10:23 volumio volumio[26131]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Jan 28 20:10:23 volumio volumio[26131]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 20:10:23 volumio volumio[26131]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 20:10:23 volumio volumio[26131]: info: Starting MyVolumio Remote Streaming Endpoints Jan 28 20:10:23 volumio volumio[26131]: info: MyVolumio login type: Token Jan 28 20:10:24 volumio volumio[26131]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Jan 28 20:10:24 volumio volumio[26131]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Jan 28 20:10:24 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 20:10:24 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 20:10:24 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 20:10:25 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Jan 28 20:10:25 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 20:10:25 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 20:10:25 volumio go-librespot[26507]: go-librespot daemon starting... Jan 28 20:10:25 volumio go-librespot[26508]: time="2026-01-28T20:10:25+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 20:10:25 volumio go-librespot[26508]: time="2026-01-28T20:10:25+07:00" level=debug msg="app state loaded" Jan 28 20:10:25 volumio go-librespot[26508]: time="2026-01-28T20:10:25+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 20:10:25 volumio volumio[26131]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Jan 28 20:10:25 volumio volumio[26131]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Jan 28 20:10:25 volumio volumio[26131]: info: Streaming services startup Jan 28 20:10:25 volumio volumio[26131]: info: Starting Streaming Daemon Jan 28 20:10:25 volumio sudo[26517]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jan 28 20:10:25 volumio sudo[26517]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 20:10:25 volumio volumio[26131]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Jan 28 20:10:25 volumio sudo[26517]: pam_unix(sudo:session): session closed for user root Jan 28 20:10:25 volumio volumio[26131]: info: Getting Spotify volume Jan 28 20:10:25 volumio volumio[26131]: info: Connection to go-librespot Websocket closed Jan 28 20:10:25 volumio volumio[26131]: error: Cannot start Volumio Streaming Daemon Jan 28 20:10:25 volumio volumio[26131]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Jan 28 20:10:25 volumio volumio[26131]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Jan 28 20:10:25 volumio volumio[26131]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Jan 28 20:10:26 volumio volumio[26131]: info: CoreCommandRouter::volumioGetState Jan 28 20:10:26 volumio volumio[26131]: info: CorePlayQueue::getTrack 0 Jan 28 20:10:26 volumio volumio[26131]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jan 28 20:10:26 volumio volumio[26131]: SPOTIFY: SPOTIFY VOLUME undefined Jan 28 20:10:26 volumio volumio[26131]: SPOTIFY: VOLUMIO VOLUME 100 Jan 28 20:10:26 volumio volumio[26131]: info: Aligning Spotify Volume to Volumio Volume Jan 28 20:10:26 volumio volumio[26131]: info: CoreCommandRouter::volumioGetState Jan 28 20:10:26 volumio volumio[26131]: info: CorePlayQueue::getTrack 0 Jan 28 20:10:26 volumio volumio[26131]: info: Setting Spotify Volume from Volumio: 100 Jan 28 20:10:26 volumio go-librespot[26508]: time="2026-01-28T20:10:26+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 20:10:26 volumio go-librespot[26508]: time="2026-01-28T20:10:26+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 28 20:10:26 volumio go-librespot[26508]: time="2026-01-28T20:10:26+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 28 20:10:26 volumio go-librespot[26508]: time="2026-01-28T20:10:26+07:00" level=info msg="zeroconf server listening on port 32977" Jan 28 20:10:26 volumio go-librespot[26508]: time="2026-01-28T20:10:26+07:00" level=debug msg="obtained new client token: AAB0tHEl6wfLEcHCt5Adak113MqcjqvmIfscnqp7glMB15eeUYxUqtaZjP/kXJGGJZfOPk14Zsdl0cLb7sXeyw2Pe2TDFvrm1PAfqvO62uichyDeLt4FYYoY4ogo+lrolWJOHvmBTi5LHEWmKslJB2zXgdD9qbUm6WjCtTZA+AFAyn/tJRf/7rYBU7lX7T72mrRUqd4XB2ql0ra5DQpi3CsQjhwqTteqUbj2kSm8Gyrs5c1PkyboguiTWL8=" Jan 28 20:10:26 volumio go-librespot[26508]: time="2026-01-28T20:10:26+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 20:10:26 volumio go-librespot[26508]: time="2026-01-28T20:10:26+07:00" level=debug msg="completed keyexchange" Jan 28 20:10:26 volumio go-librespot[26508]: time="2026-01-28T20:10:26+07:00" level=debug msg="completed challenge" Jan 28 20:10:26 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 20:10:26 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 20:10:26 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 20:10:26 volumio go-librespot[26508]: time="2026-01-28T20:10:26+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 20:10:26 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 20:10:26 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 20:10:26 volumio volumio[26131]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 28 20:10:26 volumio volumio[26131]: Error: socket hang up Jan 28 20:10:26 volumio volumio[26131]: at connResetException (node:internal/errors:720:14) Jan 28 20:10:26 volumio volumio[26131]: at Socket.socketOnEnd (node:_http_client:519:23) Jan 28 20:10:26 volumio volumio[26131]: at Socket.emit (node:events:526:35) Jan 28 20:10:26 volumio volumio[26131]: at endReadableNT (node:internal/streams/readable:1376:12) Jan 28 20:10:26 volumio volumio[26131]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Jan 28 20:10:26 volumio volumio[26131]: code: 'ECONNRESET', Jan 28 20:10:26 volumio volumio[26131]: response: undefined Jan 28 20:10:26 volumio volumio[26131]: } Jan 28 20:10:26 volumio volumio[26131]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 28 20:10:28 volumio sudo[26537]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-01-28 20:09' Jan 28 20:10:28 volumio sudo[26537]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 20:10:28 volumio sudo[26537]: pam_unix(sudo:session): session closed for user root Jan 28 20:10:28 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 20:10:28 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 20:10:28 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 20:10:29 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Jan 28 20:10:29 volumio volumio-remote-updater[628]: [2026-01-28 20:10:29] [error] handle_read_frame error: asio.system:104 (Connection reset by peer) Jan 28 20:10:29 volumio volumio-remote-updater[628]: [2026-01-28 20:10:29] [disconnect] Disconnect close local:[1006,Connection reset by peer] remote:[1006] Jan 28 20:10:29 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Jan 28 20:10:29 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 20:10:30 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 20:10:30 volumio go-librespot[26545]: go-librespot daemon starting... Jan 28 20:10:30 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Jan 28 20:10:30 volumio systemd[1]: volumio.service: Consumed 59.326s CPU time. Jan 28 20:10:30 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 28 20:10:30 volumio go-librespot[26552]: time="2026-01-28T20:10:30+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 20:10:30 volumio go-librespot[26552]: time="2026-01-28T20:10:30+07:00" level=debug msg="app state loaded" Jan 28 20:10:30 volumio go-librespot[26552]: time="2026-01-28T20:10:30+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 20:10:30 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Jan 28 20:10:30 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 10597. Jan 28 20:10:30 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 28 20:10:30 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Jan 28 20:10:30 volumio systemd[1]: volumio.service: Consumed 59.326s CPU time. Jan 28 20:10:30 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Jan 28 20:10:30 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Jan 28 20:10:30 volumio go-librespot[26552]: time="2026-01-28T20:10:30+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 20:10:30 volumio go-librespot[26552]: time="2026-01-28T20:10:30+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 28 20:10:30 volumio go-librespot[26552]: time="2026-01-28T20:10:30+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 28 20:10:30 volumio go-librespot[26552]: time="2026-01-28T20:10:30+07:00" level=info msg="zeroconf server listening on port 32955" Jan 28 20:10:30 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 20:10:30 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 20:10:30 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 20:10:30 volumio go-librespot[26552]: time="2026-01-28T20:10:30+07:00" level=debug msg="obtained new client token: AACH+RHjmA5iE+3O0VMM0V6jqMkP5vaQqJO3W60AwulhJnBDxHwxv0kKikR7WWGRaSHGn4yoiVpztAmPHsVadlFqxUXvkWQteMp/Z95csnDRo8nOZT4MBWK/zMqsKdpFP6MMhySE0gI5a2rurcgb83f3tLUDOf4EIa9N9DDMMpopx9IFDoBuBHliDMvwK+bTWcEPgZ8c4Gl9nog7zhpet6KLAK0qxyM5Rc/lWfDsCiPS0xoBwlBHW2FWPxA=" Jan 28 20:10:31 volumio go-librespot[26552]: time="2026-01-28T20:10:31+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 20:10:31 volumio go-librespot[26552]: time="2026-01-28T20:10:31+07:00" level=debug msg="completed keyexchange" Jan 28 20:10:31 volumio go-librespot[26552]: time="2026-01-28T20:10:31+07:00" level=debug msg="completed challenge" Jan 28 20:10:31 volumio go-librespot[26552]: time="2026-01-28T20:10: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 28 20:10:31 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 20:10:31 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 20:10:32 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 20:10:32 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 20:10:32 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 20:10:33 volumio volumio[26565]: info: ------------------------------------------- Jan 28 20:10:33 volumio volumio[26565]: info: ----- Volumio3 ---- Jan 28 20:10:33 volumio volumio[26565]: info: ------------------------------------------- Jan 28 20:10:33 volumio volumio[26565]: info: ----- System startup ---- Jan 28 20:10:33 volumio volumio[26565]: info: ------------------------------------------- Jan 28 20:10:34 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Jan 28 20:10:34 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 20:10:34 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 20:10:34 volumio go-librespot[26587]: go-librespot daemon starting... Jan 28 20:10:34 volumio go-librespot[26588]: time="2026-01-28T20:10:34+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 20:10:34 volumio go-librespot[26588]: time="2026-01-28T20:10:34+07:00" level=debug msg="app state loaded" Jan 28 20:10:34 volumio go-librespot[26588]: time="2026-01-28T20:10:34+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 20:10:34 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 20:10:34 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 20:10:34 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 20:10:34 volumio go-librespot[26588]: time="2026-01-28T20:10:34+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 28 20:10:34 volumio go-librespot[26588]: time="2026-01-28T20:10:34+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Jan 28 20:10:34 volumio volumio-remote-updater[628]: [2026-01-28 20:10:34] [connect] Successful connection Jan 28 20:10:34 volumio go-librespot[26588]: time="2026-01-28T20:10:34+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Jan 28 20:10:34 volumio go-librespot[26588]: time="2026-01-28T20:10:34+07:00" level=info msg="zeroconf server listening on port 40185" Jan 28 20:10:35 volumio go-librespot[26588]: time="2026-01-28T20:10:35+07:00" level=debug msg="obtained new client token: AABm1gh5VYlcFuFfpn69Ro/TzA7siuKF0R2WFj687CzbcY5JhqkQmD0SoFO3CTqwTrWhSXd3kQ+uV8ssADF9QuhyuRWdKqR5ffTH0togbxskpmf8DoLurmoAgo02e4VLcJwoZHLV/sjmBoj+ITohxHB34xc3EpBrrSj7qd2W4ykYIOwRJVmS6bSf2s5Fr63bo09o3BeKQ4CMj2uN3LQLH6yoLU+aDImFxfTCV2pIitJP4KU1hBuf5z4Q" Jan 28 20:10:35 volumio volumio[26565]: info: MYVOLUMIO Environment detected Jan 28 20:10:35 volumio go-librespot[26588]: time="2026-01-28T20:10:35+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 20:10:35 volumio go-librespot[26588]: time="2026-01-28T20:10: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 28 20:10:35 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 20:10:35 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 20:10:35 volumio volumio[26565]: info: Plugin folders cleanup Jan 28 20:10:35 volumio volumio[26565]: info: Scanning into folder /volumio/app/plugins/ Jan 28 20:10:35 volumio volumio[26565]: info: Scanning category audio_interface Jan 28 20:10:35 volumio volumio[26565]: info: Scanning category miscellanea Jan 28 20:10:35 volumio volumio[26565]: info: Scanning category music_service Jan 28 20:10:35 volumio volumio[26565]: info: Scanning category plugins.json Jan 28 20:10:35 volumio volumio[26565]: info: Scanning category system_controller Jan 28 20:10:35 volumio volumio[26565]: info: Scanning category user_interface Jan 28 20:10:35 volumio volumio[26565]: info: Scanning into folder /data/plugins/ Jan 28 20:10:35 volumio volumio[26565]: info: Scanning category music_service Jan 28 20:10:35 volumio volumio[26565]: info: Plugin folders cleanup completed Jan 28 20:10:35 volumio volumio[26565]: info: ------------------------------------------- Jan 28 20:10:35 volumio volumio[26565]: info: ----- Core plugins startup ---- Jan 28 20:10:35 volumio volumio[26565]: info: ------------------------------------------- Jan 28 20:10:35 volumio volumio[26565]: info: Loading plugins from folder /volumio/app/plugins/ Jan 28 20:10:35 volumio volumio[26565]: info: Adding plugin upnp to MyMusic Plugins Jan 28 20:10:35 volumio volumio[26565]: info: Adding plugin airplay_emulation to MyMusic Plugins Jan 28 20:10:35 volumio volumio[26565]: info: Adding plugin upnp_browser to MyMusic Plugins Jan 28 20:10:35 volumio volumio[26565]: info: Loading plugins from folder /data/plugins/ Jan 28 20:10:35 volumio volumio[26565]: info: Loading plugin "system"... Jan 28 20:10:35 volumio volumio[26565]: info: Loading plugin "appearance"... Jan 28 20:10:36 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 20:10:36 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 20:10:36 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 20:10:37 volumio volumio[26565]: info: Loading plugin "network"... Jan 28 20:10:37 volumio volumio[26565]: info: Refreshing Cached IP Addresses Jan 28 20:10:37 volumio sudo[26602]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 28 20:10:37 volumio sudo[26602]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 20:10:37 volumio sudo[26602]: pam_unix(sudo:session): session closed for user root Jan 28 20:10:37 volumio sudo[26604]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 28 20:10:37 volumio sudo[26604]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 20:10:37 volumio volumio[26565]: info: Loading plugin "services"... Jan 28 20:10:37 volumio volumio[26565]: info: Loading plugin "alsa_controller"... Jan 28 20:10:37 volumio sudo[26604]: pam_unix(sudo:session): session closed for user root Jan 28 20:10:37 volumio sudo[26612]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Jan 28 20:10:37 volumio sudo[26612]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 20:10:37 volumio volumio[26565]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 28 20:10:37 volumio volumio[26565]: info: Loading plugin "wizard"... Jan 28 20:10:37 volumio volumio[26565]: info: Loading plugin "networkfs"... Jan 28 20:10:37 volumio volumio[26565]: info: Starting Udev Watcher for removable devices Jan 28 20:10:37 volumio volumio[26565]: info: Ignoring mount for partition: boot Jan 28 20:10:37 volumio volumio[26565]: info: Ignoring mount for partition: volumio Jan 28 20:10:37 volumio volumio[26565]: info: Ignoring mount for partition: volumio_data Jan 28 20:10:37 volumio volumio[26565]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 28 20:10:37 volumio volumio[26565]: info: Loading plugin "volumio_command_line_client"... Jan 28 20:10:37 volumio volumio[26565]: info: Loading plugin "upnp"... Jan 28 20:10:37 volumio volumio[26565]: info: [1769605837847] Starting Upmpd Daemon Jan 28 20:10:37 volumio volumio[26565]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 28 20:10:37 volumio volumio[26565]: info: Loading plugin "my_music"... Jan 28 20:10:37 volumio volumio[26565]: info: Loading plugin "mpd"... Jan 28 20:10:38 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Jan 28 20:10:38 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 20:10:38 volumio volumio[26565]: info: Loading plugin "upnp_browser"... Jan 28 20:10:38 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 20:10:38 volumio go-librespot[26635]: go-librespot daemon starting... Jan 28 20:10:38 volumio go-librespot[26636]: time="2026-01-28T20:10:38+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 20:10:38 volumio go-librespot[26636]: time="2026-01-28T20:10:38+07:00" level=debug msg="app state loaded" Jan 28 20:10:38 volumio go-librespot[26636]: time="2026-01-28T20:10:38+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 20:10:38 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 20:10:38 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 20:10:38 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 20:10:39 volumio go-librespot[26636]: time="2026-01-28T20:10: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 28 20:10:39 volumio go-librespot[26636]: time="2026-01-28T20:10: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 28 20:10:39 volumio go-librespot[26636]: time="2026-01-28T20:10: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 28 20:10:39 volumio go-librespot[26636]: time="2026-01-28T20:10:39+07:00" level=info msg="zeroconf server listening on port 41591" Jan 28 20:10:39 volumio go-librespot[26636]: time="2026-01-28T20:10:39+07:00" level=debug msg="obtained new client token: AAAPO8zGHSa/d4PAzDVHZP4vD7gVWfvSHJjXKXXx7nBsMopsLX1wFQvqxq3YC7KuyCxSQiaDmKsrwLUKIDFeExIxW7IzkL63aYvlwnrfYp1Tx+d+7ZLS1qwgqFO9TAKJsJC8rSFQhWp+IpGlAtp57btYiPxcwMmps4/5Ad3wFdgt1dkyAs7z04aXZts2KPxGSvLaloP1+eolWTMd4htrslBVjWZtRE2SwF/jPTiNTsXgvOiwxxrU4v3zNy4=" Jan 28 20:10:39 volumio go-librespot[26636]: time="2026-01-28T20:10:39+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 20:10:39 volumio go-librespot[26636]: time="2026-01-28T20:10:39+07:00" level=debug msg="completed keyexchange" Jan 28 20:10:39 volumio go-librespot[26636]: time="2026-01-28T20:10:39+07:00" level=debug msg="completed challenge" Jan 28 20:10:39 volumio go-librespot[26636]: time="2026-01-28T20:10:39+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 20:10:39 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 20:10:39 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 20:10:40 volumio sudo[26612]: pam_unix(sudo:session): session closed for user root Jan 28 20:10:40 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 20:10:40 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 20:10:40 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 20:10:41 volumio volumio[26565]: info: Starting UPNP Browser Jan 28 20:10:41 volumio volumio[26565]: info: Loading plugin "alarm-clock"... Jan 28 20:10:41 volumio volumio[26565]: info: Loading plugin "airplay_emulation"... Jan 28 20:10:41 volumio volumio[26565]: info: Starting Shairport Sync Jan 28 20:10:41 volumio volumio[26565]: info: Loading plugin "last_100"... Jan 28 20:10:41 volumio volumio[26565]: info: Loading plugin "webradio"... Jan 28 20:10:41 volumio volumio[26565]: info: Loading plugin "i2s_dacs"... Jan 28 20:10:41 volumio volumio[26565]: info: Loading plugin "volumiodiscovery"... Jan 28 20:10:42 volumio volumio[26565]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 28 20:10:42 volumio volumio[26565]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 20:10:42 volumio node[26565]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 28 20:10:42 volumio volumio[26565]: *** WARNING *** For more information see Jan 28 20:10:42 volumio volumio[26565]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 28 20:10:42 volumio volumio[26565]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 20:10:42 volumio volumio[26565]: *** WARNING *** For more information see Jan 28 20:10:42 volumio node[26565]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 20:10:42 volumio node[26565]: *** WARNING *** For more information see Jan 28 20:10:42 volumio node[26565]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 28 20:10:42 volumio node[26565]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 20:10:42 volumio node[26565]: *** WARNING *** For more information see Jan 28 20:10:42 volumio volumio[26565]: info: Applying required configuration parameters for plugin volumiodiscovery Jan 28 20:10:42 volumio volumio[26565]: info: Discovery: Started advertising with name: Volumio Jan 28 20:10:42 volumio volumio[26565]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 28 20:10:42 volumio volumio[26565]: info: Loading plugin "spop"... Jan 28 20:10:42 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 20:10:42 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 20:10:42 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 20:10:42 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Jan 28 20:10:42 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 20:10:42 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 20:10:42 volumio go-librespot[26650]: go-librespot daemon starting... Jan 28 20:10:42 volumio go-librespot[26651]: time="2026-01-28T20:10:42+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 20:10:42 volumio go-librespot[26651]: time="2026-01-28T20:10:42+07:00" level=debug msg="app state loaded" Jan 28 20:10:42 volumio go-librespot[26651]: time="2026-01-28T20:10:42+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 20:10:43 volumio go-librespot[26651]: time="2026-01-28T20:10:43+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 28 20:10:43 volumio go-librespot[26651]: time="2026-01-28T20:10:43+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Jan 28 20:10:43 volumio go-librespot[26651]: time="2026-01-28T20:10:43+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Jan 28 20:10:43 volumio go-librespot[26651]: time="2026-01-28T20:10:43+07:00" level=info msg="zeroconf server listening on port 44267" Jan 28 20:10:43 volumio go-librespot[26651]: time="2026-01-28T20:10:43+07:00" level=debug msg="obtained new client token: AAAt2AksvXX0Wm9OmX8UycVi2FJZHv/2DRWAZIA9r0+3ZB6nCoE8GkG81Q+VqhzkONG2Dxj7zkIOXbWgEtRDh8P5ThcFzKCLwb9hlNIW0opd8Y7hoTx2JIfhMNQneWVEBBKltjhGIsthVQ70/a6exqQGQ8eu43rRQ5v5bXRPvVmVEro8j7Fflw7h1nGlqz6HyGXOVGUVA8w3ZWsxuURZAQnWcmUsAdH1Q4V1kb5gnZY9bSIFeWA/diCiJ0Q=" Jan 28 20:10:43 volumio go-librespot[26651]: time="2026-01-28T20:10:43+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 20:10:43 volumio go-librespot[26651]: time="2026-01-28T20:10:43+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 28 20:10:43 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 20:10:43 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 20:10:44 volumio volumio[26565]: info: Loading plugin "ytcr"... Jan 28 20:10:44 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 20:10:44 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 20:10:44 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 20:10:46 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 20:10:46 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 20:10:46 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 20:10:46 volumio volumio[26565]: info: Loading plugin "ytmusic"... Jan 28 20:10:46 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Jan 28 20:10:46 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 20:10:47 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 20:10:47 volumio go-librespot[26660]: go-librespot daemon starting... Jan 28 20:10:47 volumio go-librespot[26661]: time="2026-01-28T20:10:47+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 20:10:47 volumio go-librespot[26661]: time="2026-01-28T20:10:47+07:00" level=debug msg="app state loaded" Jan 28 20:10:47 volumio go-librespot[26661]: time="2026-01-28T20:10:47+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 20:10:47 volumio volumio-remote-updater[628]: [2026-01-28 20:10:47] [connect] Successful connection Jan 28 20:10:47 volumio go-librespot[26661]: time="2026-01-28T20:10:47+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 20:10:47 volumio go-librespot[26661]: time="2026-01-28T20:10:47+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 28 20:10:47 volumio go-librespot[26661]: time="2026-01-28T20:10:47+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 28 20:10:47 volumio go-librespot[26661]: time="2026-01-28T20:10:47+07:00" level=info msg="zeroconf server listening on port 34999" Jan 28 20:10:47 volumio volumio[26565]: info: Loading plugin "outputs"... Jan 28 20:10:47 volumio volumio[26565]: info: Loading plugin "albumart"... Jan 28 20:10:47 volumio go-librespot[26661]: time="2026-01-28T20:10:47+07:00" level=debug msg="obtained new client token: AAAmL2riWIyq7/SXGRkO9fhQUbToNW3PyJR+tc4t8hm71X/ISx0Kt0oCZVA9enWa/WCBdi37sktKfp5Zuqj+3aUZAFAZBn+Bwcf/ZNiPu7HfKSkUu2/vGhohJnqkHtLPRVWcLl+HVOkqsGnA/4gvpgPrcnU+3QL4RSDIo7Ns+MuH3w1S0xabGud5ncFHLT8snprAsBKq0zIix65x0AHYgYahGidy9+6S6GV1jb19TmWbf3oJ3q/qZCh4Ry4=" Jan 28 20:10:47 volumio volumio[26565]: info: Plugin example_plugin is not enabled Jan 28 20:10:47 volumio volumio[26565]: info: Loading plugin "inputs"... Jan 28 20:10:48 volumio volumio[26565]: info: Loading plugin "updater_comm"... Jan 28 20:10:48 volumio go-librespot[26661]: time="2026-01-28T20:10:48+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 20:10:48 volumio go-librespot[26661]: time="2026-01-28T20:10:48+07:00" level=debug msg="completed keyexchange" Jan 28 20:10:48 volumio go-librespot[26661]: time="2026-01-28T20:10:48+07:00" level=debug msg="completed challenge" Jan 28 20:10:48 volumio go-librespot[26661]: time="2026-01-28T20:10: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 28 20:10:48 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 20:10:48 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 20:10:48 volumio volumio[26565]: info: Plugin mpdemulation is not enabled Jan 28 20:10:48 volumio volumio[26565]: info: Loading plugin "rest_api"... Jan 28 20:10:48 volumio volumio[26565]: info: Loading plugin "websocket"... Jan 28 20:10:48 volumio volumio[26565]: info: Starting Socket.io Server version 1.7.4 Jan 28 20:10:48 volumio volumio[26565]: info: Loading plugin "RoonBridge"... Jan 28 20:10:48 volumio volumio[26565]: info: Applying required configuration parameters for plugin RoonBridge Jan 28 20:10:48 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 20:10:48 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 20:10:48 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 20:10:48 volumio volumio[26565]: info: Loading i18n strings for locale en Jan 28 20:10:48 volumio volumio[26565]: Updating browse sources language Jan 28 20:10:48 volumio volumio[26565]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 20:10:48 volumio volumio[26683]: Forking 3 albumart workers Jan 28 20:10:48 volumio volumio[26565]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 28 20:10:48 volumio volumio[26565]: info: CoreCommandRouter::initPlayerControls Jan 28 20:10:49 volumio volumio[26565]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 20:10:49 volumio volumio[26565]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 20:10:49 volumio volumio[26565]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 20:10:49 volumio volumio[26565]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 20:10:49 volumio volumio[26565]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 20:10:49 volumio volumio[26565]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 20:10:49 volumio volumio[26565]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 20:10:49 volumio volumio[26565]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 20:10:49 volumio volumio[26565]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 28 20:10:49 volumio volumio[26565]: Express server listening on port 3000 Jan 28 20:10:49 volumio volumio[26565]: [Metrics] WebUI: 16s 70.81ms Jan 28 20:10:49 volumio volumio[26565]: info: CoreStateMachine::resetVolumioState Jan 28 20:10:49 volumio volumio[26565]: info: CoreStateMachine::getcurrentVolume Jan 28 20:10:49 volumio volumio[26565]: info: CoreCommandRouter::volumioRetrievevolume Jan 28 20:10:49 volumio sudo[26727]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 28 20:10:49 volumio sudo[26730]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 28 20:10:49 volumio sudo[26727]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 20:10:49 volumio sudo[26730]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 20:10:49 volumio sudo[26727]: pam_unix(sudo:session): session closed for user root Jan 28 20:10:49 volumio sudo[26730]: pam_unix(sudo:session): session closed for user root Jan 28 20:10:49 volumio volumio[26565]: info: Volumio Network Manager: Network status updated: 1 Jan 28 20:10:49 volumio volumio[26565]: info: VolumeController:: Volume=100 Mute =false Jan 28 20:10:49 volumio volumio[26565]: info: CoreStateMachine::pushState Jan 28 20:10:49 volumio volumio[26565]: info: CorePlayQueue::getTrack 0 Jan 28 20:10:49 volumio volumio[26565]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 28 20:10:49 volumio volumio[26565]: info: CoreCommandRouter::volumioPushState Jan 28 20:10:49 volumio volumio[26565]: info: CoreStateMachine::updateTrackBlock Jan 28 20:10:49 volumio volumio[26565]: info: CorePlayQueue::getTrackBlock Jan 28 20:10:49 volumio volumio[26565]: info: CoreCommandRouter::volumioRetrievevolume Jan 28 20:10:49 volumio volumio-remote-updater[628]: [2026-01-28 20:10:49] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1769605847 101 Jan 28 20:10:49 volumio volumio[26565]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 1 Jan 28 20:10:49 volumio volumio[26565]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 20:10:49 volumio volumio[26565]: info: Reloading queue from file Jan 28 20:10:49 volumio volumio[26565]: info: CoreStateMachine::setRepeat null single undefined Jan 28 20:10:49 volumio volumio[26565]: info: CoreStateMachine::pushState Jan 28 20:10:49 volumio volumio[26565]: info: CorePlayQueue::getTrack 0 Jan 28 20:10:49 volumio volumio[26565]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 28 20:10:49 volumio volumio[26565]: info: CoreCommandRouter::volumioPushState Jan 28 20:10:49 volumio volumio[26565]: info: CoreStateMachine::setRandom null Jan 28 20:10:49 volumio volumio[26565]: info: CoreStateMachine::pushState Jan 28 20:10:49 volumio volumio[26565]: info: CorePlayQueue::getTrack 0 Jan 28 20:10:49 volumio volumio[26565]: info: CoreCommandRouter::volumioPushState Jan 28 20:10:49 volumio volumio[26565]: info: Setting Device type: Raspberry PI Jan 28 20:10:49 volumio volumio[26565]: info: Completed loading Core Plugins Jan 28 20:10:49 volumio volumio[26565]: info: Preparing to generate the ALSA configuration file Jan 28 20:10:50 volumio volumio[26565]: info: VolumeController:: Volume=100 Mute =false Jan 28 20:10:50 volumio volumio[26565]: info: CoreStateMachine::pushState Jan 28 20:10:50 volumio volumio[26565]: info: CorePlayQueue::getTrack 0 Jan 28 20:10:50 volumio volumio[26565]: info: CoreCommandRouter::volumioPushState Jan 28 20:10:50 volumio volumio[26565]: info: Asound.conf file unchanged, so no further update is needed Jan 28 20:10:50 volumio volumio[26565]: info: Output device has changed, restarting MPD Jan 28 20:10:50 volumio volumio[26565]: info: Output device has changed, restarting Shairport Sync Jan 28 20:10:50 volumio sudo[26743]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Jan 28 20:10:50 volumio sudo[26743]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 20:10:50 volumio volumio[26565]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 20:10:50 volumio volumio[26565]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 20:10:50 volumio sudo[26745]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 28 20:10:50 volumio sudo[26745]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 20:10:50 volumio volumio[26565]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 28 20:10:50 volumio volumio[26565]: info: ___________ START PLUGINS ___________ Jan 28 20:10:50 volumio sudo[26745]: pam_unix(sudo:session): session closed for user root Jan 28 20:10:50 volumio volumio[26565]: info: ControllerMpd::onStart: Initializing MPD Jan 28 20:10:50 volumio volumio[26565]: info: Creating MPD Configuration file Jan 28 20:10:50 volumio sudo[26750]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 28 20:10:50 volumio sudo[26743]: pam_unix(sudo:session): session closed for user root Jan 28 20:10:50 volumio sudo[26750]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 20:10:50 volumio volumio[26565]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 28 20:10:50 volumio volumio[26565]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 20:10:50 volumio volumio[26565]: info: [1769605850410] CoreMusicLibrary::Adding element Media Servers Jan 28 20:10:50 volumio volumio[26565]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 20:10:50 volumio sudo[26756]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 28 20:10:50 volumio sudo[26756]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 20:10:50 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Jan 28 20:10:50 volumio sudo[26756]: pam_unix(sudo:session): session closed for user root Jan 28 20:10:50 volumio volumio[26565]: info: UPNP Browser: Client initialized successfully Jan 28 20:10:50 volumio sudo[26758]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 28 20:10:50 volumio sudo[26758]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 20:10:50 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 28 20:10:50 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 28 20:10:50 volumio systemd[1]: mpd.service: Consumed 7.322s CPU time. Jan 28 20:10:50 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 28 20:10:50 volumio volumio[26565]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 20:10:50 volumio volumio[26565]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 20:10:50 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 28 20:10:50 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 28 20:10:50 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 20:10:50 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 20:10:50 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 20:10:50 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 28 20:10:50 volumio volumio[26565]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 28 20:10:50 volumio volumio[26565]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 20:10:50 volumio volumio[26565]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 20:10:50 volumio volumio[26565]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 28 20:10:50 volumio volumio[26565]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 20:10:50 volumio volumio[26565]: info: [1769605850788] CoreMusicLibrary::Adding element Last_100 Jan 28 20:10:50 volumio volumio[26565]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 20:10:50 volumio volumio[26565]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 20:10:50 volumio volumio[26565]: info: [1769605850807] CoreMusicLibrary::Adding element Webradio Jan 28 20:10:50 volumio volumio[26565]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 20:10:50 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 28 20:10:50 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 28 20:10:50 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 28 20:10:50 volumio volumio[26565]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 28 20:10:50 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 28 20:10:50 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 28 20:10:50 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 28 20:10:50 volumio volumio[26565]: info: Initializing BBC Radios Jan 28 20:10:50 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 28 20:10:50 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 28 20:10:51 volumio volumio[26565]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 28 20:10:51 volumio volumio[26565]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 20:10:51 volumio volumio[26565]: info: Creating Spotify config file Jan 28 20:10:51 volumio volumio[26565]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 20:10:51 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Jan 28 20:10:51 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 20:10:51 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 20:10:51 volumio go-librespot[26787]: go-librespot daemon starting... Jan 28 20:10:51 volumio sudo[26775]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 28 20:10:51 volumio sudo[26775]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jan 28 20:10:51 volumio sudo[26775]: pam_unix(sudo:session): session closed for user root Jan 28 20:10:51 volumio go-librespot[26788]: time="2026-01-28T20:10:51+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 20:10:52 volumio volumio[26694]: Starting albumart workers Jan 28 20:10:52 volumio volumio[26693]: Starting albumart workers Jan 28 20:10:52 volumio go-librespot[26788]: time="2026-01-28T20:10:52+07:00" level=info msg="zeroconf server listening on port 36637" Jan 28 20:10:52 volumio volumio[26695]: Starting albumart workers Jan 28 20:10:52 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 20:10:52 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 20:10:52 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 20:10:52 volumio volumio[26565]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 20:10:52 volumio volumio[26565]: info: [1769605852863] CoreMusicLibrary::Adding element YouTube Music Jan 28 20:10:52 volumio volumio[26565]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 20:10:52 volumio volumio[26565]: Cannot find translation for source YouTube Music Jan 28 20:10:52 volumio volumio[26565]: info: Volumio Calling Home Jan 28 20:10:53 volumio sudo[26799]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Jan 28 20:10:53 volumio sudo[26799]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 20:10:53 volumio sudo[26799]: pam_unix(sudo:session): session closed for user root Jan 28 20:10:53 volumio volumio[26565]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Jan 28 20:10:54 volumio volumio[26565]: info: Discovery: Found device Volumio Jan 28 20:10:54 volumio volumio[26565]: info: CoreCommandRouter::volumioGetState Jan 28 20:10:54 volumio volumio[26565]: info: CorePlayQueue::getTrack 0 Jan 28 20:10:54 volumio volumio[26565]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Jan 28 20:10:54 volumio volumio[26565]: info: Discovery: Found device Volumio Jan 28 20:10:54 volumio volumio[26565]: info: CoreCommandRouter::volumioGetState Jan 28 20:10:54 volumio volumio[26565]: info: CorePlayQueue::getTrack 0 Jan 28 20:10:54 volumio volumio[26565]: info: MPD Permissions set Jan 28 20:10:54 volumio volumio[26565]: info: MPD Permissions set Jan 28 20:10:54 volumio volumio[26565]: info: Upmpdcli Daemon Started Jan 28 20:10:54 volumio volumio[26565]: info: Volumio called home Jan 28 20:10:54 volumio volumio[26565]: info: Spotify config file written Jan 28 20:10:54 volumio volumio[26565]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Jan 28 20:10:54 volumio sudo[26817]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jan 28 20:10:54 volumio volumio[26565]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 20:10:54 volumio sudo[26817]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 20:10:54 volumio volumio[26565]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 20:10:54 volumio volumio[26565]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 20:10:54 volumio volumio[26565]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 20:10:54 volumio volumio[26565]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 20:10:54 volumio volumio[26565]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 20:10:54 volumio volumio[26565]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 20:10:54 volumio volumio[26565]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 20:10:54 volumio volumio[26565]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 20:10:54 volumio volumio[26565]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 20:10:54 volumio volumio[26565]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 20:10:54 volumio volumio[26565]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 20:10:54 volumio volumio[26565]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 20:10:54 volumio volumio[26565]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 20:10:54 volumio volumio[26565]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 20:10:54 volumio volumio[26565]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 20:10:54 volumio volumio[26565]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 20:10:54 volumio volumio[26565]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 20:10:54 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Jan 28 20:10:54 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Jan 28 20:10:54 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 20:10:54 volumio volumio[26565]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 20:10:54 volumio volumio[26565]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 20:10:54 volumio volumio[26565]: info: No need to fix Spotify hosts Jan 28 20:10:54 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 20:10:54 volumio go-librespot[26833]: go-librespot daemon starting... Jan 28 20:10:54 volumio sudo[26817]: pam_unix(sudo:session): session closed for user root Jan 28 20:10:54 volumio go-librespot[26837]: time="2026-01-28T20:10:54+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 20:10:54 volumio go-librespot[26837]: time="2026-01-28T20:10:54+07:00" level=debug msg="app state loaded" Jan 28 20:10:54 volumio go-librespot[26837]: time="2026-01-28T20:10:54+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 20:10:54 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 20:10:54 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 20:10:54 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 20:10:55 volumio go-librespot[26837]: time="2026-01-28T20:10:55+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 28 20:10:55 volumio go-librespot[26837]: time="2026-01-28T20:10:55+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Jan 28 20:10:55 volumio go-librespot[26837]: time="2026-01-28T20:10:55+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Jan 28 20:10:55 volumio go-librespot[26837]: time="2026-01-28T20:10:55+07:00" level=info msg="zeroconf server listening on port 34977" Jan 28 20:10:55 volumio volumio[26565]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 28 20:10:55 volumio volumio[26565]: SPOTIFY: BQDFiT1bF2uD2mIYZlmwvmqiiAIL-UgDT2kVJaVxpl8qEOBVRh0xB5YiSn7VQtryRbaIER6tsUT8ZuPv0ogtiLlLpb7M48e42a0bkVBQHCxPCYt6eDycDAEHR44JJzqWAV8yZb18i1lQKUhcDrFdd8qXy3B6PjAtDq6sStKuR_KNEUBSLRWfNQZyxficNvs6RMQN-9XCfCJBoSMRqkH79K6XBuWmwOj4ib8pgyXvoWvyIbb5fLv5HeyXcLpFFxySqjSLSyI5nXdfdpuu6ftQF04Tqdj_a6t8-Dv9m2I1Egkbm30xwdqPCVSJ Jan 28 20:10:55 volumio volumio[26565]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 28 20:10:55 volumio volumio[26565]: info: New Spotify access token = BQDFiT1bF2uD2mIYZlmwvmqiiAIL-UgDT2kVJaVxpl8qEOBVRh0xB5YiSn7VQtryRbaIER6tsUT8ZuPv0ogtiLlLpb7M48e42a0bkVBQHCxPCYt6eDycDAEHR44JJzqWAV8yZb18i1lQKUhcDrFdd8qXy3B6PjAtDq6sStKuR_KNEUBSLRWfNQZyxficNvs6RMQN-9XCfCJBoSMRqkH79K6XBuWmwOj4ib8pgyXvoWvyIbb5fLv5HeyXcLpFFxySqjSLSyI5nXdfdpuu6ftQF04Tqdj_a6t8-Dv9m2I1Egkbm30xwdqPCVSJ Jan 28 20:10:55 volumio volumio[26565]: info: Spotify credentials grant success - running version from March 24, 2019 Jan 28 20:10:55 volumio volumio[26565]: info: Starting Shairport Sync Jan 28 20:10:55 volumio volumio[26565]: info: Starting Shairport Sync Jan 28 20:10:55 volumio go-librespot[26837]: time="2026-01-28T20:10:55+07:00" level=debug msg="obtained new client token: AAAlsZL4aJ9ACdVCsyUJepZSmcfAi36wj1RJT84J7LVaXt6z+b33eUesTYvRKkAPfTf93Sf25OLQxjR3ADhEbFSOJpaVZIcQQQ4Tpl02dvF0CKrjVMogMFaEkoa8JkCOeWfH2UeMTzY+F/nH/1d1XssMw+qyS6PjYEQCrE5n/QZPX07duklnuqqfO0vxNlWuyyP/cbbV3USFYONkJ3fnqUrHVaPNXRQjqhvzY6+7FmINN7PQP2a97k0F7hA=" Jan 28 20:10:55 volumio volumio[26565]: info: Starting Shairport Sync Jan 28 20:10:55 volumio sudo[26845]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 28 20:10:55 volumio sudo[26845]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 20:10:55 volumio sudo[26847]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 28 20:10:55 volumio sudo[26847]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 20:10:55 volumio go-librespot[26837]: time="2026-01-28T20:10:55+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 20:10:55 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 28 20:10:55 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Jan 28 20:10:55 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 28 20:10:55 volumio systemd[1]: shairport-sync.service: Consumed 2.372s CPU time. Jan 28 20:10:55 volumio go-librespot[26837]: time="2026-01-28T20:10:55+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 28 20:10:55 volumio sudo[26850]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 28 20:10:55 volumio sudo[26850]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 20:10:55 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 28 20:10:55 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 20:10:55 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 20:10:55 volumio sudo[26845]: pam_unix(sudo:session): session closed for user root Jan 28 20:10:55 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 28 20:10:55 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Jan 28 20:10:55 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 28 20:10:55 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 28 20:10:55 volumio sudo[26847]: pam_unix(sudo:session): session closed for user root Jan 28 20:10:55 volumio sudo[26850]: pam_unix(sudo:session): session closed for user root Jan 28 20:10:55 volumio volumio[26565]: info: Shairport-Sync Started Jan 28 20:10:55 volumio volumio[26565]: Error adding Membership: Error: addMembership EINVAL Jan 28 20:10:56 volumio volumio[26565]: info: Shairport-Sync Started Jan 28 20:10:56 volumio volumio[26565]: info: Shairport-Sync Started Jan 28 20:10:56 volumio volumio[26565]: info: CoreCommandRouter::volumioGetState Jan 28 20:10:56 volumio volumio[26565]: info: CorePlayQueue::getTrack 0 Jan 28 20:10:56 volumio volumio[26565]: SPOTIFY: User informations: {"country":"PK","display_name":"215mmgea6kss3jxeqsqdquvji","email":"linh.ngotran@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/215mmgea6kss3jxeqsqdquvji"},"followers":{"href":null,"total":1},"href":"https://api.spotify.com/v1/users/215mmgea6kss3jxeqsqdquvji","id":"215mmgea6kss3jxeqsqdquvji","images":[],"product":"premium","type":"user","uri":"spotify:user:215mmgea6kss3jxeqsqdquvji"} Jan 28 20:10:56 volumio volumio[26565]: info: Spotify Successfully logged in Jan 28 20:10:56 volumio volumio[26565]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 20:10:56 volumio volumio[26565]: info: [1769605856262] CoreMusicLibrary::Adding element Spotify Jan 28 20:10:56 volumio volumio[26565]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 20:10:56 volumio volumio[26565]: Cannot find translation for source YouTube Music Jan 28 20:10:56 volumio volumio[26565]: Cannot find translation for source Spotify Jan 28 20:10:56 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 20:10:56 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 20:10:56 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 20:10:57 volumio volumio[26565]: info: [yt-cast-receiver] DIAL server listening on port 8098 Jan 28 20:10:57 volumio volumio[26565]: info: CoreCommandRouter::volumioRetrievevolume Jan 28 20:10:57 volumio volumio[26565]: info: VolumeController:: Volume=100 Mute =false Jan 28 20:10:57 volumio volumio[26565]: info: CoreCommandRouter::volumioGetState Jan 28 20:10:57 volumio volumio[26565]: info: CorePlayQueue::getTrack 0 Jan 28 20:10:57 volumio volumio[26565]: info: CoreStateMachine::pushState Jan 28 20:10:57 volumio volumio[26565]: info: CorePlayQueue::getTrack 0 Jan 28 20:10:57 volumio volumio[26565]: info: CoreCommandRouter::volumioPushState Jan 28 20:10:58 volumio volumio[26565]: info: go-librespot daemon successfully initialized Jan 28 20:10:58 volumio mpd[26795]: 2026-01-28T20:10:58 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 28 20:10:58 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Jan 28 20:10:58 volumio systemd[1]: Started mpd.service - Music Player Daemon. Jan 28 20:10:58 volumio sudo[26758]: pam_unix(sudo:session): session closed for user root Jan 28 20:10:58 volumio sudo[26750]: pam_unix(sudo:session): session closed for user root Jan 28 20:10:58 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 20:10:58 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 20:10:58 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 20:10:58 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 20:10:58 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 20:10:58 volumio go-librespot[26900]: go-librespot daemon starting... Jan 28 20:10:58 volumio go-librespot[26903]: time="2026-01-28T20:10:58+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 20:10:58 volumio go-librespot[26903]: time="2026-01-28T20:10:58+07:00" level=debug msg="app state loaded" Jan 28 20:10:58 volumio go-librespot[26903]: time="2026-01-28T20:10:58+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 20:10:58 volumio volumio[26565]: error: MPD error: The expression evaluated to a falsy value: Jan 28 20:10:58 volumio volumio[26565]: assert.ok(self.idling) Jan 28 20:10:58 volumio volumio[26565]: error: The expression evaluated to a falsy value: Jan 28 20:10:58 volumio volumio[26565]: assert.ok(self.idling) Jan 28 20:10:58 volumio volumio[26565]: error: updateQueue error: null Jan 28 20:10:58 volumio volumio[26565]: info: MPD running with PID26795 Jan 28 20:10:58 volumio volumio[26565]: ,establishing connection Jan 28 20:10:59 volumio volumio[26565]: info: Completed starting Core Plugins Jan 28 20:10:59 volumio volumio[26565]: info: ------------------------------------------- Jan 28 20:10:59 volumio volumio[26565]: info: ----- MyVolumio plugins startup ---- Jan 28 20:10:59 volumio volumio[26565]: info: ------------------------------------------- Jan 28 20:10:59 volumio volumio[26565]: info: [MyVolumio PluginManager] Fetching plans data.... Jan 28 20:10:59 volumio volumio[26565]: error: updateQueue error: null Jan 28 20:10:59 volumio go-librespot[26903]: time="2026-01-28T20:10:59+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 20:10:59 volumio go-librespot[26903]: time="2026-01-28T20:10:59+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 28 20:10:59 volumio go-librespot[26903]: time="2026-01-28T20:10:59+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 28 20:10:59 volumio go-librespot[26903]: time="2026-01-28T20:10:59+07:00" level=info msg="zeroconf server listening on port 36001" Jan 28 20:10:59 volumio go-librespot[26903]: time="2026-01-28T20:10:59+07:00" level=debug msg="obtained new client token: AACbtlcdUFCZQmf8nWfPT5RyscAPlvxc4UUfmNa1OK1Al+Bu8P7RJ9g2ZiVbVw0jyOVYgbkUDkEFzwp7Xmf1qOdGclmsjEmpKxLQAC9IvxcW+Nyo3lD0eh9aZa32LotPXRzEpXAA74oAmjMMtKL4N39FIJ2JqbapJw+UQjBuEqVfKmTq2qQ/G7rN3GJsHm+WLv1RXS3zljYKPIHnNDEWIXBMQNc8QZ3/nB25tg08TtSYtOtOEyL6V6hbh4U=" Jan 28 20:10:59 volumio go-librespot[26903]: time="2026-01-28T20:10:59+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 20:10:59 volumio go-librespot[26903]: time="2026-01-28T20:10:59+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 28 20:10:59 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 20:10:59 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 20:11:00 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 20:11:00 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 20:11:00 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 20:11:01 volumio volumio[26565]: info: Initializing connection to go-librespot Websocket Jan 28 20:11:01 volumio volumio[26565]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 28 20:11:02 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 20:11:02 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 20:11:02 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 20:11:02 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Jan 28 20:11:02 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 20:11:02 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 20:11:02 volumio go-librespot[26912]: go-librespot daemon starting... Jan 28 20:11:02 volumio go-librespot[26913]: time="2026-01-28T20:11:02+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 20:11:02 volumio go-librespot[26913]: time="2026-01-28T20:11:02+07:00" level=debug msg="app state loaded" Jan 28 20:11:02 volumio go-librespot[26913]: time="2026-01-28T20:11:02+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 20:11:03 volumio go-librespot[26913]: time="2026-01-28T20:11:03+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 20:11:03 volumio go-librespot[26913]: time="2026-01-28T20:11:03+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 28 20:11:03 volumio go-librespot[26913]: time="2026-01-28T20:11:03+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 28 20:11:03 volumio go-librespot[26913]: time="2026-01-28T20:11:03+07:00" level=info msg="zeroconf server listening on port 41491" Jan 28 20:11:03 volumio go-librespot[26913]: time="2026-01-28T20:11:03+07:00" level=debug msg="obtained new client token: AAC9ZK6mcx3doUwOTlXk+7C3P2L7B1aL+ySqWG0mSZ7Lr6R/Odosmo8CbS3xyXT1YLmNcvELqTi37/WmLCkCi12myMk9mQZKGC22b0yHZV3vU5vQ6ngOfLfDE5rbCUAr+uWWZEAY86+2d+TTX1/E63lR0oZhTAZcTVvaOHbeA26JlfU3jEY3Bix5Ypwc0/aOQ1DK4/XpRriFLMAlEnry8aS9gocInOuQR0gfGaPZJL/4Li2rTx8DNsCaSJs=" Jan 28 20:11:03 volumio go-librespot[26913]: time="2026-01-28T20:11:03+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 20:11:03 volumio volumio[26565]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Jan 28 20:11:03 volumio go-librespot[26913]: time="2026-01-28T20:11:03+07:00" level=debug msg="completed keyexchange" Jan 28 20:11:03 volumio go-librespot[26913]: time="2026-01-28T20:11:03+07:00" level=debug msg="completed challenge" Jan 28 20:11:03 volumio go-librespot[26913]: time="2026-01-28T20:11:03+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 20:11:03 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 20:11:03 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 20:11:04 volumio volumio[26565]: info: Initializing connection to go-librespot Websocket Jan 28 20:11:04 volumio volumio[26565]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 28 20:11:04 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 20:11:04 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 20:11:04 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 20:11:06 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 20:11:06 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 20:11:06 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 20:11:06 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Jan 28 20:11:06 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 20:11:07 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 20:11:07 volumio go-librespot[26921]: go-librespot daemon starting... Jan 28 20:11:07 volumio systemd[1]: Starting setdatetime-helper.service - Time Synchronization Helper Service... Jan 28 20:11:07 volumio go-librespot[26922]: time="2026-01-28T20:11:07+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 20:11:07 volumio go-librespot[26922]: time="2026-01-28T20:11:07+07:00" level=debug msg="app state loaded" Jan 28 20:11:07 volumio go-librespot[26922]: time="2026-01-28T20:11:07+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 20:11:07 volumio volumio[26565]: info: Initializing connection to go-librespot Websocket Jan 28 20:11:07 volumio go-librespot[26922]: time="2026-01-28T20:11:07+07:00" level=debug msg="new websocket client" Jan 28 20:11:07 volumio volumio[26565]: info: Connection to go-librespot Websocket established Jan 28 20:11:07 volumio go-librespot[26922]: time="2026-01-28T20:11:07+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 20:11:07 volumio go-librespot[26922]: time="2026-01-28T20:11:07+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 28 20:11:07 volumio go-librespot[26922]: time="2026-01-28T20:11:07+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 28 20:11:07 volumio go-librespot[26922]: time="2026-01-28T20:11:07+07:00" level=info msg="zeroconf server listening on port 40237" Jan 28 20:11:07 volumio go-librespot[26922]: time="2026-01-28T20:11:07+07:00" level=debug msg="obtained new client token: AADmOo6kw6w8HZj5NA1uyjBaS+xcYk0OxoCHRvPyNpo/5i5UyCnLIVTkjjswXb2OIrmd96YPElB19f2DRaZLiTwGrFhCQmNVLaTShYpGqPOyS6pVWCHc14Ps+KRxF3jBBBCW40GINyytvjt+/UpBHctK4qpQf9CAqERRuH/1pcLRGhl1N7IgUVWGbK6rHr6Flh52vgd2XXeiYV6NvE/OfVmrLT3v7EBMCsCCvDjHWQQE6XvayWJ/JyX8J9U=" Jan 28 20:11:07 volumio volumio[26565]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Jan 28 20:11:07 volumio volumio[26565]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Jan 28 20:11:07 volumio volumio[26565]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Jan 28 20:11:07 volumio volumio[26565]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Jan 28 20:11:07 volumio volumio[26565]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Jan 28 20:11:07 volumio volumio[26565]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Jan 28 20:11:07 volumio volumio[26565]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Jan 28 20:11:07 volumio volumio[26565]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Jan 28 20:11:07 volumio volumio[26565]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Jan 28 20:11:07 volumio volumio[26565]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Jan 28 20:11:07 volumio volumio[26565]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Jan 28 20:11:07 volumio volumio[26565]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Jan 28 20:11:07 volumio volumio[26565]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Jan 28 20:11:07 volumio volumio[26565]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Jan 28 20:11:07 volumio volumio[26565]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Jan 28 20:11:07 volumio volumio[26565]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Jan 28 20:11:07 volumio volumio[26565]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Jan 28 20:11:07 volumio volumio[26565]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Jan 28 20:11:07 volumio volumio[26565]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Jan 28 20:11:07 volumio volumio[26565]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Jan 28 20:11:07 volumio volumio[26565]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Jan 28 20:11:07 volumio volumio[26565]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Jan 28 20:11:07 volumio volumio[26565]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Jan 28 20:11:07 volumio volumio[26565]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Jan 28 20:11:07 volumio volumio[26565]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Jan 28 20:11:07 volumio volumio[26565]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Jan 28 20:11:07 volumio volumio[26565]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Jan 28 20:11:07 volumio volumio[26565]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Jan 28 20:11:07 volumio volumio[26565]: info: Adding plugin bluetooth to MyMusic Plugins Jan 28 20:11:07 volumio volumio[26565]: info: Adding plugin multiroom to MyMusic Plugins Jan 28 20:11:07 volumio volumio[26565]: info: Adding plugin metavolumio to MyMusic Plugins Jan 28 20:11:07 volumio volumio[26565]: info: Adding plugin cd_controller to MyMusic Plugins Jan 28 20:11:07 volumio volumio[26565]: info: Adding plugin qobuzconnect to MyMusic Plugins Jan 28 20:11:07 volumio volumio[26565]: info: Adding plugin smart_inputs to MyMusic Plugins Jan 28 20:11:07 volumio volumio[26565]: info: Adding plugin tidalconnect to MyMusic Plugins Jan 28 20:11:07 volumio volumio[26565]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Jan 28 20:11:07 volumio go-librespot[26922]: time="2026-01-28T20:11:07+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 20:11:08 volumio go-librespot[26922]: time="2026-01-28T20:11:08+07:00" level=debug msg="completed keyexchange" Jan 28 20:11:08 volumio go-librespot[26922]: time="2026-01-28T20:11:08+07:00" level=debug msg="completed challenge" Jan 28 20:11:08 volumio go-librespot[26922]: time="2026-01-28T20:11:08+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 20:11:08 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 20:11:08 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 20:11:08 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 20:11:08 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 20:11:08 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 20:11:09 volumio systemd[1]: setdatetime-helper.service: Deactivated successfully. Jan 28 20:11:09 volumio systemd[1]: Finished setdatetime-helper.service - Time Synchronization Helper Service. Jan 28 20:11:09 volumio systemd[1]: setdatetime-helper.service: Consumed 1.925s CPU time. Jan 28 20:11:09 volumio volumio[26565]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Jan 28 20:11:09 volumio volumio[26565]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Jan 28 20:11:09 volumio volumio[26565]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 20:11:09 volumio volumio[26565]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 20:11:10 volumio volumio[26565]: info: Starting MyVolumio Remote Streaming Endpoints Jan 28 20:11:10 volumio volumio[26565]: info: MyVolumio login type: Token Jan 28 20:11:10 volumio volumio[26565]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Jan 28 20:11:10 volumio volumio[26565]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Jan 28 20:11:10 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 20:11:10 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 20:11:10 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 20:11:11 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Jan 28 20:11:11 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 20:11:11 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 20:11:11 volumio go-librespot[26969]: go-librespot daemon starting... Jan 28 20:11:11 volumio go-librespot[26970]: time="2026-01-28T20:11:11+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 20:11:11 volumio go-librespot[26970]: time="2026-01-28T20:11:11+07:00" level=debug msg="app state loaded" Jan 28 20:11:11 volumio go-librespot[26970]: time="2026-01-28T20:11:11+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 20:11:11 volumio volumio[26565]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Jan 28 20:11:11 volumio volumio[26565]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Jan 28 20:11:11 volumio volumio[26565]: info: Streaming services startup Jan 28 20:11:11 volumio volumio[26565]: info: Starting Streaming Daemon Jan 28 20:11:11 volumio sudo[26979]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jan 28 20:11:11 volumio sudo[26979]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 20:11:11 volumio volumio[26565]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Jan 28 20:11:11 volumio sudo[26979]: pam_unix(sudo:session): session closed for user root Jan 28 20:11:11 volumio go-librespot[26970]: time="2026-01-28T20:11:11+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 20:11:11 volumio go-librespot[26970]: time="2026-01-28T20:11:11+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 28 20:11:11 volumio go-librespot[26970]: time="2026-01-28T20:11:11+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 28 20:11:11 volumio go-librespot[26970]: time="2026-01-28T20:11:11+07:00" level=info msg="zeroconf server listening on port 42859" Jan 28 20:11:11 volumio volumio[26565]: info: Getting Spotify volume Jan 28 20:11:11 volumio volumio[26565]: info: Connection to go-librespot Websocket closed Jan 28 20:11:11 volumio volumio[26565]: error: Cannot start Volumio Streaming Daemon Jan 28 20:11:11 volumio volumio[26565]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Jan 28 20:11:11 volumio volumio[26565]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Jan 28 20:11:12 volumio volumio[26565]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Jan 28 20:11:12 volumio go-librespot[26970]: time="2026-01-28T20:11:12+07:00" level=debug msg="obtained new client token: AACJVqJbR02XSx8zwkLtbtwvxHFuWRgc67d50v92g3TSBprJZ+KSzwIgBRntr/q6ey207a/D2Dip2va5faJaBnBh8TD6I0u0OMB2hR1qUm9lXW+T24M/tMfnHC+PASjjpKHn8JZRAPuCss5P4kb3TyrkdFAwBuoDRuBqQM6kf4Yeg/qudiYFe3hsg4Ue298h2g2gdDL8/rbrq1J6TC4AitJ4UmjKisT+SRt1t/f+p9kctl212dY+VAHa" Jan 28 20:11:12 volumio go-librespot[26970]: time="2026-01-28T20:11:12+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 20:11:12 volumio volumio[26565]: info: CoreCommandRouter::volumioGetState Jan 28 20:11:12 volumio volumio[26565]: info: CorePlayQueue::getTrack 0 Jan 28 20:11:12 volumio volumio[26565]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jan 28 20:11:12 volumio volumio[26565]: SPOTIFY: SPOTIFY VOLUME undefined Jan 28 20:11:12 volumio volumio[26565]: SPOTIFY: VOLUMIO VOLUME 100 Jan 28 20:11:12 volumio volumio[26565]: info: Aligning Spotify Volume to Volumio Volume Jan 28 20:11:12 volumio volumio[26565]: info: CoreCommandRouter::volumioGetState Jan 28 20:11:12 volumio volumio[26565]: info: CorePlayQueue::getTrack 0 Jan 28 20:11:12 volumio volumio[26565]: info: Setting Spotify Volume from Volumio: 100 Jan 28 20:11:12 volumio go-librespot[26970]: time="2026-01-28T20:11:12+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 28 20:11:12 volumio volumio[26565]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 28 20:11:12 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 20:11:12 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 20:11:12 volumio volumio[26565]: Error: socket hang up Jan 28 20:11:12 volumio volumio[26565]: at connResetException (node:internal/errors:720:14) Jan 28 20:11:12 volumio volumio[26565]: at Socket.socketOnEnd (node:_http_client:519:23) Jan 28 20:11:12 volumio volumio[26565]: at Socket.emit (node:events:526:35) Jan 28 20:11:12 volumio volumio[26565]: at endReadableNT (node:internal/streams/readable:1376:12) Jan 28 20:11:12 volumio volumio[26565]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Jan 28 20:11:12 volumio volumio[26565]: code: 'ECONNRESET', Jan 28 20:11:12 volumio volumio[26565]: response: undefined Jan 28 20:11:12 volumio volumio[26565]: } Jan 28 20:11:12 volumio volumio[26565]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 28 20:11:12 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 20:11:12 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 20:11:12 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 20:11:13 volumio sudo[26999]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-01-28 20:10' Jan 28 20:11:13 volumio sudo[26999]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 20:11:14 volumio sudo[26999]: pam_unix(sudo:session): session closed for user root Jan 28 20:11:14 volumio volumio-remote-updater[628]: [2026-01-28 20:11:14] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Jan 28 20:11:14 volumio volumio-remote-updater[628]: [2026-01-28 20:11:14] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Jan 28 20:11:14 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Jan 28 20:11:14 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Jan 28 20:11:14 volumio systemd[1]: volumio.service: Consumed 59.441s CPU time. Jan 28 20:11:14 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 28 20:11:14 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Jan 28 20:11:14 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 10598. Jan 28 20:11:14 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 28 20:11:14 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Jan 28 20:11:14 volumio systemd[1]: volumio.service: Consumed 59.441s CPU time. Jan 28 20:11:14 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Jan 28 20:11:14 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Jan 28 20:11:14 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 20:11:14 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 20:11:14 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 20:11:15 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Jan 28 20:11:15 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 20:11:15 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 20:11:15 volumio go-librespot[27026]: go-librespot daemon starting... Jan 28 20:11:15 volumio go-librespot[27027]: time="2026-01-28T20:11:15+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 20:11:15 volumio go-librespot[27027]: time="2026-01-28T20:11:15+07:00" level=debug msg="app state loaded" Jan 28 20:11:15 volumio go-librespot[27027]: time="2026-01-28T20:11:15+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 20:11:16 volumio go-librespot[27027]: time="2026-01-28T20:11:16+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 28 20:11:16 volumio go-librespot[27027]: time="2026-01-28T20:11:16+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Jan 28 20:11:16 volumio go-librespot[27027]: time="2026-01-28T20:11:16+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Jan 28 20:11:16 volumio go-librespot[27027]: time="2026-01-28T20:11:16+07:00" level=info msg="zeroconf server listening on port 34795" Jan 28 20:11:16 volumio go-librespot[27027]: time="2026-01-28T20:11:16+07:00" level=debug msg="obtained new client token: AABd/jFaIpB6vuurbGrtvE4CG0GCHrNU+2ZCIrDBOMb9Ahj3mwqZqjbq6G139LTan8wzyYk16UqkRO1BZpuicDhezz3oFOLgMth2C4XxoWzCjbG5CNmpZkrMZTVaQ1JbP3Z+6c0r6rurnzdcShQ5c+21NMsAZuc16GbxDgagg+qMCcZJjGKQFK9WTO6ZXjm0a/CvAxJ3h3DwhLOmT+kXBmIZyMyl3sngNUBOvsqalx8tkSeUBVrUl5ZF260=" Jan 28 20:11:16 volumio go-librespot[27027]: time="2026-01-28T20:11:16+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 20:11:16 volumio go-librespot[27027]: time="2026-01-28T20:11:16+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 28 20:11:16 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 20:11:16 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 20:11:16 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 20:11:16 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 20:11:16 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 20:11:18 volumio volumio[27011]: info: ------------------------------------------- Jan 28 20:11:18 volumio volumio[27011]: info: ----- Volumio3 ---- Jan 28 20:11:18 volumio volumio[27011]: info: ------------------------------------------- Jan 28 20:11:18 volumio volumio[27011]: info: ----- System startup ---- Jan 28 20:11:18 volumio volumio[27011]: info: ------------------------------------------- Jan 28 20:11:18 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 20:11:18 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 20:11:18 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 20:11:19 volumio volumio-remote-updater[628]: [2026-01-28 20:11:19] [connect] Successful connection Jan 28 20:11:19 volumio volumio[27011]: info: MYVOLUMIO Environment detected Jan 28 20:11:19 volumio volumio[27011]: info: Plugin folders cleanup Jan 28 20:11:19 volumio volumio[27011]: info: Scanning into folder /volumio/app/plugins/ Jan 28 20:11:19 volumio volumio[27011]: info: Scanning category audio_interface Jan 28 20:11:19 volumio volumio[27011]: info: Scanning category miscellanea Jan 28 20:11:19 volumio volumio[27011]: info: Scanning category music_service Jan 28 20:11:19 volumio volumio[27011]: info: Scanning category plugins.json Jan 28 20:11:19 volumio volumio[27011]: info: Scanning category system_controller Jan 28 20:11:19 volumio volumio[27011]: info: Scanning category user_interface Jan 28 20:11:19 volumio volumio[27011]: info: Scanning into folder /data/plugins/ Jan 28 20:11:19 volumio volumio[27011]: info: Scanning category music_service Jan 28 20:11:19 volumio volumio[27011]: info: Plugin folders cleanup completed Jan 28 20:11:19 volumio volumio[27011]: info: ------------------------------------------- Jan 28 20:11:19 volumio volumio[27011]: info: ----- Core plugins startup ---- Jan 28 20:11:19 volumio volumio[27011]: info: ------------------------------------------- Jan 28 20:11:19 volumio volumio[27011]: info: Loading plugins from folder /volumio/app/plugins/ Jan 28 20:11:19 volumio volumio[27011]: info: Adding plugin upnp to MyMusic Plugins Jan 28 20:11:19 volumio volumio[27011]: info: Adding plugin airplay_emulation to MyMusic Plugins Jan 28 20:11:19 volumio volumio[27011]: info: Adding plugin upnp_browser to MyMusic Plugins Jan 28 20:11:19 volumio volumio[27011]: info: Loading plugins from folder /data/plugins/ Jan 28 20:11:19 volumio volumio[27011]: info: Loading plugin "system"... Jan 28 20:11:19 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Jan 28 20:11:19 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 20:11:19 volumio volumio[27011]: info: Loading plugin "appearance"... Jan 28 20:11:19 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 20:11:19 volumio go-librespot[27043]: go-librespot daemon starting... Jan 28 20:11:19 volumio go-librespot[27047]: time="2026-01-28T20:11:19+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 20:11:19 volumio go-librespot[27047]: time="2026-01-28T20:11:19+07:00" level=debug msg="app state loaded" Jan 28 20:11:19 volumio go-librespot[27047]: time="2026-01-28T20:11:19+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 20:11:20 volumio go-librespot[27047]: time="2026-01-28T20:11:20+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 28 20:11:20 volumio go-librespot[27047]: time="2026-01-28T20:11:20+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Jan 28 20:11:20 volumio go-librespot[27047]: time="2026-01-28T20:11:20+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Jan 28 20:11:20 volumio go-librespot[27047]: time="2026-01-28T20:11:20+07:00" level=info msg="zeroconf server listening on port 33585" Jan 28 20:11:20 volumio go-librespot[27047]: time="2026-01-28T20:11:20+07:00" level=debug msg="obtained new client token: AACGKYSAO4Y+X3K4M1FqDy9+ygE7wMjTkf8j3IZsX/6h5roQLGNoI5v4daXKksVzRZNwsGKjesyy56VguAmqo+fRWckY91EE/2pL9ibGov1MqtWPx8nsrSdbKUbI8lk5/c413X7YLB3yfEmmdFZVkJ7yhW9kur37sjE7OcXgeMIYFWCnX2SU7m89Uf6JttnVhbjZPSGXsxN+0F5ZADwqIMebJQ874VCOdojkYbONsy6QuhgawM+mhc2B4gA=" Jan 28 20:11:20 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 20:11:20 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 20:11:20 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 20:11:20 volumio go-librespot[27047]: time="2026-01-28T20:11:20+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 20:11:20 volumio go-librespot[27047]: time="2026-01-28T20:11:20+07:00" level=debug msg="completed keyexchange" Jan 28 20:11:20 volumio go-librespot[27047]: time="2026-01-28T20:11:20+07:00" level=debug msg="completed challenge" Jan 28 20:11:20 volumio go-librespot[27047]: time="2026-01-28T20:11:20+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 20:11:20 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 20:11:20 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 20:11:21 volumio volumio[27011]: info: Loading plugin "network"... Jan 28 20:11:21 volumio volumio[27011]: info: Refreshing Cached IP Addresses Jan 28 20:11:21 volumio sudo[27057]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 28 20:11:21 volumio sudo[27057]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 20:11:21 volumio sudo[27059]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 28 20:11:21 volumio sudo[27059]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 20:11:21 volumio volumio[27011]: info: Loading plugin "services"... Jan 28 20:11:21 volumio sudo[27057]: pam_unix(sudo:session): session closed for user root Jan 28 20:11:21 volumio volumio[27011]: info: Loading plugin "alsa_controller"... Jan 28 20:11:21 volumio sudo[27059]: pam_unix(sudo:session): session closed for user root Jan 28 20:11:21 volumio sudo[27067]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Jan 28 20:11:21 volumio sudo[27067]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 20:11:21 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 28 20:11:21 volumio volumio[27011]: info: Loading plugin "wizard"... Jan 28 20:11:21 volumio volumio[27011]: info: Loading plugin "networkfs"... Jan 28 20:11:22 volumio volumio[27011]: info: Starting Udev Watcher for removable devices Jan 28 20:11:22 volumio volumio[27011]: info: Ignoring mount for partition: boot Jan 28 20:11:22 volumio volumio[27011]: info: Ignoring mount for partition: volumio Jan 28 20:11:22 volumio volumio[27011]: info: Ignoring mount for partition: volumio_data Jan 28 20:11:22 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 28 20:11:22 volumio volumio[27011]: info: Loading plugin "volumio_command_line_client"... Jan 28 20:11:22 volumio volumio[27011]: info: Loading plugin "upnp"... Jan 28 20:11:22 volumio volumio[27011]: info: [1769605882123] Starting Upmpd Daemon Jan 28 20:11:22 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 28 20:11:22 volumio volumio[27011]: info: Loading plugin "my_music"... Jan 28 20:11:22 volumio volumio[27011]: info: Loading plugin "mpd"... Jan 28 20:11:22 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 20:11:22 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 20:11:22 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 20:11:22 volumio volumio[27011]: info: Loading plugin "upnp_browser"... Jan 28 20:11:23 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Jan 28 20:11:23 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 20:11:24 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 20:11:24 volumio go-librespot[27091]: go-librespot daemon starting... Jan 28 20:11:24 volumio go-librespot[27092]: time="2026-01-28T20:11:24+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 20:11:24 volumio go-librespot[27092]: time="2026-01-28T20:11:24+07:00" level=debug msg="app state loaded" Jan 28 20:11:24 volumio go-librespot[27092]: time="2026-01-28T20:11:24+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 20:11:24 volumio go-librespot[27092]: time="2026-01-28T20:11: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-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 20:11:24 volumio go-librespot[27092]: time="2026-01-28T20:11:24+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 28 20:11:24 volumio go-librespot[27092]: time="2026-01-28T20:11:24+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 28 20:11:24 volumio go-librespot[27092]: time="2026-01-28T20:11:24+07:00" level=info msg="zeroconf server listening on port 35015" Jan 28 20:11:24 volumio sudo[27067]: pam_unix(sudo:session): session closed for user root Jan 28 20:11:24 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 20:11:24 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 20:11:24 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 20:11:24 volumio go-librespot[27092]: time="2026-01-28T20:11:24+07:00" level=debug msg="obtained new client token: AABiYeVnQkLTynwIbiyNRhNAptF9PVghJkEMjydandMvlfqXw6akmSewrB9kMnaDDEdGHludYGqDYMo6U6rHZFH6w5aokor6MFFQ6Wr4UXNO5NVmfMTDtQ/YFFqWN+goJpI++tYtP7yKCs+Mjngp9rUBo1qbParZJ7gilr3Nd0L4ivirpS4Wchrc7P5PDMMdvoppQ0zEbgrNCNoFbMQNq36HtEgApZsT2hQnSH4eL+U6P2viBjAsgI67Fi0=" Jan 28 20:11:24 volumio go-librespot[27092]: time="2026-01-28T20:11:24+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 20:11:25 volumio go-librespot[27092]: time="2026-01-28T20:11:25+07:00" level=debug msg="completed keyexchange" Jan 28 20:11:25 volumio go-librespot[27092]: time="2026-01-28T20:11:25+07:00" level=debug msg="completed challenge" Jan 28 20:11:25 volumio go-librespot[27092]: time="2026-01-28T20:11:25+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 20:11:25 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 20:11:25 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 20:11:25 volumio volumio[27011]: info: Starting UPNP Browser Jan 28 20:11:25 volumio volumio[27011]: info: Loading plugin "alarm-clock"... Jan 28 20:11:26 volumio volumio[27011]: info: Loading plugin "airplay_emulation"... Jan 28 20:11:26 volumio volumio[27011]: info: Starting Shairport Sync Jan 28 20:11:26 volumio volumio[27011]: info: Loading plugin "last_100"... Jan 28 20:11:26 volumio volumio[27011]: info: Loading plugin "webradio"... Jan 28 20:11:26 volumio volumio[27011]: info: Loading plugin "i2s_dacs"... Jan 28 20:11:26 volumio volumio[27011]: info: Loading plugin "volumiodiscovery"... Jan 28 20:11:26 volumio volumio[27011]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 28 20:11:26 volumio volumio[27011]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 20:11:26 volumio volumio[27011]: *** WARNING *** For more information see Jan 28 20:11:26 volumio volumio[27011]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 28 20:11:26 volumio volumio[27011]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 20:11:26 volumio volumio[27011]: *** WARNING *** For more information see Jan 28 20:11:26 volumio node[27011]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 28 20:11:26 volumio node[27011]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 20:11:26 volumio node[27011]: *** WARNING *** For more information see Jan 28 20:11:26 volumio node[27011]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 28 20:11:26 volumio node[27011]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 20:11:26 volumio node[27011]: *** WARNING *** For more information see Jan 28 20:11:26 volumio volumio[27011]: info: Applying required configuration parameters for plugin volumiodiscovery Jan 28 20:11:26 volumio volumio[27011]: info: Discovery: Started advertising with name: Volumio Jan 28 20:11:26 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 28 20:11:26 volumio volumio[27011]: info: Loading plugin "spop"... Jan 28 20:11:26 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 20:11:26 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 20:11:26 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 20:11:28 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Jan 28 20:11:28 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 20:11:28 volumio volumio[27011]: info: Loading plugin "ytcr"... Jan 28 20:11:28 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 20:11:28 volumio go-librespot[27101]: go-librespot daemon starting... Jan 28 20:11:28 volumio go-librespot[27102]: time="2026-01-28T20:11:28+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 20:11:28 volumio go-librespot[27102]: time="2026-01-28T20:11:28+07:00" level=debug msg="app state loaded" Jan 28 20:11:28 volumio go-librespot[27102]: time="2026-01-28T20:11:28+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 20:11:28 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 20:11:28 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 20:11:28 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 20:11:28 volumio go-librespot[27102]: time="2026-01-28T20:11: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-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 20:11:28 volumio go-librespot[27102]: time="2026-01-28T20:11:28+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 28 20:11:28 volumio go-librespot[27102]: time="2026-01-28T20:11:28+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 28 20:11:28 volumio go-librespot[27102]: time="2026-01-28T20:11:28+07:00" level=info msg="zeroconf server listening on port 42713" Jan 28 20:11:29 volumio go-librespot[27102]: time="2026-01-28T20:11:29+07:00" level=debug msg="obtained new client token: AADj/5tAnQx8N9ZUdx+MZlznRDFDsC9ScoU/Tw0atHguJa0oW71PTeeF/WDm+vXxQicHbPUj193GgXo+zdRLH/tsH07A57j4PZOfrcRLaNctshlW+7n4pJQ4M9QeLRt2gD6nqpTaMXghQMmhO3Y01RnC1prvrZPWSLRJE9Ra2xgxkiy1O2ORDTssBCqgU0hlWWajcW1BxXUE5Vd/3XrGV31RQxBwmJtrr1HS04+2SkHoJxubVOXrLMiX" Jan 28 20:11:29 volumio go-librespot[27102]: time="2026-01-28T20:11:29+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 20:11:29 volumio go-librespot[27102]: time="2026-01-28T20:11:29+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 28 20:11:29 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 20:11:29 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 20:11:30 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 20:11:30 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 20:11:30 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 20:11:31 volumio volumio[27011]: info: Loading plugin "ytmusic"... Jan 28 20:11:31 volumio volumio-remote-updater[628]: [2026-01-28 20:11:31] [connect] Successful connection Jan 28 20:11:32 volumio volumio[27011]: info: Loading plugin "outputs"... Jan 28 20:11:32 volumio volumio[27011]: info: Loading plugin "albumart"... Jan 28 20:11:32 volumio volumio[27011]: info: Plugin example_plugin is not enabled Jan 28 20:11:32 volumio volumio[27011]: info: Loading plugin "inputs"... Jan 28 20:11:32 volumio volumio[27011]: info: Loading plugin "updater_comm"... Jan 28 20:11:32 volumio volumio[27011]: info: Plugin mpdemulation is not enabled Jan 28 20:11:32 volumio volumio[27011]: info: Loading plugin "rest_api"... Jan 28 20:11:32 volumio volumio[27011]: info: Loading plugin "websocket"... Jan 28 20:11:32 volumio volumio[27011]: info: Starting Socket.io Server version 1.7.4 Jan 28 20:11:32 volumio volumio[27011]: info: Loading plugin "RoonBridge"... Jan 28 20:11:32 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Jan 28 20:11:32 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 20:11:32 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 20:11:32 volumio go-librespot[27133]: go-librespot daemon starting... Jan 28 20:11:32 volumio go-librespot[27134]: time="2026-01-28T20:11:32+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 20:11:32 volumio go-librespot[27134]: time="2026-01-28T20:11:32+07:00" level=debug msg="app state loaded" Jan 28 20:11:32 volumio go-librespot[27134]: time="2026-01-28T20:11:32+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 20:11:32 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 20:11:32 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 20:11:32 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 20:11:33 volumio volumio[27011]: info: Applying required configuration parameters for plugin RoonBridge Jan 28 20:11:33 volumio volumio[27011]: info: Loading i18n strings for locale en Jan 28 20:11:33 volumio volumio[27011]: Updating browse sources language Jan 28 20:11:33 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 20:11:33 volumio go-librespot[27134]: time="2026-01-28T20:11:33+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 20:11:33 volumio go-librespot[27134]: time="2026-01-28T20:11:33+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 28 20:11:33 volumio go-librespot[27134]: time="2026-01-28T20:11:33+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 28 20:11:33 volumio go-librespot[27134]: time="2026-01-28T20:11:33+07:00" level=info msg="zeroconf server listening on port 39665" Jan 28 20:11:33 volumio volumio[27123]: Forking 3 albumart workers Jan 28 20:11:33 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 28 20:11:33 volumio volumio[27011]: info: CoreCommandRouter::initPlayerControls Jan 28 20:11:33 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 20:11:33 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 20:11:33 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 20:11:33 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 20:11:33 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 20:11:33 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 20:11:33 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 20:11:33 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 20:11:33 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 28 20:11:33 volumio volumio[27011]: Express server listening on port 3000 Jan 28 20:11:33 volumio volumio[27011]: [Metrics] WebUI: 16s 118.36ms Jan 28 20:11:33 volumio go-librespot[27134]: time="2026-01-28T20:11:33+07:00" level=debug msg="obtained new client token: AADTaqsKl4Y5g//akR31FBp04rmYBci7j0W2/kynySmVjkvyy/1/C0fNp410S2yBsVXlXQLbSr+BR2TCj73tyHafe63ziAsBysI96lTlwXSoe6F1hxyexGOUo3u/ZUPpXHM/L7EVHkNQ+WlN9LNvfUtPnAgnnjNaD3qn15jq4pcRWvAftAiSc5lgl+bh4SwzjqewmRElc6zhntShSfN3FstYBcQ07bvBKyT3ACp8g2AM3w5W0nj6Z4ot5aA=" Jan 28 20:11:33 volumio volumio[27011]: info: CoreStateMachine::resetVolumioState Jan 28 20:11:33 volumio volumio[27011]: info: CoreStateMachine::getcurrentVolume Jan 28 20:11:33 volumio volumio[27011]: info: CoreCommandRouter::volumioRetrievevolume Jan 28 20:11:33 volumio go-librespot[27134]: time="2026-01-28T20:11:33+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 20:11:33 volumio sudo[27173]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 28 20:11:33 volumio sudo[27173]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 20:11:33 volumio sudo[27173]: pam_unix(sudo:session): session closed for user root Jan 28 20:11:33 volumio sudo[27175]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 28 20:11:33 volumio sudo[27175]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 20:11:33 volumio sudo[27175]: pam_unix(sudo:session): session closed for user root Jan 28 20:11:33 volumio go-librespot[27134]: time="2026-01-28T20:11:33+07:00" level=debug msg="completed keyexchange" Jan 28 20:11:33 volumio go-librespot[27134]: time="2026-01-28T20:11:33+07:00" level=debug msg="completed challenge" Jan 28 20:11:33 volumio volumio[27011]: info: Volumio Network Manager: Network status updated: 1 Jan 28 20:11:33 volumio go-librespot[27134]: time="2026-01-28T20:11:33+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 20:11:33 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 20:11:33 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 20:11:34 volumio volumio-remote-updater[628]: [2026-01-28 20:11:34] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1769605891 101 Jan 28 20:11:34 volumio volumio[27011]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 1 Jan 28 20:11:34 volumio volumio[27011]: info: VolumeController:: Volume=100 Mute =false Jan 28 20:11:34 volumio volumio[27011]: info: CoreStateMachine::pushState Jan 28 20:11:34 volumio volumio[27011]: info: CorePlayQueue::getTrack 0 Jan 28 20:11:34 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 28 20:11:34 volumio volumio[27011]: info: CoreCommandRouter::volumioPushState Jan 28 20:11:34 volumio volumio[27011]: info: CoreStateMachine::updateTrackBlock Jan 28 20:11:34 volumio volumio[27011]: info: CorePlayQueue::getTrackBlock Jan 28 20:11:34 volumio volumio[27011]: info: CoreCommandRouter::volumioRetrievevolume Jan 28 20:11:34 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 20:11:34 volumio volumio[27011]: info: Reloading queue from file Jan 28 20:11:34 volumio volumio[27011]: info: CoreStateMachine::setRepeat null single undefined Jan 28 20:11:34 volumio volumio[27011]: info: CoreStateMachine::pushState Jan 28 20:11:34 volumio volumio[27011]: info: CorePlayQueue::getTrack 0 Jan 28 20:11:34 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 28 20:11:34 volumio volumio[27011]: info: CoreCommandRouter::volumioPushState Jan 28 20:11:34 volumio volumio[27011]: info: CoreStateMachine::setRandom null Jan 28 20:11:34 volumio volumio[27011]: info: CoreStateMachine::pushState Jan 28 20:11:34 volumio volumio[27011]: info: CorePlayQueue::getTrack 0 Jan 28 20:11:34 volumio volumio[27011]: info: CoreCommandRouter::volumioPushState Jan 28 20:11:34 volumio volumio[27011]: info: Setting Device type: Raspberry PI Jan 28 20:11:34 volumio volumio[27011]: info: Completed loading Core Plugins Jan 28 20:11:34 volumio volumio[27011]: info: Preparing to generate the ALSA configuration file Jan 28 20:11:34 volumio volumio[27011]: info: VolumeController:: Volume=100 Mute =false Jan 28 20:11:34 volumio volumio[27011]: info: CoreStateMachine::pushState Jan 28 20:11:34 volumio volumio[27011]: info: CorePlayQueue::getTrack 0 Jan 28 20:11:34 volumio volumio[27011]: info: CoreCommandRouter::volumioPushState Jan 28 20:11:34 volumio volumio[27011]: info: Asound.conf file unchanged, so no further update is needed Jan 28 20:11:34 volumio volumio[27011]: info: Output device has changed, restarting MPD Jan 28 20:11:34 volumio volumio[27011]: info: Output device has changed, restarting Shairport Sync Jan 28 20:11:34 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 20:11:34 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 20:11:34 volumio sudo[27191]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Jan 28 20:11:34 volumio sudo[27191]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 20:11:34 volumio sudo[27193]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 28 20:11:34 volumio sudo[27193]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 20:11:34 volumio sudo[27195]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 28 20:11:34 volumio volumio[27011]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 28 20:11:34 volumio volumio[27011]: info: ___________ START PLUGINS ___________ Jan 28 20:11:34 volumio sudo[27195]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 20:11:34 volumio sudo[27193]: pam_unix(sudo:session): session closed for user root Jan 28 20:11:34 volumio volumio[27011]: info: ControllerMpd::onStart: Initializing MPD Jan 28 20:11:34 volumio volumio[27011]: info: Creating MPD Configuration file Jan 28 20:11:34 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 20:11:34 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 20:11:34 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 20:11:34 volumio sudo[27191]: pam_unix(sudo:session): session closed for user root Jan 28 20:11:34 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 28 20:11:34 volumio volumio[27011]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 20:11:34 volumio volumio[27011]: info: [1769605894800] CoreMusicLibrary::Adding element Media Servers Jan 28 20:11:34 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 20:11:34 volumio sudo[27204]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 28 20:11:34 volumio sudo[27204]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 20:11:34 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Jan 28 20:11:34 volumio sudo[27204]: pam_unix(sudo:session): session closed for user root Jan 28 20:11:34 volumio volumio[27011]: info: UPNP Browser: Client initialized successfully Jan 28 20:11:34 volumio sudo[27206]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 28 20:11:34 volumio sudo[27206]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 20:11:34 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 20:11:34 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 20:11:34 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 28 20:11:34 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 28 20:11:34 volumio systemd[1]: mpd.service: Consumed 7.287s CPU time. Jan 28 20:11:34 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 28 20:11:34 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 28 20:11:34 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 28 20:11:34 volumio volumio[27011]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 28 20:11:34 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 20:11:34 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 20:11:35 volumio volumio[27011]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 28 20:11:35 volumio volumio[27011]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 20:11:35 volumio volumio[27011]: info: [1769605895056] CoreMusicLibrary::Adding element Last_100 Jan 28 20:11:35 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 28 20:11:35 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 20:11:35 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 28 20:11:35 volumio volumio[27011]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 20:11:35 volumio volumio[27011]: info: [1769605895094] CoreMusicLibrary::Adding element Webradio Jan 28 20:11:35 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 20:11:35 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 28 20:11:35 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 28 20:11:35 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 28 20:11:35 volumio volumio[27011]: info: Initializing BBC Radios Jan 28 20:11:35 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 28 20:11:35 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 28 20:11:35 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 28 20:11:35 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 28 20:11:35 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 28 20:11:35 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 28 20:11:35 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 20:11:35 volumio volumio[27011]: info: Creating Spotify config file Jan 28 20:11:35 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 20:11:35 volumio sudo[27230]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 28 20:11:35 volumio sudo[27230]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jan 28 20:11:35 volumio sudo[27230]: pam_unix(sudo:session): session closed for user root Jan 28 20:11:36 volumio volumio[27011]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 20:11:36 volumio volumio[27011]: info: [1769605896384] CoreMusicLibrary::Adding element YouTube Music Jan 28 20:11:36 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 20:11:36 volumio volumio[27011]: Cannot find translation for source YouTube Music Jan 28 20:11:36 volumio volumio[27011]: info: Volumio Calling Home Jan 28 20:11:36 volumio volumio[27141]: Starting albumart workers Jan 28 20:11:36 volumio sudo[27237]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Jan 28 20:11:36 volumio sudo[27237]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 20:11:36 volumio sudo[27237]: pam_unix(sudo:session): session closed for user root Jan 28 20:11:36 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 20:11:36 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 20:11:36 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 20:11:36 volumio volumio[27143]: Starting albumart workers Jan 28 20:11:36 volumio volumio[27142]: Starting albumart workers Jan 28 20:11:36 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Jan 28 20:11:37 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 20:11:37 volumio go-librespot[27242]: go-librespot daemon starting... Jan 28 20:11:37 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 20:11:37 volumio go-librespot[27243]: time="2026-01-28T20:11:37+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 20:11:37 volumio volumio[27011]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Jan 28 20:11:37 volumio volumio[27011]: info: Discovery: Found device Volumio Jan 28 20:11:37 volumio volumio[27011]: info: CoreCommandRouter::volumioGetState Jan 28 20:11:37 volumio volumio[27011]: info: CorePlayQueue::getTrack 0 Jan 28 20:11:37 volumio volumio[27011]: info: MPD Permissions set Jan 28 20:11:37 volumio volumio[27011]: info: MPD Permissions set Jan 28 20:11:37 volumio volumio[27011]: info: Upmpdcli Daemon Started Jan 28 20:11:37 volumio volumio[27011]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Jan 28 20:11:37 volumio volumio[27011]: info: Discovery: Found device Volumio Jan 28 20:11:37 volumio volumio[27011]: info: CoreCommandRouter::volumioGetState Jan 28 20:11:37 volumio volumio[27011]: info: CorePlayQueue::getTrack 0 Jan 28 20:11:37 volumio volumio[27011]: info: Volumio called home Jan 28 20:11:37 volumio volumio[27011]: info: Spotify config file written Jan 28 20:11:37 volumio sudo[27251]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jan 28 20:11:37 volumio sudo[27251]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 20:11:37 volumio go-librespot[27243]: time="2026-01-28T20:11:37+07:00" level=info msg="zeroconf server listening on port 35691" Jan 28 20:11:38 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Jan 28 20:11:38 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Jan 28 20:11:38 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 20:11:38 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 20:11:38 volumio go-librespot[27253]: go-librespot daemon starting... Jan 28 20:11:38 volumio sudo[27251]: pam_unix(sudo:session): session closed for user root Jan 28 20:11:38 volumio go-librespot[27254]: time="2026-01-28T20:11:38+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 20:11:38 volumio go-librespot[27254]: time="2026-01-28T20:11:38+07:00" level=debug msg="app state loaded" Jan 28 20:11:38 volumio go-librespot[27254]: time="2026-01-28T20:11:38+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 20:11:38 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 20:11:38 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 20:11:38 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 20:11:38 volumio volumio[27011]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Jan 28 20:11:38 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 20:11:38 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 20:11:38 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 20:11:38 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 20:11:38 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 20:11:38 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 20:11:38 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 20:11:38 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 20:11:38 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 20:11:38 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 20:11:38 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 20:11:38 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 20:11:38 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 20:11:38 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 20:11:38 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 20:11:38 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 20:11:38 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 20:11:38 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 20:11:39 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 20:11:39 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 20:11:39 volumio volumio[27011]: info: No need to fix Spotify hosts Jan 28 20:11:39 volumio go-librespot[27254]: time="2026-01-28T20:11: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-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 20:11:39 volumio go-librespot[27254]: time="2026-01-28T20:11:39+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 28 20:11:39 volumio go-librespot[27254]: time="2026-01-28T20:11:39+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 28 20:11:39 volumio go-librespot[27254]: time="2026-01-28T20:11:39+07:00" level=info msg="zeroconf server listening on port 37325" Jan 28 20:11:39 volumio go-librespot[27254]: time="2026-01-28T20:11:39+07:00" level=debug msg="obtained new client token: AAAIlpwJV6DZnhJ0g+thJvzcv4hcVEH1gBbyjJFdDDUKGj340enzFpQY4QLiy+be1KrhzhRdSk8NIr+4uPbqcWki0sun6RJs4zyZG3Di7TdVzBhe89zGA5s51I7e+kRpwAc9vDSQNDBzlGJy9QpU5rnhMfmU8UjNn6ma8vOpooxhUDGN6q9NQIUYy0c+nEGanHdCqv09KmiuAFBZEdeY6JaMEgYGi4o6vLtJ1F5VcHz8OECQRrhU+4nwi40=" Jan 28 20:11:39 volumio go-librespot[27254]: time="2026-01-28T20:11:39+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 20:11:39 volumio volumio[27011]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 28 20:11:39 volumio volumio[27011]: SPOTIFY: BQB-8W27dpLDilGAtraGPFeEHXksDR2lJjbrbhdDg1DA-NVS33bG_Oj4b1un1w8f5AQ3yb5-rFBALO4Vs_B5r4bjumEWHe75hUPAzFnqi83nB4dbkc-M1LqpVy-Wb8F1XwrMUKlCreeQVPY-IVQivW4jpduM7RJzFgvs2thYol-LFF767oGyf3evxvzV04A0vwoZCwD3L-v-XtppwA2cw-XTkgJAdnc3jEEcIpdZI60tio9x1HI2fBaNHP3cZogGdfkn5S_WiueQFtKI2MAdCAzaddXQVjitbssiCPWM9UIV0TepDwsFqpAA Jan 28 20:11:39 volumio volumio[27011]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 28 20:11:39 volumio volumio[27011]: info: New Spotify access token = BQB-8W27dpLDilGAtraGPFeEHXksDR2lJjbrbhdDg1DA-NVS33bG_Oj4b1un1w8f5AQ3yb5-rFBALO4Vs_B5r4bjumEWHe75hUPAzFnqi83nB4dbkc-M1LqpVy-Wb8F1XwrMUKlCreeQVPY-IVQivW4jpduM7RJzFgvs2thYol-LFF767oGyf3evxvzV04A0vwoZCwD3L-v-XtppwA2cw-XTkgJAdnc3jEEcIpdZI60tio9x1HI2fBaNHP3cZogGdfkn5S_WiueQFtKI2MAdCAzaddXQVjitbssiCPWM9UIV0TepDwsFqpAA Jan 28 20:11:39 volumio volumio[27011]: info: Spotify credentials grant success - running version from March 24, 2019 Jan 28 20:11:39 volumio go-librespot[27254]: time="2026-01-28T20:11:39+07:00" level=debug msg="completed keyexchange" Jan 28 20:11:39 volumio go-librespot[27254]: time="2026-01-28T20:11:39+07:00" level=debug msg="completed challenge" Jan 28 20:11:39 volumio volumio[27011]: info: Starting Shairport Sync Jan 28 20:11:39 volumio volumio[27011]: info: Starting Shairport Sync Jan 28 20:11:39 volumio volumio[27011]: info: Starting Shairport Sync Jan 28 20:11:39 volumio go-librespot[27254]: time="2026-01-28T20:11:39+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 20:11:39 volumio sudo[27294]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 28 20:11:39 volumio sudo[27294]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 20:11:39 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 20:11:39 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 20:11:39 volumio sudo[27296]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 28 20:11:39 volumio sudo[27296]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 20:11:39 volumio sudo[27299]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 28 20:11:39 volumio sudo[27299]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 20:11:39 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 28 20:11:39 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Jan 28 20:11:39 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 28 20:11:39 volumio systemd[1]: shairport-sync.service: Consumed 2.367s CPU time. Jan 28 20:11:40 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 28 20:11:40 volumio sudo[27296]: pam_unix(sudo:session): session closed for user root Jan 28 20:11:40 volumio sudo[27299]: pam_unix(sudo:session): session closed for user root Jan 28 20:11:40 volumio sudo[27294]: pam_unix(sudo:session): session closed for user root Jan 28 20:11:40 volumio volumio[27011]: info: CoreCommandRouter::volumioGetState Jan 28 20:11:40 volumio volumio[27011]: info: CorePlayQueue::getTrack 0 Jan 28 20:11:40 volumio volumio[27011]: info: Shairport-Sync Started Jan 28 20:11:40 volumio volumio[27011]: Error adding Membership: Error: addMembership EINVAL Jan 28 20:11:40 volumio volumio[27011]: info: Shairport-Sync Started Jan 28 20:11:40 volumio volumio[27011]: info: Shairport-Sync Started Jan 28 20:11:40 volumio volumio[27011]: SPOTIFY: User informations: {"country":"PK","display_name":"215mmgea6kss3jxeqsqdquvji","email":"linh.ngotran@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/215mmgea6kss3jxeqsqdquvji"},"followers":{"href":null,"total":1},"href":"https://api.spotify.com/v1/users/215mmgea6kss3jxeqsqdquvji","id":"215mmgea6kss3jxeqsqdquvji","images":[],"product":"premium","type":"user","uri":"spotify:user:215mmgea6kss3jxeqsqdquvji"} Jan 28 20:11:40 volumio volumio[27011]: info: Spotify Successfully logged in Jan 28 20:11:40 volumio volumio[27011]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 20:11:40 volumio volumio[27011]: info: [1769605900463] CoreMusicLibrary::Adding element Spotify Jan 28 20:11:40 volumio volumio[27011]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 20:11:40 volumio volumio[27011]: Cannot find translation for source YouTube Music Jan 28 20:11:40 volumio volumio[27011]: Cannot find translation for source Spotify Jan 28 20:11:40 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 20:11:40 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 20:11:40 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 20:11:41 volumio volumio[27011]: info: [yt-cast-receiver] DIAL server listening on port 8098 Jan 28 20:11:41 volumio volumio[27011]: info: CoreCommandRouter::volumioRetrievevolume Jan 28 20:11:41 volumio volumio[27011]: info: VolumeController:: Volume=100 Mute =false Jan 28 20:11:41 volumio volumio[27011]: info: CoreCommandRouter::volumioGetState Jan 28 20:11:41 volumio volumio[27011]: info: CorePlayQueue::getTrack 0 Jan 28 20:11:41 volumio volumio[27011]: info: CoreStateMachine::pushState Jan 28 20:11:41 volumio volumio[27011]: info: CorePlayQueue::getTrack 0 Jan 28 20:11:41 volumio volumio[27011]: info: CoreCommandRouter::volumioPushState Jan 28 20:11:42 volumio volumio[27011]: info: go-librespot daemon successfully initialized Jan 28 20:11:42 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 20:11:42 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 20:11:42 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 20:11:42 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Jan 28 20:11:42 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 20:11:43 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 20:11:43 volumio go-librespot[27334]: go-librespot daemon starting... Jan 28 20:11:43 volumio mpd[27235]: 2026-01-28T20:11:43 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 28 20:11:43 volumio go-librespot[27335]: time="2026-01-28T20:11:43+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 20:11:43 volumio go-librespot[27335]: time="2026-01-28T20:11:43+07:00" level=debug msg="app state loaded" Jan 28 20:11:43 volumio systemd[1]: Started mpd.service - Music Player Daemon. Jan 28 20:11:43 volumio go-librespot[27335]: time="2026-01-28T20:11:43+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 20:11:43 volumio sudo[27195]: pam_unix(sudo:session): session closed for user root Jan 28 20:11:43 volumio sudo[27206]: pam_unix(sudo:session): session closed for user root Jan 28 20:11:43 volumio volumio[27011]: error: MPD error: The expression evaluated to a falsy value: Jan 28 20:11:43 volumio volumio[27011]: assert.ok(self.idling) Jan 28 20:11:43 volumio volumio[27011]: error: The expression evaluated to a falsy value: Jan 28 20:11:43 volumio volumio[27011]: assert.ok(self.idling) Jan 28 20:11:43 volumio volumio[27011]: error: updateQueue error: null Jan 28 20:11:43 volumio volumio[27011]: info: MPD running with PID27235 Jan 28 20:11:43 volumio volumio[27011]: ,establishing connection Jan 28 20:11:43 volumio volumio[27011]: info: Completed starting Core Plugins Jan 28 20:11:43 volumio volumio[27011]: info: ------------------------------------------- Jan 28 20:11:43 volumio volumio[27011]: info: ----- MyVolumio plugins startup ---- Jan 28 20:11:43 volumio volumio[27011]: info: ------------------------------------------- Jan 28 20:11:43 volumio volumio[27011]: info: [MyVolumio PluginManager] Fetching plans data.... Jan 28 20:11:43 volumio volumio[27011]: error: updateQueue error: null Jan 28 20:11:43 volumio go-librespot[27335]: time="2026-01-28T20:11: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 28 20:11:43 volumio go-librespot[27335]: time="2026-01-28T20:11: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 28 20:11:43 volumio go-librespot[27335]: time="2026-01-28T20:11: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 28 20:11:43 volumio go-librespot[27335]: time="2026-01-28T20:11:43+07:00" level=info msg="zeroconf server listening on port 36653" Jan 28 20:11:43 volumio go-librespot[27335]: time="2026-01-28T20:11:43+07:00" level=debug msg="obtained new client token: AAC057+mxOePOLzfWuFG9EqHggstaMWxiVUbkx48a5kITf7AubLoYx+110pwKbidld+NPpXkjSzfBjjTClS8WVDQekC739V4Nr2bI+ntiA0RQT4jPJn7lDr0Lbo6EMGxOFe5XHiWdVub29sGZqAF0qJ7rrgy4ReN/iWt0BUHu0WDSX/aNRSTPn4x+OHqe9Gz9p/krdXX71JerP23IqQoUApNr2p9IM5hMqC+JRYUaXh5FhiWa9v3mEHSjwc=" Jan 28 20:11:44 volumio go-librespot[27335]: time="2026-01-28T20:11:44+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 20:11:44 volumio go-librespot[27335]: time="2026-01-28T20:11:44+07:00" level=debug msg="completed keyexchange" Jan 28 20:11:44 volumio go-librespot[27335]: time="2026-01-28T20:11:44+07:00" level=debug msg="completed challenge" Jan 28 20:11:44 volumio go-librespot[27335]: time="2026-01-28T20:11: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 28 20:11:44 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 20:11:44 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 20:11:44 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 20:11:44 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 20:11:44 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 20:11:45 volumio volumio[27011]: info: Initializing connection to go-librespot Websocket Jan 28 20:11:45 volumio volumio[27011]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 28 20:11:46 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 20:11:46 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 20:11:46 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 20:11:47 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Jan 28 20:11:47 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 20:11:47 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 20:11:47 volumio go-librespot[27347]: go-librespot daemon starting... Jan 28 20:11:47 volumio go-librespot[27348]: time="2026-01-28T20:11:47+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 20:11:47 volumio go-librespot[27348]: time="2026-01-28T20:11:47+07:00" level=debug msg="app state loaded" Jan 28 20:11:47 volumio go-librespot[27348]: time="2026-01-28T20:11:47+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 20:11:48 volumio go-librespot[27348]: time="2026-01-28T20:11: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-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 20:11:48 volumio go-librespot[27348]: time="2026-01-28T20:11:48+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 28 20:11:48 volumio go-librespot[27348]: time="2026-01-28T20:11:48+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 28 20:11:48 volumio go-librespot[27348]: time="2026-01-28T20:11:48+07:00" level=info msg="zeroconf server listening on port 37993" Jan 28 20:11:48 volumio volumio[27011]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Jan 28 20:11:48 volumio go-librespot[27348]: time="2026-01-28T20:11:48+07:00" level=debug msg="obtained new client token: AACMLCe6ZaRjfZvjxmLoaetjDp8eX1KCZLMWHi+UKSwE6QUFOnRDFyMhsk/yK9Y7JjI8JktJ4hAXI0oTBm/1qAJjsXmzLNkxW4e6jmOP9XBceeAlgZdYK6UTomqH3c0snBbM7dEFlkhKRpmniQCJy9CGJddRS3HF9t/sEkaPUka22JbqNlR1GvCGQzoAoLELPYqOrxBMli5UM9G3FYV1DDu0B6Gw+/1X+H/pNuADEh1sKAfVWnu30fIk" Jan 28 20:11:48 volumio go-librespot[27348]: time="2026-01-28T20:11:48+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 20:11:48 volumio go-librespot[27348]: time="2026-01-28T20:11:48+07:00" level=debug msg="completed keyexchange" Jan 28 20:11:48 volumio go-librespot[27348]: time="2026-01-28T20:11:48+07:00" level=debug msg="completed challenge" Jan 28 20:11:48 volumio volumio[27011]: info: Initializing connection to go-librespot Websocket Jan 28 20:11:48 volumio go-librespot[27348]: time="2026-01-28T20:11:48+07:00" level=debug msg="new websocket client" Jan 28 20:11:48 volumio volumio[27011]: info: Connection to go-librespot Websocket established Jan 28 20:11:48 volumio go-librespot[27348]: time="2026-01-28T20:11: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 28 20:11:48 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 20:11:48 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 20:11:48 volumio volumio[27011]: info: Connection to go-librespot Websocket closed Jan 28 20:11:48 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 20:11:48 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 20:11:48 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 20:11:50 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 20:11:50 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 20:11:50 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 20:11:51 volumio volumio[27011]: info: Getting Spotify volume Jan 28 20:11:51 volumio volumio[27011]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 28 20:11:51 volumio volumio[27011]: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 28 20:11:51 volumio volumio[27011]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Jan 28 20:11:51 volumio volumio[27011]: errno: -111, Jan 28 20:11:51 volumio volumio[27011]: code: 'ECONNREFUSED', Jan 28 20:11:51 volumio volumio[27011]: syscall: 'connect', Jan 28 20:11:51 volumio volumio[27011]: address: '127.0.0.1', Jan 28 20:11:51 volumio volumio[27011]: port: 9879, Jan 28 20:11:51 volumio volumio[27011]: response: undefined Jan 28 20:11:51 volumio volumio[27011]: } Jan 28 20:11:51 volumio volumio[27011]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 28 20:11:51 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Jan 28 20:11:51 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 20:11:51 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 20:11:51 volumio go-librespot[27358]: go-librespot daemon starting... Jan 28 20:11:51 volumio go-librespot[27367]: time="2026-01-28T20:11:51+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 20:11:51 volumio go-librespot[27367]: time="2026-01-28T20:11:51+07:00" level=debug msg="app state loaded" Jan 28 20:11:51 volumio go-librespot[27367]: time="2026-01-28T20:11:51+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 20:11:52 volumio go-librespot[27367]: time="2026-01-28T20:11:52+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 20:11:52 volumio go-librespot[27367]: time="2026-01-28T20:11:52+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 28 20:11:52 volumio go-librespot[27367]: time="2026-01-28T20:11:52+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 28 20:11:52 volumio go-librespot[27367]: time="2026-01-28T20:11:52+07:00" level=info msg="zeroconf server listening on port 34927" Jan 28 20:11:52 volumio go-librespot[27367]: time="2026-01-28T20:11:52+07:00" level=debug msg="obtained new client token: AABqFIO8iKpPeLPqwVZzwW9T4BTmtohA7m/ujVRlISQ9LJQhy2326BWn3SJAo1LknINCKw1eg4Fz+fznf13xH+ZvLBYmBGDJDrwdn0SuozfaJkNW+zVYQzb+/MdUux4PWFM9uvsDKLJwVuiGPL59S6Sp71fnTrcKVTdHZ7A12taxuyKzjCV7ZGpmo54WDTHkbldnJjXilxtJ/cMUzbd6/d4o9Nc5IGBV07RtKRqqiYyAhKqcqndsnyaKHcA=" Jan 28 20:11:52 volumio go-librespot[27367]: time="2026-01-28T20:11:52+07:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:4070, retrying with a different AP" error="dial tcp 104.199.241.202:4070: connect: connection refused" Jan 28 20:11:52 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 20:11:52 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 20:11:52 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 20:11:52 volumio go-librespot[27367]: time="2026-01-28T20:11:52+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Jan 28 20:11:52 volumio go-librespot[27367]: time="2026-01-28T20:11:52+07:00" level=debug msg="completed keyexchange" Jan 28 20:11:52 volumio go-librespot[27367]: time="2026-01-28T20:11:52+07:00" level=debug msg="completed challenge" Jan 28 20:11:53 volumio go-librespot[27367]: time="2026-01-28T20:11:53+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 20:11:53 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 20:11:53 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 20:11:53 volumio sudo[27391]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-01-28 20:10' Jan 28 20:11:53 volumio sudo[27391]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) PRETTY_NAME="Raspbian GNU/Linux 12 (bookworm)" NAME="Raspbian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="b05a530ca81d05eb9a84d0acf82089f0a60b8ee6" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="4ad85e2147d972f0b838d33c21382d2d813b2ae8" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu Dec 25 09:13:19 UTC 2025" VOLUMIO_VERSION="4.084" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="792f09af7488531aecd1aadcaa9b175e"