Jan 28 07:45:00 volumio go-librespot[32223]: time="2026-01-28T07:45:00+07:00" level=debug msg="obtained new client token: AACTrCjEfcJmtBQbHvuZrjyDcmX9pg8g5icrMDVynRD8hriSPmF370zusfiudawXksH4NhBDP0fmAJza3dNWkBfesnQT+3b/p5Btv+wruCZd+fWY9tfmzh0+YprRQqQmIk3GUWcsfMDD8yVyxhbtogtGeeCWvzcDbXbIkvrP7mH5I1NA26r0CZhO8evQLIdrVc0EDLTE3I8kvTXx8GjbRyeelshOqYjU3Xl8DL3Z7G2L9k76kTzmggpa" Jan 28 07:45:00 volumio go-librespot[32223]: time="2026-01-28T07:45:00+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 07:45:00 volumio go-librespot[32223]: time="2026-01-28T07:45:00+07:00" level=debug msg="completed keyexchange" Jan 28 07:45:00 volumio go-librespot[32223]: time="2026-01-28T07:45:00+07:00" level=debug msg="completed challenge" Jan 28 07:45:00 volumio go-librespot[32223]: time="2026-01-28T07:45:00+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 07:45:00 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 07:45:00 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 07:45:01 volumio volumio[32144]: info: Loading plugin "ytcr"... Jan 28 07:45:01 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 07:45:01 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 07:45:01 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 07:45:03 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 07:45:03 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 07:45:03 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 07:45:03 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 17. Jan 28 07:45:03 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 07:45:03 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 07:45:03 volumio go-librespot[32233]: go-librespot daemon starting... Jan 28 07:45:03 volumio go-librespot[32234]: time="2026-01-28T07:45:03+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 07:45:03 volumio go-librespot[32234]: time="2026-01-28T07:45:03+07:00" level=debug msg="app state loaded" Jan 28 07:45:03 volumio go-librespot[32234]: time="2026-01-28T07:45:03+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 07:45:03 volumio volumio[32144]: info: Loading plugin "ytmusic"... Jan 28 07:45:04 volumio go-librespot[32234]: time="2026-01-28T07:45:04+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 07:45:04 volumio go-librespot[32234]: time="2026-01-28T07:45:04+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 07:45:04 volumio go-librespot[32234]: time="2026-01-28T07:45:04+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 07:45:04 volumio go-librespot[32234]: time="2026-01-28T07:45:04+07:00" level=info msg="zeroconf server listening on port 43871" Jan 28 07:45:04 volumio volumio-remote-updater[628]: [2026-01-28 07:45:04] [connect] Successful connection Jan 28 07:45:04 volumio go-librespot[32234]: time="2026-01-28T07:45:04+07:00" level=debug msg="obtained new client token: AACH+PwH6ZrUEA14n1cvP8MHcHybMPgfjd6j1pdLcJ/driZM9D/s/3uDEgyPmg0P+ZxTlKftfvsIYgnc166pQJQTfqQWgrpnHB7msC6U+l3ur27bw3Sy4bHoi5WHoI/W7VRiH+/7OhtUcVz9/qun7uPqltRQXweVFi75K6fksaHJcCYNhhmoCR1i72uE/kdHGRF3n1+eIHdAQAAqWidsl/AHbl9L/TysD0Ryk8iQVS/Kj53WogV1EcYlov8=" Jan 28 07:45:04 volumio go-librespot[32234]: time="2026-01-28T07:45:04+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 07:45:04 volumio go-librespot[32234]: time="2026-01-28T07:45:04+07:00" level=debug msg="completed keyexchange" Jan 28 07:45:04 volumio go-librespot[32234]: time="2026-01-28T07:45:04+07:00" level=debug msg="completed challenge" Jan 28 07:45:05 volumio volumio[32144]: info: Loading plugin "outputs"... Jan 28 07:45:05 volumio go-librespot[32234]: time="2026-01-28T07:45:05+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 07:45:05 volumio volumio[32144]: info: Loading plugin "albumart"... Jan 28 07:45:05 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 07:45:05 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 07:45:05 volumio volumio[32144]: info: Plugin example_plugin is not enabled Jan 28 07:45:05 volumio volumio[32144]: info: Loading plugin "inputs"... Jan 28 07:45:05 volumio volumio[32144]: info: Loading plugin "updater_comm"... Jan 28 07:45:05 volumio volumio[32144]: info: Plugin mpdemulation is not enabled Jan 28 07:45:05 volumio volumio[32144]: info: Loading plugin "rest_api"... Jan 28 07:45:05 volumio volumio[32144]: info: Loading plugin "websocket"... Jan 28 07:45:05 volumio volumio[32144]: info: Starting Socket.io Server version 1.7.4 Jan 28 07:45:05 volumio volumio[32144]: info: Loading plugin "RoonBridge"... Jan 28 07:45:05 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 07:45:05 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 07:45:05 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 07:45:05 volumio volumio[32144]: info: Applying required configuration parameters for plugin RoonBridge Jan 28 07:45:05 volumio volumio[32144]: info: Loading i18n strings for locale en Jan 28 07:45:05 volumio volumio[32144]: Updating browse sources language Jan 28 07:45:05 volumio volumio[32144]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 07:45:06 volumio volumio[32256]: Forking 3 albumart workers Jan 28 07:45:06 volumio volumio[32144]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 28 07:45:06 volumio volumio[32144]: info: CoreCommandRouter::initPlayerControls Jan 28 07:45:06 volumio volumio[32144]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 07:45:06 volumio volumio[32144]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 07:45:06 volumio volumio[32144]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 07:45:06 volumio volumio[32144]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 07:45:06 volumio volumio[32144]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 07:45:06 volumio volumio[32144]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 07:45:06 volumio volumio[32144]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 07:45:06 volumio volumio[32144]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 07:45:06 volumio volumio[32144]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 28 07:45:06 volumio volumio[32144]: Express server listening on port 3000 Jan 28 07:45:06 volumio volumio[32144]: [Metrics] WebUI: 16s 233.03ms Jan 28 07:45:06 volumio volumio[32144]: info: CoreStateMachine::resetVolumioState Jan 28 07:45:06 volumio volumio[32144]: info: CoreStateMachine::getcurrentVolume Jan 28 07:45:06 volumio volumio[32144]: info: CoreCommandRouter::volumioRetrievevolume Jan 28 07:45:06 volumio sudo[32298]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 28 07:45:06 volumio sudo[32298]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 07:45:06 volumio sudo[32298]: pam_unix(sudo:session): session closed for user root Jan 28 07:45:06 volumio sudo[32300]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 28 07:45:06 volumio sudo[32300]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 07:45:06 volumio sudo[32300]: pam_unix(sudo:session): session closed for user root Jan 28 07:45:06 volumio volumio[32144]: info: Volumio Network Manager: Network status updated: 1 Jan 28 07:45:06 volumio volumio-remote-updater[628]: [2026-01-28 07:45:06] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1769561104 101 Jan 28 07:45:06 volumio volumio[32144]: 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 07:45:06 volumio volumio[32144]: info: VolumeController:: Volume=100 Mute =false Jan 28 07:45:06 volumio volumio[32144]: info: CoreStateMachine::pushState Jan 28 07:45:06 volumio volumio[32144]: info: CorePlayQueue::getTrack 0 Jan 28 07:45:06 volumio volumio[32144]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 28 07:45:06 volumio volumio[32144]: info: CoreCommandRouter::volumioPushState Jan 28 07:45:06 volumio volumio[32144]: info: CoreStateMachine::updateTrackBlock Jan 28 07:45:06 volumio volumio[32144]: info: CorePlayQueue::getTrackBlock Jan 28 07:45:06 volumio volumio[32144]: info: CoreCommandRouter::volumioRetrievevolume Jan 28 07:45:07 volumio volumio[32144]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 07:45:07 volumio volumio[32144]: info: Reloading queue from file Jan 28 07:45:07 volumio volumio[32144]: info: CoreStateMachine::setRepeat null single undefined Jan 28 07:45:07 volumio volumio[32144]: info: CoreStateMachine::pushState Jan 28 07:45:07 volumio volumio[32144]: info: CorePlayQueue::getTrack 0 Jan 28 07:45:07 volumio volumio[32144]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 28 07:45:07 volumio volumio[32144]: info: CoreCommandRouter::volumioPushState Jan 28 07:45:07 volumio volumio[32144]: info: CoreStateMachine::setRandom null Jan 28 07:45:07 volumio volumio[32144]: info: CoreStateMachine::pushState Jan 28 07:45:07 volumio volumio[32144]: info: CorePlayQueue::getTrack 0 Jan 28 07:45:07 volumio volumio[32144]: info: CoreCommandRouter::volumioPushState Jan 28 07:45:07 volumio volumio[32144]: info: Setting Device type: Raspberry PI Jan 28 07:45:07 volumio volumio[32144]: info: Completed loading Core Plugins Jan 28 07:45:07 volumio volumio[32144]: info: Preparing to generate the ALSA configuration file Jan 28 07:45:07 volumio volumio[32144]: info: VolumeController:: Volume=100 Mute =false Jan 28 07:45:07 volumio volumio[32144]: info: CoreStateMachine::pushState Jan 28 07:45:07 volumio volumio[32144]: info: CorePlayQueue::getTrack 0 Jan 28 07:45:07 volumio volumio[32144]: info: CoreCommandRouter::volumioPushState Jan 28 07:45:07 volumio volumio[32144]: info: Asound.conf file unchanged, so no further update is needed Jan 28 07:45:07 volumio volumio[32144]: info: Output device has changed, restarting MPD Jan 28 07:45:07 volumio sudo[32318]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Jan 28 07:45:07 volumio sudo[32318]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 07:45:07 volumio volumio[32144]: info: Output device has changed, restarting Shairport Sync Jan 28 07:45:07 volumio volumio[32144]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 07:45:07 volumio volumio[32144]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 07:45:07 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 07:45:07 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 07:45:07 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 07:45:07 volumio volumio[32144]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 28 07:45:07 volumio volumio[32144]: info: ___________ START PLUGINS ___________ Jan 28 07:45:07 volumio sudo[32320]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 28 07:45:07 volumio sudo[32320]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 07:45:07 volumio volumio[32144]: info: ControllerMpd::onStart: Initializing MPD Jan 28 07:45:07 volumio volumio[32144]: info: Creating MPD Configuration file Jan 28 07:45:07 volumio sudo[32322]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 28 07:45:07 volumio sudo[32322]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 07:45:07 volumio sudo[32318]: pam_unix(sudo:session): session closed for user root Jan 28 07:45:07 volumio sudo[32320]: pam_unix(sudo:session): session closed for user root Jan 28 07:45:07 volumio volumio[32144]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 28 07:45:07 volumio volumio[32144]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 07:45:07 volumio volumio[32144]: info: [1769561107587] CoreMusicLibrary::Adding element Media Servers Jan 28 07:45:07 volumio volumio[32144]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 07:45:07 volumio volumio[32144]: info: UPNP Browser: Client initialized successfully Jan 28 07:45:07 volumio sudo[32331]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 28 07:45:07 volumio sudo[32331]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 07:45:07 volumio volumio[32144]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 07:45:07 volumio volumio[32144]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 07:45:07 volumio sudo[32331]: pam_unix(sudo:session): session closed for user root Jan 28 07:45:07 volumio sudo[32333]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 28 07:45:07 volumio sudo[32333]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 07:45:07 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Jan 28 07:45:07 volumio volumio[32144]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 28 07:45:07 volumio volumio[32144]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 07:45:07 volumio volumio[32144]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 07:45:07 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 28 07:45:07 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 28 07:45:07 volumio systemd[1]: mpd.service: Consumed 7.552s CPU time. Jan 28 07:45:07 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 28 07:45:07 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 28 07:45:07 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 28 07:45:07 volumio volumio[32144]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 28 07:45:07 volumio volumio[32144]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 07:45:07 volumio volumio[32144]: info: [1769561107917] CoreMusicLibrary::Adding element Last_100 Jan 28 07:45:07 volumio volumio[32144]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 07:45:07 volumio volumio[32144]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 07:45:07 volumio volumio[32144]: info: [1769561107927] CoreMusicLibrary::Adding element Webradio Jan 28 07:45:07 volumio volumio[32144]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 07:45:07 volumio volumio[32144]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 28 07:45:07 volumio volumio[32144]: info: Initializing BBC Radios Jan 28 07:45:07 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 28 07:45:07 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 28 07:45:08 volumio volumio[32144]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 28 07:45:08 volumio volumio[32144]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 07:45:08 volumio volumio[32144]: info: Creating Spotify config file Jan 28 07:45:08 volumio volumio[32144]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 07:45:08 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 18. Jan 28 07:45:08 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 07:45:08 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 07:45:08 volumio go-librespot[32359]: go-librespot daemon starting... Jan 28 07:45:08 volumio go-librespot[32360]: time="2026-01-28T07:45:08+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 07:45:08 volumio sudo[32347]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 28 07:45:08 volumio sudo[32347]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jan 28 07:45:08 volumio sudo[32347]: pam_unix(sudo:session): session closed for user root Jan 28 07:45:09 volumio go-librespot[32360]: time="2026-01-28T07:45:09+07:00" level=info msg="zeroconf server listening on port 44121" Jan 28 07:45:09 volumio volumio[32266]: Starting albumart workers Jan 28 07:45:09 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 07:45:09 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 07:45:09 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 07:45:09 volumio volumio[32268]: Starting albumart workers Jan 28 07:45:09 volumio volumio[32144]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 07:45:09 volumio volumio[32144]: info: [1769561109718] CoreMusicLibrary::Adding element YouTube Music Jan 28 07:45:09 volumio volumio[32144]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 07:45:09 volumio volumio[32144]: Cannot find translation for source YouTube Music Jan 28 07:45:09 volumio volumio[32144]: info: Volumio Calling Home Jan 28 07:45:09 volumio sudo[32370]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Jan 28 07:45:09 volumio sudo[32370]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 07:45:10 volumio sudo[32370]: pam_unix(sudo:session): session closed for user root Jan 28 07:45:10 volumio volumio[32267]: Starting albumart workers Jan 28 07:45:10 volumio volumio[32144]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Jan 28 07:45:10 volumio volumio[32144]: info: Discovery: Found device Volumio Jan 28 07:45:10 volumio volumio[32144]: info: CoreCommandRouter::volumioGetState Jan 28 07:45:10 volumio volumio[32144]: info: CorePlayQueue::getTrack 0 Jan 28 07:45:10 volumio volumio[32144]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Jan 28 07:45:10 volumio volumio[32144]: info: Discovery: Found device Volumio Jan 28 07:45:10 volumio volumio[32144]: info: CoreCommandRouter::volumioGetState Jan 28 07:45:10 volumio volumio[32144]: info: CorePlayQueue::getTrack 0 Jan 28 07:45:10 volumio volumio[32144]: info: MPD Permissions set Jan 28 07:45:10 volumio volumio[32144]: info: MPD Permissions set Jan 28 07:45:10 volumio volumio[32144]: info: Upmpdcli Daemon Started Jan 28 07:45:10 volumio volumio[32144]: info: Volumio called home Jan 28 07:45:10 volumio volumio[32144]: info: Spotify config file written Jan 28 07:45:10 volumio volumio[32144]: 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 07:45:10 volumio sudo[32376]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jan 28 07:45:10 volumio sudo[32376]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 07:45:10 volumio volumio[32144]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 07:45:10 volumio volumio[32144]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 07:45:10 volumio volumio[32144]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 07:45:10 volumio volumio[32144]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 07:45:10 volumio volumio[32144]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 07:45:10 volumio volumio[32144]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 07:45:10 volumio volumio[32144]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 07:45:10 volumio volumio[32144]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 07:45:10 volumio volumio[32144]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 07:45:10 volumio volumio[32144]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 07:45:10 volumio volumio[32144]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 07:45:10 volumio volumio[32144]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 07:45:10 volumio volumio[32144]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 07:45:10 volumio volumio[32144]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 07:45:10 volumio volumio[32144]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 07:45:10 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Jan 28 07:45:10 volumio volumio[32144]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 07:45:10 volumio volumio[32144]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 07:45:10 volumio volumio[32144]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 07:45:10 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Jan 28 07:45:10 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 07:45:11 volumio volumio[32144]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 07:45:11 volumio volumio[32144]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 07:45:11 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 07:45:11 volumio go-librespot[32384]: go-librespot daemon starting... Jan 28 07:45:11 volumio volumio[32144]: info: No need to fix Spotify hosts Jan 28 07:45:11 volumio sudo[32376]: pam_unix(sudo:session): session closed for user root Jan 28 07:45:11 volumio go-librespot[32389]: time="2026-01-28T07:45:11+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 07:45:11 volumio go-librespot[32389]: time="2026-01-28T07:45:11+07:00" level=debug msg="app state loaded" Jan 28 07:45:11 volumio go-librespot[32389]: time="2026-01-28T07:45:11+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 07:45:11 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 07:45:11 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 07:45:11 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 07:45:11 volumio go-librespot[32389]: time="2026-01-28T07:45: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 07:45:11 volumio go-librespot[32389]: time="2026-01-28T07:45: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 07:45:11 volumio go-librespot[32389]: time="2026-01-28T07:45: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 07:45:11 volumio go-librespot[32389]: time="2026-01-28T07:45:11+07:00" level=info msg="zeroconf server listening on port 36247" Jan 28 07:45:12 volumio go-librespot[32389]: time="2026-01-28T07:45:12+07:00" level=debug msg="obtained new client token: AADfXvTI0zp4arFUiHxwBfARd1+AwEOJrR9ZO57o0ZnpQivGOCr9nsbZX4mP3L+avuCDGafQCQUVkYoOcn11GmvTYx1bSXYtvQG9UzZMCB4uufVDb89S4c0K/tbrOQKnv2I1/g6o/wJoKbZQ1Vkjc1HmZFfxpyXMkJe4qt7NAxgOmLaMslvYI/IDBoGtGUFlz3Dh3/127fVbz1lvty3RSlnEMkbd/DCQY6UU+VX4sRf8YIN3Lw+GpOQ/" Jan 28 07:45:12 volumio go-librespot[32389]: time="2026-01-28T07:45:12+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 07:45:12 volumio go-librespot[32389]: time="2026-01-28T07:45:12+07:00" level=debug msg="completed keyexchange" Jan 28 07:45:12 volumio go-librespot[32389]: time="2026-01-28T07:45:12+07:00" level=debug msg="completed challenge" Jan 28 07:45:12 volumio go-librespot[32389]: time="2026-01-28T07:45:12+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 07:45:12 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 07:45:12 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 07:45:12 volumio volumio[32144]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 28 07:45:12 volumio volumio[32144]: SPOTIFY: BQCEwZq2MksOP1G0Cl7lbF223n9sEWq_89EjauPSxfkdt8NHwGxGabCM3ez1oIfRqi-2sQji7RweUHJqA5hn_5sq2zTy4FyRihUtOEARxX230GbEDEyDzE7q8qVzOFg0g8IaZdIaNYJYZol5sDxjaVJJyRiDfNMkUUcU-u3C9RzcrIt_9FZByNuspPFGsLeYMvkuSdd5cZah8i8E7o3sJaVcgh1mL22GmPn36cw41DqFccdPgPZ49cw88spKOxWt0h_QUYfL_1UQKswYDWcovonKuj3wGSGdPmc9YL3i5YB2Et0oqLAcWV0B Jan 28 07:45:12 volumio volumio[32144]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 28 07:45:12 volumio volumio[32144]: info: New Spotify access token = BQCEwZq2MksOP1G0Cl7lbF223n9sEWq_89EjauPSxfkdt8NHwGxGabCM3ez1oIfRqi-2sQji7RweUHJqA5hn_5sq2zTy4FyRihUtOEARxX230GbEDEyDzE7q8qVzOFg0g8IaZdIaNYJYZol5sDxjaVJJyRiDfNMkUUcU-u3C9RzcrIt_9FZByNuspPFGsLeYMvkuSdd5cZah8i8E7o3sJaVcgh1mL22GmPn36cw41DqFccdPgPZ49cw88spKOxWt0h_QUYfL_1UQKswYDWcovonKuj3wGSGdPmc9YL3i5YB2Et0oqLAcWV0B Jan 28 07:45:12 volumio volumio[32144]: info: Spotify credentials grant success - running version from March 24, 2019 Jan 28 07:45:12 volumio volumio[32144]: info: Starting Shairport Sync Jan 28 07:45:12 volumio volumio[32144]: info: Starting Shairport Sync Jan 28 07:45:12 volumio volumio[32144]: info: Starting Shairport Sync Jan 28 07:45:12 volumio sudo[32417]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 28 07:45:12 volumio sudo[32417]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 07:45:12 volumio sudo[32419]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 28 07:45:12 volumio sudo[32419]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 07:45:12 volumio sudo[32422]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 28 07:45:12 volumio sudo[32422]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 07:45:12 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 28 07:45:12 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Jan 28 07:45:12 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 28 07:45:12 volumio systemd[1]: shairport-sync.service: Consumed 2.344s CPU time. Jan 28 07:45:12 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 28 07:45:12 volumio sudo[32417]: pam_unix(sudo:session): session closed for user root Jan 28 07:45:13 volumio sudo[32419]: pam_unix(sudo:session): session closed for user root Jan 28 07:45:13 volumio sudo[32422]: pam_unix(sudo:session): session closed for user root Jan 28 07:45:13 volumio volumio[32144]: info: CoreCommandRouter::volumioGetState Jan 28 07:45:13 volumio volumio[32144]: info: CorePlayQueue::getTrack 0 Jan 28 07:45:13 volumio volumio[32144]: info: Shairport-Sync Started Jan 28 07:45:13 volumio volumio[32144]: Error adding Membership: Error: addMembership EINVAL Jan 28 07:45:13 volumio volumio[32144]: info: Shairport-Sync Started Jan 28 07:45:13 volumio volumio[32144]: info: Shairport-Sync Started Jan 28 07:45:13 volumio volumio[32144]: 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 07:45:13 volumio volumio[32144]: info: Spotify Successfully logged in Jan 28 07:45:13 volumio volumio[32144]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 07:45:13 volumio volumio[32144]: info: [1769561113289] CoreMusicLibrary::Adding element Spotify Jan 28 07:45:13 volumio volumio[32144]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 07:45:13 volumio volumio[32144]: Cannot find translation for source YouTube Music Jan 28 07:45:13 volumio volumio[32144]: Cannot find translation for source Spotify Jan 28 07:45:13 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 07:45:13 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 07:45:13 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 07:45:13 volumio volumio[32144]: info: [yt-cast-receiver] DIAL server listening on port 8098 Jan 28 07:45:13 volumio volumio[32144]: info: CoreCommandRouter::volumioRetrievevolume Jan 28 07:45:14 volumio volumio[32144]: info: VolumeController:: Volume=100 Mute =false Jan 28 07:45:14 volumio volumio[32144]: info: CoreCommandRouter::volumioGetState Jan 28 07:45:14 volumio volumio[32144]: info: CorePlayQueue::getTrack 0 Jan 28 07:45:14 volumio volumio[32144]: info: CoreStateMachine::pushState Jan 28 07:45:14 volumio volumio[32144]: info: CorePlayQueue::getTrack 0 Jan 28 07:45:14 volumio volumio[32144]: info: CoreCommandRouter::volumioPushState Jan 28 07:45:15 volumio volumio[32144]: info: go-librespot daemon successfully initialized Jan 28 07:45:15 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 07:45:15 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 07:45:15 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 07:45:15 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Jan 28 07:45:15 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 07:45:15 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 07:45:15 volumio go-librespot[32456]: go-librespot daemon starting... Jan 28 07:45:15 volumio go-librespot[32457]: time="2026-01-28T07:45:15+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 07:45:15 volumio go-librespot[32457]: time="2026-01-28T07:45:15+07:00" level=debug msg="app state loaded" Jan 28 07:45:15 volumio go-librespot[32457]: time="2026-01-28T07:45:15+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 07:45:15 volumio mpd[32367]: 2026-01-28T07:45:15 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 28 07:45:15 volumio systemd[1]: Started mpd.service - Music Player Daemon. Jan 28 07:45:15 volumio sudo[32333]: pam_unix(sudo:session): session closed for user root Jan 28 07:45:15 volumio sudo[32322]: pam_unix(sudo:session): session closed for user root Jan 28 07:45:16 volumio volumio[32144]: error: MPD error: The expression evaluated to a falsy value: Jan 28 07:45:16 volumio volumio[32144]: assert.ok(self.idling) Jan 28 07:45:16 volumio volumio[32144]: error: The expression evaluated to a falsy value: Jan 28 07:45:16 volumio volumio[32144]: assert.ok(self.idling) Jan 28 07:45:16 volumio volumio[32144]: error: updateQueue error: null Jan 28 07:45:16 volumio volumio[32144]: info: MPD running with PID32367 Jan 28 07:45:16 volumio volumio[32144]: ,establishing connection Jan 28 07:45:16 volumio go-librespot[32457]: time="2026-01-28T07:45: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 07:45:16 volumio go-librespot[32457]: time="2026-01-28T07:45:16+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 07:45:16 volumio go-librespot[32457]: time="2026-01-28T07:45:16+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 07:45:16 volumio go-librespot[32457]: time="2026-01-28T07:45:16+07:00" level=info msg="zeroconf server listening on port 41493" Jan 28 07:45:16 volumio volumio[32144]: info: Completed starting Core Plugins Jan 28 07:45:16 volumio volumio[32144]: info: ------------------------------------------- Jan 28 07:45:16 volumio volumio[32144]: info: ----- MyVolumio plugins startup ---- Jan 28 07:45:16 volumio volumio[32144]: info: ------------------------------------------- Jan 28 07:45:16 volumio volumio[32144]: info: [MyVolumio PluginManager] Fetching plans data.... Jan 28 07:45:16 volumio volumio[32144]: error: updateQueue error: null Jan 28 07:45:16 volumio go-librespot[32457]: time="2026-01-28T07:45:16+07:00" level=debug msg="obtained new client token: AACht3Ccg5qbohXZOPFZo8AhFFAghUWrHkF5SBfl6FxZhV5IZvYYoaK8xD+L7+kKH6ZsUJywgRpSfHHvX9guSpaP+0u7l3sArkt+sCCD4EgDtBsV3AaOiod+RIFHW0Rv2iNRXWi67NucnKoJYAN93lDhEwua/CRnd4u23T7TtXPVIdaqfvzx35wkQMyOEDmQOr3cxXuO0oQZsnujqCEJoImU+p4vlsLmhIeSm8hqmz0RLWKq8e+dtJm+EWQ=" Jan 28 07:45:16 volumio go-librespot[32457]: time="2026-01-28T07:45:16+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 07:45:16 volumio go-librespot[32457]: time="2026-01-28T07:45:16+07:00" level=debug msg="completed keyexchange" Jan 28 07:45:16 volumio go-librespot[32457]: time="2026-01-28T07:45:16+07:00" level=debug msg="completed challenge" Jan 28 07:45:16 volumio go-librespot[32457]: time="2026-01-28T07:45:16+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 07:45:16 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 07:45:16 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 07:45:17 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 07:45:17 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 07:45:17 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 07:45:18 volumio volumio[32144]: info: Initializing connection to go-librespot Websocket Jan 28 07:45:18 volumio volumio[32144]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 28 07:45:19 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 07:45:19 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 07:45:19 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 07:45:19 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Jan 28 07:45:19 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 07:45:20 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 07:45:20 volumio go-librespot[32468]: go-librespot daemon starting... Jan 28 07:45:20 volumio go-librespot[32471]: time="2026-01-28T07:45:20+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 07:45:20 volumio go-librespot[32471]: time="2026-01-28T07:45:20+07:00" level=debug msg="app state loaded" Jan 28 07:45:20 volumio go-librespot[32471]: time="2026-01-28T07:45:20+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 07:45:20 volumio go-librespot[32471]: time="2026-01-28T07:45: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 07:45:20 volumio go-librespot[32471]: time="2026-01-28T07:45: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 07:45:20 volumio go-librespot[32471]: time="2026-01-28T07:45: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 07:45:20 volumio go-librespot[32471]: time="2026-01-28T07:45:20+07:00" level=info msg="zeroconf server listening on port 36763" Jan 28 07:45:20 volumio go-librespot[32471]: time="2026-01-28T07:45:20+07:00" level=debug msg="obtained new client token: AADvHHx+gX6/sgrUeZx12Qi25HnoOhZk5TLG/Ex727JsD2S2knNggGlsu9Rp682aPjg8jGuI8RE+GqZwy1A+wPoMbTc56dREkhs7eRhcn0rmBJPO9DcDS+ocDtXgxNMejmOQfwLn8/AWnfJ2Fzr3f0mRKnlig4sem9z7Ful/pxJV0kxFrwJ5DLZyeZPU2o+1FbWJioCcO8boXW0cPJ9hmmJ0kqgEOa6E4SbzWEiYgYTPWgWtZLyHeXR0wb0=" Jan 28 07:45:20 volumio go-librespot[32471]: time="2026-01-28T07:45:20+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 07:45:21 volumio go-librespot[32471]: time="2026-01-28T07:45:21+07:00" level=debug msg="completed keyexchange" Jan 28 07:45:21 volumio go-librespot[32471]: time="2026-01-28T07:45:21+07:00" level=debug msg="completed challenge" Jan 28 07:45:21 volumio volumio[32144]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Jan 28 07:45:21 volumio go-librespot[32471]: time="2026-01-28T07:45:21+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 07:45:21 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 07:45:21 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 07:45:21 volumio volumio[32144]: info: Initializing connection to go-librespot Websocket Jan 28 07:45:21 volumio volumio[32144]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 28 07:45:21 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 07:45:21 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 07:45:21 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 07:45:23 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 07:45:23 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 07:45:23 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 07:45:24 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Jan 28 07:45:24 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 07:45:24 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 07:45:24 volumio go-librespot[32479]: go-librespot daemon starting... Jan 28 07:45:24 volumio go-librespot[32480]: time="2026-01-28T07:45:24+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 07:45:24 volumio go-librespot[32480]: time="2026-01-28T07:45:24+07:00" level=debug msg="app state loaded" Jan 28 07:45:24 volumio go-librespot[32480]: time="2026-01-28T07:45:24+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 07:45:24 volumio volumio[32144]: info: Initializing connection to go-librespot Websocket Jan 28 07:45:24 volumio go-librespot[32480]: time="2026-01-28T07:45:24+07:00" level=debug msg="new websocket client" Jan 28 07:45:24 volumio volumio[32144]: info: Connection to go-librespot Websocket established Jan 28 07:45:24 volumio go-librespot[32480]: time="2026-01-28T07:45: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 07:45:24 volumio go-librespot[32480]: time="2026-01-28T07:45: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 07:45:24 volumio go-librespot[32480]: time="2026-01-28T07:45: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 07:45:24 volumio go-librespot[32480]: time="2026-01-28T07:45:24+07:00" level=info msg="zeroconf server listening on port 35353" Jan 28 07:45:25 volumio go-librespot[32480]: time="2026-01-28T07:45:25+07:00" level=debug msg="obtained new client token: AACztUwYeLwS0pexLTG7ORa9IqYrc+ItHLnrvsA1DtYNphDxPG525jYZo9dDAIHw/eBYg3E6Vp7GeeqdyRm+gl1PVU740zDOGZuxmSglVBYi9mAt5wLh5uHDg40YN7XX8uHOEmE7+fiTL2CQ468QCCN7LpgY4CXM/LA6F/cjW8HiT/Fb6GZvGH+aSDQi7xLgV10MWUIqiqc1JPCE60QOiPu2QydJUaJwXnp9t9l6Z5YONKAKfRgrj0ZD" Jan 28 07:45:25 volumio volumio[32144]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Jan 28 07:45:25 volumio volumio[32144]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Jan 28 07:45:25 volumio volumio[32144]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Jan 28 07:45:25 volumio volumio[32144]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Jan 28 07:45:25 volumio volumio[32144]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Jan 28 07:45:25 volumio volumio[32144]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Jan 28 07:45:25 volumio volumio[32144]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Jan 28 07:45:25 volumio volumio[32144]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Jan 28 07:45:25 volumio volumio[32144]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Jan 28 07:45:25 volumio volumio[32144]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Jan 28 07:45:25 volumio volumio[32144]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Jan 28 07:45:25 volumio volumio[32144]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Jan 28 07:45:25 volumio volumio[32144]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Jan 28 07:45:25 volumio volumio[32144]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Jan 28 07:45:25 volumio volumio[32144]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Jan 28 07:45:25 volumio volumio[32144]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Jan 28 07:45:25 volumio volumio[32144]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Jan 28 07:45:25 volumio volumio[32144]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Jan 28 07:45:25 volumio volumio[32144]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Jan 28 07:45:25 volumio volumio[32144]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Jan 28 07:45:25 volumio volumio[32144]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Jan 28 07:45:25 volumio volumio[32144]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Jan 28 07:45:25 volumio volumio[32144]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Jan 28 07:45:25 volumio volumio[32144]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Jan 28 07:45:25 volumio volumio[32144]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Jan 28 07:45:25 volumio volumio[32144]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Jan 28 07:45:25 volumio volumio[32144]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Jan 28 07:45:25 volumio volumio[32144]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Jan 28 07:45:25 volumio volumio[32144]: info: Adding plugin bluetooth to MyMusic Plugins Jan 28 07:45:25 volumio volumio[32144]: info: Adding plugin multiroom to MyMusic Plugins Jan 28 07:45:25 volumio volumio[32144]: info: Adding plugin metavolumio to MyMusic Plugins Jan 28 07:45:25 volumio volumio[32144]: info: Adding plugin cd_controller to MyMusic Plugins Jan 28 07:45:25 volumio volumio[32144]: info: Adding plugin qobuzconnect to MyMusic Plugins Jan 28 07:45:25 volumio volumio[32144]: info: Adding plugin smart_inputs to MyMusic Plugins Jan 28 07:45:25 volumio volumio[32144]: info: Adding plugin tidalconnect to MyMusic Plugins Jan 28 07:45:25 volumio volumio[32144]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Jan 28 07:45:25 volumio go-librespot[32480]: time="2026-01-28T07:45:25+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 07:45:25 volumio go-librespot[32480]: time="2026-01-28T07:45:25+07:00" level=debug msg="completed keyexchange" Jan 28 07:45:25 volumio go-librespot[32480]: time="2026-01-28T07:45:25+07:00" level=debug msg="completed challenge" Jan 28 07:45:25 volumio go-librespot[32480]: time="2026-01-28T07:45: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 07:45:25 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 07:45:25 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 07:45:25 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 07:45:25 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 07:45:25 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 07:45:27 volumio volumio[32144]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Jan 28 07:45:27 volumio volumio[32144]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Jan 28 07:45:27 volumio volumio[32144]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 07:45:27 volumio volumio[32144]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 07:45:27 volumio volumio[32144]: info: Starting MyVolumio Remote Streaming Endpoints Jan 28 07:45:27 volumio volumio[32144]: info: MyVolumio login type: Token Jan 28 07:45:27 volumio volumio[32144]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Jan 28 07:45:27 volumio volumio[32144]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Jan 28 07:45:27 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 07:45:27 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 07:45:27 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 07:45:28 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Jan 28 07:45:28 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 07:45:28 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 07:45:28 volumio go-librespot[32501]: go-librespot daemon starting... Jan 28 07:45:28 volumio go-librespot[32502]: time="2026-01-28T07:45:28+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 07:45:28 volumio go-librespot[32502]: time="2026-01-28T07:45:28+07:00" level=debug msg="app state loaded" Jan 28 07:45:28 volumio go-librespot[32502]: time="2026-01-28T07:45:28+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 07:45:28 volumio volumio[32144]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Jan 28 07:45:28 volumio volumio[32144]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Jan 28 07:45:28 volumio volumio[32144]: info: Streaming services startup Jan 28 07:45:28 volumio volumio[32144]: info: Starting Streaming Daemon Jan 28 07:45:28 volumio sudo[32509]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jan 28 07:45:28 volumio volumio[32144]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Jan 28 07:45:28 volumio sudo[32509]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 07:45:28 volumio sudo[32509]: pam_unix(sudo:session): session closed for user root Jan 28 07:45:28 volumio volumio[32144]: info: Getting Spotify volume Jan 28 07:45:29 volumio volumio[32144]: info: Connection to go-librespot Websocket closed Jan 28 07:45:29 volumio volumio[32144]: error: Cannot start Volumio Streaming Daemon Jan 28 07:45:29 volumio volumio[32144]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Jan 28 07:45:29 volumio volumio[32144]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Jan 28 07:45:29 volumio volumio[32144]: 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 07:45:29 volumio go-librespot[32502]: time="2026-01-28T07:45:29+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 07:45:29 volumio go-librespot[32502]: time="2026-01-28T07:45:29+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 07:45:29 volumio go-librespot[32502]: time="2026-01-28T07:45:29+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 07:45:29 volumio go-librespot[32502]: time="2026-01-28T07:45:29+07:00" level=info msg="zeroconf server listening on port 42723" Jan 28 07:45:29 volumio volumio[32144]: info: CoreCommandRouter::volumioGetState Jan 28 07:45:29 volumio volumio[32144]: info: CorePlayQueue::getTrack 0 Jan 28 07:45:29 volumio volumio[32144]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jan 28 07:45:29 volumio volumio[32144]: SPOTIFY: SPOTIFY VOLUME undefined Jan 28 07:45:29 volumio volumio[32144]: SPOTIFY: VOLUMIO VOLUME 100 Jan 28 07:45:29 volumio volumio[32144]: info: Aligning Spotify Volume to Volumio Volume Jan 28 07:45:29 volumio volumio[32144]: info: CoreCommandRouter::volumioGetState Jan 28 07:45:29 volumio volumio[32144]: info: CorePlayQueue::getTrack 0 Jan 28 07:45:29 volumio volumio[32144]: info: Setting Spotify Volume from Volumio: 100 Jan 28 07:45:29 volumio go-librespot[32502]: time="2026-01-28T07:45:29+07:00" level=debug msg="obtained new client token: AABjvncohUHqeLg19lJ7nfG6FThXAlEXc65A5ZL7/o+hT6usfXYEbpKkn/Yt+n652vO7EwKBp5A3XGdPOk2n2MqlRldtst+caeMCYuISmbyX/QZy8ULx4ikhWQZzvQr56am+hcNpfTHIdXR2Htc7qpMkI5ltEOW1R69DahEa/jA9lV65rufz8s+6RYXlUJjWWff87eCIyXXLNwKHTWHw9+FRWfHwYI8cKRyH78HMINU/vxyZKPGL+BEd3H0=" Jan 28 07:45:29 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 07:45:29 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 07:45:29 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 07:45:29 volumio go-librespot[32502]: time="2026-01-28T07:45:29+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 07:45:29 volumio go-librespot[32502]: time="2026-01-28T07:45:29+07:00" level=debug msg="completed keyexchange" Jan 28 07:45:29 volumio go-librespot[32502]: time="2026-01-28T07:45:29+07:00" level=debug msg="completed challenge" Jan 28 07:45:29 volumio go-librespot[32502]: time="2026-01-28T07:45:29+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 07:45:29 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 07:45:29 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 07:45:29 volumio volumio[32144]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 28 07:45:29 volumio volumio[32144]: Error: socket hang up Jan 28 07:45:29 volumio volumio[32144]: at connResetException (node:internal/errors:720:14) Jan 28 07:45:29 volumio volumio[32144]: at Socket.socketOnEnd (node:_http_client:519:23) Jan 28 07:45:29 volumio volumio[32144]: at Socket.emit (node:events:526:35) Jan 28 07:45:29 volumio volumio[32144]: at endReadableNT (node:internal/streams/readable:1376:12) Jan 28 07:45:29 volumio volumio[32144]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Jan 28 07:45:29 volumio volumio[32144]: code: 'ECONNRESET', Jan 28 07:45:29 volumio volumio[32144]: response: undefined Jan 28 07:45:29 volumio volumio[32144]: } Jan 28 07:45:29 volumio volumio[32144]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 28 07:45:31 volumio sudo[32531]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-01-28 07:44' Jan 28 07:45:31 volumio sudo[32531]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 07:45:31 volumio sudo[32531]: pam_unix(sudo:session): session closed for user root Jan 28 07:45:31 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 07:45:31 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 07:45:31 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 07:45:32 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Jan 28 07:45:32 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 07:45:32 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 07:45:32 volumio go-librespot[32539]: go-librespot daemon starting... Jan 28 07:45:32 volumio go-librespot[32540]: time="2026-01-28T07:45:32+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 07:45:32 volumio go-librespot[32540]: time="2026-01-28T07:45:32+07:00" level=debug msg="app state loaded" Jan 28 07:45:32 volumio go-librespot[32540]: time="2026-01-28T07:45:32+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 07:45:32 volumio volumio-remote-updater[628]: [2026-01-28 07:45:32] [error] handle_read_frame error: asio.system:104 (Connection reset by peer) Jan 28 07:45:32 volumio volumio-remote-updater[628]: [2026-01-28 07:45:32] [disconnect] Disconnect close local:[1006,Connection reset by peer] remote:[1006] Jan 28 07:45:32 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Jan 28 07:45:32 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Jan 28 07:45:32 volumio systemd[1]: volumio.service: Consumed 59.410s CPU time. Jan 28 07:45:33 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 28 07:45:33 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Jan 28 07:45:33 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 9813. Jan 28 07:45:33 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 28 07:45:33 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Jan 28 07:45:33 volumio systemd[1]: volumio.service: Consumed 59.410s CPU time. Jan 28 07:45:33 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Jan 28 07:45:33 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Jan 28 07:45:33 volumio go-librespot[32540]: time="2026-01-28T07:45:33+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 28 07:45:33 volumio go-librespot[32540]: time="2026-01-28T07:45:33+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 07:45:33 volumio go-librespot[32540]: time="2026-01-28T07:45:33+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 07:45:33 volumio go-librespot[32540]: time="2026-01-28T07:45:33+07:00" level=info msg="zeroconf server listening on port 33803" Jan 28 07:45:33 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 07:45:33 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 07:45:33 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 07:45:33 volumio go-librespot[32540]: time="2026-01-28T07:45:33+07:00" level=debug msg="obtained new client token: AACY0f1n6aDwX/tMBN8ZptNWzPKO6Av+bgBg+zCY4WUILT/79fpMPQxxQ6e7cjEHkJOKXhd99tRkU4OlcKUzZye2GPSFHp8IhyFR8g9653vZLcGlUrMy3vA2LegiXKBoeMD+zvKpt5pa0FjSEBY1my/7la9tPk+sQhEv3Sycy5n3W97dqi6uNM+d8+b1uKOBLj5K6PnnJu0o3FQc9TURhd6NH30+12w3vQSKm2VPd6mwjfaxf+oODBbIwfo=" Jan 28 07:45:33 volumio go-librespot[32540]: time="2026-01-28T07:45:33+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 07:45:33 volumio go-librespot[32540]: time="2026-01-28T07:45:33+07:00" level=debug msg="completed keyexchange" Jan 28 07:45:33 volumio go-librespot[32540]: time="2026-01-28T07:45:33+07:00" level=debug msg="completed challenge" Jan 28 07:45:34 volumio go-librespot[32540]: time="2026-01-28T07:45:34+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 07:45:34 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 07:45:34 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 07:45:35 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 07:45:35 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 07:45:35 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 07:45:36 volumio volumio[32559]: info: ------------------------------------------- Jan 28 07:45:36 volumio volumio[32559]: info: ----- Volumio3 ---- Jan 28 07:45:36 volumio volumio[32559]: info: ------------------------------------------- Jan 28 07:45:36 volumio volumio[32559]: info: ----- System startup ---- Jan 28 07:45:36 volumio volumio[32559]: info: ------------------------------------------- Jan 28 07:45:37 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Jan 28 07:45:37 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 07:45:37 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 07:45:37 volumio go-librespot[32583]: go-librespot daemon starting... Jan 28 07:45:37 volumio go-librespot[32584]: time="2026-01-28T07:45:37+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 07:45:37 volumio go-librespot[32584]: time="2026-01-28T07:45:37+07:00" level=debug msg="app state loaded" Jan 28 07:45:37 volumio go-librespot[32584]: time="2026-01-28T07:45:37+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 07:45:37 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 07:45:37 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 07:45:37 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 07:45:37 volumio go-librespot[32584]: time="2026-01-28T07:45:37+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 07:45:37 volumio go-librespot[32584]: time="2026-01-28T07:45:37+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 07:45:37 volumio go-librespot[32584]: time="2026-01-28T07:45:37+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 07:45:37 volumio go-librespot[32584]: time="2026-01-28T07:45:37+07:00" level=info msg="zeroconf server listening on port 42297" Jan 28 07:45:37 volumio volumio-remote-updater[628]: [2026-01-28 07:45:37] [connect] Successful connection Jan 28 07:45:38 volumio go-librespot[32584]: time="2026-01-28T07:45:38+07:00" level=debug msg="obtained new client token: AACrw+AF4lJ3lYCwzN0gHtYyCdTlmc6r6Tc3HJaAHBVICjfBOaHB/6NEN1tipGK6pofSyPGNI1zprKXolwCBz1knCLquD1VYDDmtqVviyFNRE6Wpfs8gCbXm0jYoZzS2XpXRhkTlJspnEn7w6Y9sIko47qLCdp8Eb7kO3H8XAPPfaFSqZfIHgwF/WQ/UfD0rp995RvJq66HbZo8+a5aOwN0Ui7WCpte/kl1DI6U5WxMLJss4UstpIkYP" Jan 28 07:45:38 volumio volumio[32559]: info: MYVOLUMIO Environment detected Jan 28 07:45:38 volumio go-librespot[32584]: time="2026-01-28T07:45:38+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 07:45:38 volumio volumio[32559]: info: Plugin folders cleanup Jan 28 07:45:38 volumio volumio[32559]: info: Scanning into folder /volumio/app/plugins/ Jan 28 07:45:38 volumio volumio[32559]: info: Scanning category audio_interface Jan 28 07:45:38 volumio volumio[32559]: info: Scanning category miscellanea Jan 28 07:45:38 volumio volumio[32559]: info: Scanning category music_service Jan 28 07:45:38 volumio volumio[32559]: info: Scanning category plugins.json Jan 28 07:45:38 volumio volumio[32559]: info: Scanning category system_controller Jan 28 07:45:38 volumio volumio[32559]: info: Scanning category user_interface Jan 28 07:45:38 volumio volumio[32559]: info: Scanning into folder /data/plugins/ Jan 28 07:45:38 volumio volumio[32559]: info: Scanning category music_service Jan 28 07:45:38 volumio volumio[32559]: info: Plugin folders cleanup completed Jan 28 07:45:38 volumio volumio[32559]: info: ------------------------------------------- Jan 28 07:45:38 volumio volumio[32559]: info: ----- Core plugins startup ---- Jan 28 07:45:38 volumio volumio[32559]: info: ------------------------------------------- Jan 28 07:45:38 volumio volumio[32559]: info: Loading plugins from folder /volumio/app/plugins/ Jan 28 07:45:38 volumio volumio[32559]: info: Adding plugin upnp to MyMusic Plugins Jan 28 07:45:38 volumio go-librespot[32584]: time="2026-01-28T07:45:38+07:00" level=debug msg="completed keyexchange" Jan 28 07:45:38 volumio go-librespot[32584]: time="2026-01-28T07:45:38+07:00" level=debug msg="completed challenge" Jan 28 07:45:38 volumio volumio[32559]: info: Adding plugin airplay_emulation to MyMusic Plugins Jan 28 07:45:38 volumio volumio[32559]: info: Adding plugin upnp_browser to MyMusic Plugins Jan 28 07:45:38 volumio volumio[32559]: info: Loading plugins from folder /data/plugins/ Jan 28 07:45:38 volumio volumio[32559]: info: Loading plugin "system"... Jan 28 07:45:38 volumio go-librespot[32584]: time="2026-01-28T07:45:38+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 07:45:38 volumio volumio[32559]: info: Loading plugin "appearance"... Jan 28 07:45:38 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 07:45:38 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 07:45:39 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 07:45:39 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 07:45:39 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 07:45:40 volumio volumio[32559]: info: Loading plugin "network"... Jan 28 07:45:40 volumio volumio[32559]: info: Refreshing Cached IP Addresses Jan 28 07:45:40 volumio sudo[32599]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 28 07:45:40 volumio sudo[32599]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 07:45:40 volumio sudo[32601]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 28 07:45:40 volumio sudo[32601]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 07:45:40 volumio sudo[32599]: pam_unix(sudo:session): session closed for user root Jan 28 07:45:40 volumio volumio[32559]: info: Loading plugin "services"... Jan 28 07:45:40 volumio volumio[32559]: info: Loading plugin "alsa_controller"... Jan 28 07:45:40 volumio sudo[32601]: pam_unix(sudo:session): session closed for user root Jan 28 07:45:40 volumio sudo[32609]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Jan 28 07:45:40 volumio sudo[32609]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 07:45:40 volumio volumio[32559]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 28 07:45:40 volumio volumio[32559]: info: Loading plugin "wizard"... Jan 28 07:45:40 volumio volumio[32559]: info: Loading plugin "networkfs"... Jan 28 07:45:40 volumio volumio[32559]: info: Starting Udev Watcher for removable devices Jan 28 07:45:40 volumio volumio[32559]: info: Ignoring mount for partition: boot Jan 28 07:45:40 volumio volumio[32559]: info: Ignoring mount for partition: volumio Jan 28 07:45:40 volumio volumio[32559]: info: Ignoring mount for partition: volumio_data Jan 28 07:45:40 volumio volumio[32559]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 28 07:45:40 volumio volumio[32559]: info: Loading plugin "volumio_command_line_client"... Jan 28 07:45:40 volumio volumio[32559]: info: Loading plugin "upnp"... Jan 28 07:45:40 volumio volumio[32559]: info: [1769561140770] Starting Upmpd Daemon Jan 28 07:45:40 volumio volumio[32559]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 28 07:45:40 volumio volumio[32559]: info: Loading plugin "my_music"... Jan 28 07:45:40 volumio volumio[32559]: info: Loading plugin "mpd"... Jan 28 07:45:41 volumio volumio[32559]: info: Loading plugin "upnp_browser"... Jan 28 07:45:41 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Jan 28 07:45:41 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 07:45:41 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 07:45:41 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 07:45:41 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 07:45:41 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 07:45:41 volumio go-librespot[32632]: go-librespot daemon starting... Jan 28 07:45:41 volumio go-librespot[32633]: time="2026-01-28T07:45:41+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 07:45:41 volumio go-librespot[32633]: time="2026-01-28T07:45:41+07:00" level=debug msg="app state loaded" Jan 28 07:45:41 volumio go-librespot[32633]: time="2026-01-28T07:45:41+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 07:45:42 volumio go-librespot[32633]: time="2026-01-28T07:45:42+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 28 07:45:42 volumio go-librespot[32633]: time="2026-01-28T07:45:42+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 07:45:42 volumio go-librespot[32633]: time="2026-01-28T07:45:42+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 07:45:42 volumio go-librespot[32633]: time="2026-01-28T07:45:42+07:00" level=info msg="zeroconf server listening on port 37651" Jan 28 07:45:42 volumio go-librespot[32633]: time="2026-01-28T07:45:42+07:00" level=debug msg="obtained new client token: AAAIi9VWFhUCupFiPhI0aDhn18pWqLkEndP2NPQ0HKHUGtyk2n5FEm4Gmgkb7zCwC+t9rbt/xg/mwdh1J2gYinKNeoQuwcPwORvZJHxiDdZx+vSzEOEUvNT3+m+4S3sK4x6EDFXydzdIodSCwLUnZuwUFA5Jp9YHwoomI8MeTTETr4Vj1lEhYQBdPyrPOP8VkH4Jlwe1V80K7v4VP8ZfuZKy88Mp0BfAcxFMyumi3zcjrpI51ZZq7qNFotw=" Jan 28 07:45:42 volumio go-librespot[32633]: time="2026-01-28T07:45:42+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 07:45:42 volumio go-librespot[32633]: time="2026-01-28T07:45:42+07:00" level=debug msg="completed keyexchange" Jan 28 07:45:42 volumio go-librespot[32633]: time="2026-01-28T07:45:42+07:00" level=debug msg="completed challenge" Jan 28 07:45:42 volumio go-librespot[32633]: time="2026-01-28T07:45:42+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 07:45:42 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 07:45:42 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 07:45:43 volumio sudo[32609]: pam_unix(sudo:session): session closed for user root Jan 28 07:45:43 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 07:45:43 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 07:45:43 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 07:45:44 volumio volumio[32559]: info: Starting UPNP Browser Jan 28 07:45:44 volumio volumio[32559]: info: Loading plugin "alarm-clock"... Jan 28 07:45:44 volumio volumio[32559]: info: Loading plugin "airplay_emulation"... Jan 28 07:45:44 volumio volumio[32559]: info: Starting Shairport Sync Jan 28 07:45:44 volumio volumio[32559]: info: Loading plugin "last_100"... Jan 28 07:45:44 volumio volumio[32559]: info: Loading plugin "webradio"... Jan 28 07:45:44 volumio volumio[32559]: info: Loading plugin "i2s_dacs"... Jan 28 07:45:44 volumio volumio[32559]: info: Loading plugin "volumiodiscovery"... Jan 28 07:45:45 volumio volumio[32559]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 28 07:45:45 volumio volumio[32559]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 07:45:45 volumio volumio[32559]: *** WARNING *** For more information see Jan 28 07:45:45 volumio volumio[32559]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 28 07:45:45 volumio volumio[32559]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 07:45:45 volumio volumio[32559]: *** WARNING *** For more information see Jan 28 07:45:45 volumio node[32559]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 28 07:45:45 volumio node[32559]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 07:45:45 volumio node[32559]: *** WARNING *** For more information see Jan 28 07:45:45 volumio node[32559]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 28 07:45:45 volumio node[32559]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 07:45:45 volumio node[32559]: *** WARNING *** For more information see Jan 28 07:45:45 volumio volumio[32559]: info: Applying required configuration parameters for plugin volumiodiscovery Jan 28 07:45:45 volumio volumio[32559]: info: Discovery: Started advertising with name: Volumio Jan 28 07:45:45 volumio volumio[32559]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 28 07:45:45 volumio volumio[32559]: info: Loading plugin "spop"... Jan 28 07:45:45 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 07:45:45 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 07:45:45 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 07:45:45 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Jan 28 07:45:45 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 07:45:46 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 07:45:46 volumio go-librespot[32642]: go-librespot daemon starting... Jan 28 07:45:46 volumio go-librespot[32643]: time="2026-01-28T07:45:46+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 07:45:46 volumio go-librespot[32643]: time="2026-01-28T07:45:46+07:00" level=debug msg="app state loaded" Jan 28 07:45:46 volumio go-librespot[32643]: time="2026-01-28T07:45:46+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 07:45:46 volumio go-librespot[32643]: time="2026-01-28T07:45:46+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 28 07:45:46 volumio go-librespot[32643]: time="2026-01-28T07:45:46+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Jan 28 07:45:46 volumio go-librespot[32643]: time="2026-01-28T07:45:46+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Jan 28 07:45:46 volumio go-librespot[32643]: time="2026-01-28T07:45:46+07:00" level=info msg="zeroconf server listening on port 37685" Jan 28 07:45:46 volumio go-librespot[32643]: time="2026-01-28T07:45:46+07:00" level=debug msg="obtained new client token: AACX5yTaea+oxNKhc920XWh25lFm+FnUnnGYO8jofTF8rACbE3X3FbG8y4XBIfUvoyJRq7u24lYGlFW3fISfp3+Li0TuoWZudQ2V2PvBu1YK+zSCMrRJCYbE5G6o0xUZ5SEU9krMBflUKqXosNXyawD2eDqfQrgo1Ku5imeYY+FmGZMDq4rnJjYROKx2pO76n6MYidTzE+MiwHS6o/Syj3Ge424o8i9dkhmey/Y+GBUrj/syehdYaKRK4rY=" Jan 28 07:45:46 volumio volumio[32559]: info: Loading plugin "ytcr"... Jan 28 07:45:47 volumio go-librespot[32643]: time="2026-01-28T07:45:47+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 07:45:47 volumio go-librespot[32643]: time="2026-01-28T07:45:47+07:00" level=debug msg="completed keyexchange" Jan 28 07:45:47 volumio go-librespot[32643]: time="2026-01-28T07:45:47+07:00" level=debug msg="completed challenge" Jan 28 07:45:47 volumio go-librespot[32643]: time="2026-01-28T07:45:47+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 07:45:47 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 07:45:47 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 07:45:47 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 07:45:47 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 07:45:47 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 07:45:49 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 07:45:49 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 07:45:49 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 07:45:49 volumio volumio[32559]: info: Loading plugin "ytmusic"... Jan 28 07:45:50 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Jan 28 07:45:50 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 07:45:50 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 07:45:50 volumio go-librespot[32651]: go-librespot daemon starting... Jan 28 07:45:50 volumio go-librespot[32652]: time="2026-01-28T07:45:50+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 07:45:50 volumio go-librespot[32652]: time="2026-01-28T07:45:50+07:00" level=debug msg="app state loaded" Jan 28 07:45:50 volumio go-librespot[32652]: time="2026-01-28T07:45:50+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 07:45:50 volumio volumio-remote-updater[628]: [2026-01-28 07:45:50] [connect] Successful connection Jan 28 07:45:50 volumio volumio[32559]: info: Loading plugin "outputs"... Jan 28 07:45:50 volumio volumio[32559]: info: Loading plugin "albumart"... Jan 28 07:45:50 volumio volumio[32559]: info: Plugin example_plugin is not enabled Jan 28 07:45:50 volumio volumio[32559]: info: Loading plugin "inputs"... Jan 28 07:45:50 volumio volumio[32559]: info: Loading plugin "updater_comm"... Jan 28 07:45:50 volumio go-librespot[32652]: time="2026-01-28T07:45:50+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 28 07:45:50 volumio go-librespot[32652]: time="2026-01-28T07:45:50+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 07:45:50 volumio go-librespot[32652]: time="2026-01-28T07:45:50+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 07:45:50 volumio go-librespot[32652]: time="2026-01-28T07:45:50+07:00" level=info msg="zeroconf server listening on port 37337" Jan 28 07:45:51 volumio volumio[32559]: info: Plugin mpdemulation is not enabled Jan 28 07:45:51 volumio volumio[32559]: info: Loading plugin "rest_api"... Jan 28 07:45:51 volumio volumio[32559]: info: Loading plugin "websocket"... Jan 28 07:45:51 volumio volumio[32559]: info: Starting Socket.io Server version 1.7.4 Jan 28 07:45:51 volumio volumio[32559]: info: Loading plugin "RoonBridge"... Jan 28 07:45:51 volumio go-librespot[32652]: time="2026-01-28T07:45:51+07:00" level=debug msg="obtained new client token: AACCgZAAFTqqDk3rsFZZZci5+LqGABTTlp2SPAFz5MJ2OxQbtUuXAKrBxY9jk3dlM1LxIxmJV4waZndIBSWGnD1yyWqnh6gLvD5Eof5wp8Y2mufgBboroDOM+QngoUba5Ee59bcGq0P5dUk0MQ87Yq6zhJi0XqK3grYt3s37SH1qHEsARayA0Vd2v9O0Pr9FB+mSjni7LD2hDZ9SQfUbNuJ6Yyo4fo9qb9QQTzkeEsZM53VPCNCEC6vp" Jan 28 07:45:51 volumio go-librespot[32652]: time="2026-01-28T07:45:51+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 07:45:51 volumio go-librespot[32652]: time="2026-01-28T07:45:51+07:00" level=debug msg="completed keyexchange" Jan 28 07:45:51 volumio go-librespot[32652]: time="2026-01-28T07:45:51+07:00" level=debug msg="completed challenge" Jan 28 07:45:51 volumio go-librespot[32652]: time="2026-01-28T07:45:51+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 07:45:51 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 07:45:51 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 07:45:51 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 07:45:51 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 07:45:51 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 07:45:51 volumio volumio[32559]: info: Applying required configuration parameters for plugin RoonBridge Jan 28 07:45:51 volumio volumio[32559]: info: Loading i18n strings for locale en Jan 28 07:45:51 volumio volumio[32559]: Updating browse sources language Jan 28 07:45:51 volumio volumio[32559]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 07:45:51 volumio volumio[32673]: Forking 3 albumart workers Jan 28 07:45:51 volumio volumio[32559]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 28 07:45:51 volumio volumio[32559]: info: CoreCommandRouter::initPlayerControls Jan 28 07:45:51 volumio volumio[32559]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 07:45:51 volumio volumio[32559]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 07:45:51 volumio volumio[32559]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 07:45:51 volumio volumio[32559]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 07:45:51 volumio volumio[32559]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 07:45:51 volumio volumio[32559]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 07:45:51 volumio volumio[32559]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 07:45:51 volumio volumio[32559]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 07:45:51 volumio volumio[32559]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 28 07:45:51 volumio volumio[32559]: Express server listening on port 3000 Jan 28 07:45:51 volumio volumio[32559]: [Metrics] WebUI: 16s 165.73ms Jan 28 07:45:52 volumio volumio[32559]: info: CoreStateMachine::resetVolumioState Jan 28 07:45:52 volumio volumio[32559]: info: CoreStateMachine::getcurrentVolume Jan 28 07:45:52 volumio volumio[32559]: info: CoreCommandRouter::volumioRetrievevolume Jan 28 07:45:52 volumio sudo[32715]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 28 07:45:52 volumio sudo[32715]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 07:45:52 volumio sudo[32715]: pam_unix(sudo:session): session closed for user root Jan 28 07:45:52 volumio volumio[32559]: info: Volumio Network Manager: Network status updated: 1 Jan 28 07:45:52 volumio sudo[32717]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 28 07:45:52 volumio sudo[32717]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 07:45:52 volumio sudo[32717]: pam_unix(sudo:session): session closed for user root Jan 28 07:45:52 volumio volumio-remote-updater[628]: [2026-01-28 07:45:52] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1769561150 101 Jan 28 07:45:52 volumio volumio[32559]: 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 07:45:52 volumio volumio[32559]: info: VolumeController:: Volume=100 Mute =false Jan 28 07:45:52 volumio volumio[32559]: info: CoreStateMachine::pushState Jan 28 07:45:52 volumio volumio[32559]: info: CorePlayQueue::getTrack 0 Jan 28 07:45:52 volumio volumio[32559]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 28 07:45:52 volumio volumio[32559]: info: CoreCommandRouter::volumioPushState Jan 28 07:45:52 volumio volumio[32559]: info: CoreStateMachine::updateTrackBlock Jan 28 07:45:52 volumio volumio[32559]: info: CorePlayQueue::getTrackBlock Jan 28 07:45:52 volumio volumio[32559]: info: CoreCommandRouter::volumioRetrievevolume Jan 28 07:45:52 volumio volumio[32559]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 07:45:52 volumio volumio[32559]: info: Reloading queue from file Jan 28 07:45:52 volumio volumio[32559]: info: CoreStateMachine::setRepeat null single undefined Jan 28 07:45:52 volumio volumio[32559]: info: CoreStateMachine::pushState Jan 28 07:45:52 volumio volumio[32559]: info: CorePlayQueue::getTrack 0 Jan 28 07:45:52 volumio volumio[32559]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 28 07:45:52 volumio volumio[32559]: info: CoreCommandRouter::volumioPushState Jan 28 07:45:52 volumio volumio[32559]: info: CoreStateMachine::setRandom null Jan 28 07:45:52 volumio volumio[32559]: info: CoreStateMachine::pushState Jan 28 07:45:52 volumio volumio[32559]: info: CorePlayQueue::getTrack 0 Jan 28 07:45:52 volumio volumio[32559]: info: CoreCommandRouter::volumioPushState Jan 28 07:45:52 volumio volumio[32559]: info: Setting Device type: Raspberry PI Jan 28 07:45:52 volumio volumio[32559]: info: Completed loading Core Plugins Jan 28 07:45:52 volumio volumio[32559]: info: Preparing to generate the ALSA configuration file Jan 28 07:45:52 volumio volumio[32559]: info: VolumeController:: Volume=100 Mute =false Jan 28 07:45:52 volumio volumio[32559]: info: CoreStateMachine::pushState Jan 28 07:45:52 volumio volumio[32559]: info: CorePlayQueue::getTrack 0 Jan 28 07:45:52 volumio volumio[32559]: info: CoreCommandRouter::volumioPushState Jan 28 07:45:52 volumio volumio[32559]: info: Asound.conf file unchanged, so no further update is needed Jan 28 07:45:52 volumio volumio[32559]: info: Output device has changed, restarting MPD Jan 28 07:45:53 volumio volumio[32559]: info: Output device has changed, restarting Shairport Sync Jan 28 07:45:53 volumio volumio[32559]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 07:45:53 volumio volumio[32559]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 07:45:53 volumio sudo[32735]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Jan 28 07:45:53 volumio sudo[32735]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 07:45:53 volumio sudo[32738]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 28 07:45:53 volumio sudo[32738]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 07:45:53 volumio sudo[32739]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 28 07:45:53 volumio sudo[32739]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 07:45:53 volumio sudo[32738]: pam_unix(sudo:session): session closed for user root Jan 28 07:45:53 volumio volumio[32559]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 28 07:45:53 volumio volumio[32559]: info: ___________ START PLUGINS ___________ Jan 28 07:45:53 volumio volumio[32559]: info: ControllerMpd::onStart: Initializing MPD Jan 28 07:45:53 volumio volumio[32559]: info: Creating MPD Configuration file Jan 28 07:45:53 volumio sudo[32735]: pam_unix(sudo:session): session closed for user root Jan 28 07:45:53 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Jan 28 07:45:53 volumio volumio[32559]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 28 07:45:53 volumio volumio[32559]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 07:45:53 volumio volumio[32559]: info: [1769561153276] CoreMusicLibrary::Adding element Media Servers Jan 28 07:45:53 volumio volumio[32559]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 07:45:53 volumio volumio[32559]: info: UPNP Browser: Client initialized successfully Jan 28 07:45:53 volumio sudo[32750]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 28 07:45:53 volumio sudo[32750]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 07:45:53 volumio sudo[32748]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 28 07:45:53 volumio sudo[32748]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 07:45:53 volumio volumio[32559]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 07:45:53 volumio volumio[32559]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 07:45:53 volumio sudo[32748]: pam_unix(sudo:session): session closed for user root Jan 28 07:45:53 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 28 07:45:53 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 28 07:45:53 volumio systemd[1]: mpd.service: Consumed 7.461s CPU time. Jan 28 07:45:53 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 28 07:45:53 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 28 07:45:53 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 28 07:45:53 volumio volumio[32559]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 28 07:45:53 volumio volumio[32559]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 07:45:53 volumio volumio[32559]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 07:45:53 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 07:45:53 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 07:45:53 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 07:45:53 volumio volumio[32559]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 28 07:45:53 volumio volumio[32559]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 07:45:53 volumio volumio[32559]: info: [1769561153545] CoreMusicLibrary::Adding element Last_100 Jan 28 07:45:53 volumio volumio[32559]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 07:45:53 volumio volumio[32559]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 07:45:53 volumio volumio[32559]: info: [1769561153559] CoreMusicLibrary::Adding element Webradio Jan 28 07:45:53 volumio volumio[32559]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 07:45:53 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 28 07:45:53 volumio volumio[32559]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 28 07:45:53 volumio volumio[32559]: info: Initializing BBC Radios Jan 28 07:45:53 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 28 07:45:53 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 28 07:45:53 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 28 07:45:53 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 28 07:45:53 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 28 07:45:53 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 28 07:45:53 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 28 07:45:53 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 28 07:45:53 volumio volumio[32559]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 28 07:45:53 volumio volumio[32559]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 07:45:53 volumio volumio[32559]: info: Creating Spotify config file Jan 28 07:45:53 volumio volumio[32559]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 07:45:54 volumio sudo[305]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 28 07:45:54 volumio sudo[305]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jan 28 07:45:54 volumio sudo[305]: pam_unix(sudo:session): session closed for user root Jan 28 07:45:54 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Jan 28 07:45:54 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 07:45:54 volumio volumio[32559]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 07:45:54 volumio volumio[32559]: info: [1769561154775] CoreMusicLibrary::Adding element YouTube Music Jan 28 07:45:54 volumio volumio[32559]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 07:45:54 volumio volumio[32559]: Cannot find translation for source YouTube Music Jan 28 07:45:54 volumio volumio[32559]: info: Volumio Calling Home Jan 28 07:45:54 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 07:45:54 volumio go-librespot[313]: go-librespot daemon starting... Jan 28 07:45:54 volumio sudo[315]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Jan 28 07:45:54 volumio sudo[315]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 07:45:54 volumio go-librespot[317]: time="2026-01-28T07:45:54+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 07:45:55 volumio sudo[315]: pam_unix(sudo:session): session closed for user root Jan 28 07:45:55 volumio volumio[32683]: Starting albumart workers Jan 28 07:45:55 volumio volumio[32684]: Starting albumart workers Jan 28 07:45:55 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 07:45:55 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 07:45:55 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 07:45:55 volumio go-librespot[317]: time="2026-01-28T07:45:55+07:00" level=info msg="zeroconf server listening on port 44481" Jan 28 07:45:55 volumio volumio[32559]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Jan 28 07:45:55 volumio volumio[32559]: info: Discovery: Found device Volumio Jan 28 07:45:55 volumio volumio[32559]: info: CoreCommandRouter::volumioGetState Jan 28 07:45:55 volumio volumio[32559]: info: CorePlayQueue::getTrack 0 Jan 28 07:45:55 volumio volumio[32559]: info: MPD Permissions set Jan 28 07:45:55 volumio volumio[32559]: info: MPD Permissions set Jan 28 07:45:55 volumio volumio[32559]: info: Upmpdcli Daemon Started Jan 28 07:45:55 volumio volumio[32559]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Jan 28 07:45:55 volumio volumio[32559]: info: Discovery: Found device Volumio Jan 28 07:45:55 volumio volumio[32559]: info: CoreCommandRouter::volumioGetState Jan 28 07:45:55 volumio volumio[32559]: info: CorePlayQueue::getTrack 0 Jan 28 07:45:55 volumio volumio[32559]: info: Volumio called home Jan 28 07:45:55 volumio volumio[32559]: info: Spotify config file written Jan 28 07:45:56 volumio sudo[328]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jan 28 07:45:56 volumio sudo[328]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 07:45:56 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Jan 28 07:45:56 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Jan 28 07:45:56 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 07:45:56 volumio volumio[32559]: 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 07:45:56 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 07:45:56 volumio go-librespot[330]: go-librespot daemon starting... Jan 28 07:45:56 volumio volumio[32559]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 07:45:56 volumio volumio[32559]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 07:45:56 volumio volumio[32559]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 07:45:56 volumio sudo[328]: pam_unix(sudo:session): session closed for user root Jan 28 07:45:56 volumio volumio[32559]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 07:45:56 volumio volumio[32559]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 07:45:56 volumio volumio[32559]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 07:45:56 volumio volumio[32559]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 07:45:56 volumio volumio[32559]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 07:45:56 volumio go-librespot[331]: time="2026-01-28T07:45:56+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 07:45:56 volumio go-librespot[331]: time="2026-01-28T07:45:56+07:00" level=debug msg="app state loaded" Jan 28 07:45:56 volumio go-librespot[331]: time="2026-01-28T07:45:56+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 07:45:56 volumio volumio[32559]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 07:45:56 volumio volumio[32559]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 07:45:56 volumio volumio[32559]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 07:45:56 volumio volumio[32559]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 07:45:56 volumio volumio[32559]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 07:45:56 volumio volumio[32559]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 07:45:56 volumio volumio[32559]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 07:45:56 volumio volumio[32559]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 07:45:56 volumio volumio[32559]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 07:45:56 volumio volumio[32559]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 07:45:56 volumio volumio[32559]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 07:45:56 volumio volumio[32559]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 07:45:56 volumio volumio[32685]: Starting albumart workers Jan 28 07:45:56 volumio volumio[32559]: info: No need to fix Spotify hosts Jan 28 07:45:57 volumio go-librespot[331]: time="2026-01-28T07:45:57+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 07:45:57 volumio go-librespot[331]: time="2026-01-28T07:45:57+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 28 07:45:57 volumio go-librespot[331]: time="2026-01-28T07:45:57+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 28 07:45:57 volumio go-librespot[331]: time="2026-01-28T07:45:57+07:00" level=info msg="zeroconf server listening on port 46753" Jan 28 07:45:57 volumio go-librespot[331]: time="2026-01-28T07:45:57+07:00" level=debug msg="obtained new client token: AAAHF4EznYZ0XcY8bGA5A0vFqjPrbllbAtkaXowCkkaH6BTrawT62+nRe4CFx3mr6eBCyWcH805JOi+QO/AuIy16RhaWjOj6Dm6WTUN3kn3poX4ViTw2guzGBICaAFwKQ+GCVOyTRcyqnLdpvRCsdmaGa1FEJUH2i0FnTbfMiUxNeC7pVEBlXnRXUTjYWdwv6Wi/eLtREJdZAF5qLA9+ISBm1u7YT7KHvTT7+70jrARWo8VMNHfKbMbJiOQ=" Jan 28 07:45:57 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 07:45:57 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 07:45:57 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 07:45:57 volumio go-librespot[331]: time="2026-01-28T07:45:57+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 07:45:57 volumio go-librespot[331]: time="2026-01-28T07:45:57+07:00" level=debug msg="completed keyexchange" Jan 28 07:45:57 volumio go-librespot[331]: time="2026-01-28T07:45:57+07:00" level=debug msg="completed challenge" Jan 28 07:45:57 volumio go-librespot[331]: time="2026-01-28T07:45:57+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 07:45:57 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 07:45:57 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 07:45:58 volumio volumio[32559]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 28 07:45:58 volumio volumio[32559]: SPOTIFY: BQDOXj5MUpGhf5lBSSWzk1U6-cXwovVgpClIFig9qe6PlT8mZpLfn9c-DZ25vjmBKmwXjg0csedZcA1-6OGlJMZAnThG-9tuCKOex4VU4B5-T18Lqgrp9BM7kUvvTgKGaRULKGXgPPgfoItJaOrWGS9YOd02YrVY-rIhE7xGzd5hKX8aBlVUdd3CHtEggvX7GRYiBdnVgscTMa3UiSj0ZIvEtsDzyXpN9CINIepItlZnwQhpLDHG4UH32a0xQwbyVfIswFrm80IhrEIcwoV7ER3NNTNrt7DgF1hZah7UIZLjQLaTDaotZpnT Jan 28 07:45:58 volumio volumio[32559]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 28 07:45:58 volumio volumio[32559]: info: New Spotify access token = BQDOXj5MUpGhf5lBSSWzk1U6-cXwovVgpClIFig9qe6PlT8mZpLfn9c-DZ25vjmBKmwXjg0csedZcA1-6OGlJMZAnThG-9tuCKOex4VU4B5-T18Lqgrp9BM7kUvvTgKGaRULKGXgPPgfoItJaOrWGS9YOd02YrVY-rIhE7xGzd5hKX8aBlVUdd3CHtEggvX7GRYiBdnVgscTMa3UiSj0ZIvEtsDzyXpN9CINIepItlZnwQhpLDHG4UH32a0xQwbyVfIswFrm80IhrEIcwoV7ER3NNTNrt7DgF1hZah7UIZLjQLaTDaotZpnT Jan 28 07:45:58 volumio volumio[32559]: info: Spotify credentials grant success - running version from March 24, 2019 Jan 28 07:45:58 volumio volumio[32559]: info: Starting Shairport Sync Jan 28 07:45:58 volumio volumio[32559]: info: Starting Shairport Sync Jan 28 07:45:58 volumio volumio[32559]: info: Starting Shairport Sync Jan 28 07:45:58 volumio sudo[364]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 28 07:45:58 volumio sudo[364]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 07:45:58 volumio sudo[366]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 28 07:45:58 volumio sudo[366]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 07:45:58 volumio sudo[368]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 28 07:45:58 volumio sudo[368]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 07:45:58 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 28 07:45:58 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Jan 28 07:45:58 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 28 07:45:58 volumio systemd[1]: shairport-sync.service: Consumed 2.322s CPU time. Jan 28 07:45:58 volumio volumio[32559]: info: CoreCommandRouter::volumioGetState Jan 28 07:45:58 volumio volumio[32559]: info: CorePlayQueue::getTrack 0 Jan 28 07:45:58 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 28 07:45:58 volumio sudo[368]: pam_unix(sudo:session): session closed for user root Jan 28 07:45:58 volumio sudo[366]: pam_unix(sudo:session): session closed for user root Jan 28 07:45:58 volumio sudo[364]: pam_unix(sudo:session): session closed for user root Jan 28 07:45:58 volumio volumio[32559]: info: Shairport-Sync Started Jan 28 07:45:58 volumio volumio[32559]: Error adding Membership: Error: addMembership EINVAL Jan 28 07:45:58 volumio volumio[32559]: info: Shairport-Sync Started Jan 28 07:45:58 volumio volumio[32559]: info: Shairport-Sync Started Jan 28 07:45:59 volumio volumio[32559]: 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 07:45:59 volumio volumio[32559]: info: Spotify Successfully logged in Jan 28 07:45:59 volumio volumio[32559]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 07:45:59 volumio volumio[32559]: info: [1769561159078] CoreMusicLibrary::Adding element Spotify Jan 28 07:45:59 volumio volumio[32559]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 07:45:59 volumio volumio[32559]: Cannot find translation for source YouTube Music Jan 28 07:45:59 volumio volumio[32559]: Cannot find translation for source Spotify Jan 28 07:45:59 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 07:45:59 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 07:45:59 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 07:45:59 volumio volumio[32559]: info: [yt-cast-receiver] DIAL server listening on port 8098 Jan 28 07:45:59 volumio volumio[32559]: info: CoreCommandRouter::volumioRetrievevolume Jan 28 07:46:00 volumio volumio[32559]: info: VolumeController:: Volume=100 Mute =false Jan 28 07:46:00 volumio volumio[32559]: info: CoreCommandRouter::volumioGetState Jan 28 07:46:00 volumio volumio[32559]: info: CorePlayQueue::getTrack 0 Jan 28 07:46:00 volumio volumio[32559]: info: CoreStateMachine::pushState Jan 28 07:46:00 volumio volumio[32559]: info: CorePlayQueue::getTrack 0 Jan 28 07:46:00 volumio volumio[32559]: info: CoreCommandRouter::volumioPushState Jan 28 07:46:00 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Jan 28 07:46:00 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 07:46:01 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 07:46:01 volumio go-librespot[413]: go-librespot daemon starting... Jan 28 07:46:01 volumio go-librespot[414]: time="2026-01-28T07:46:01+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 07:46:01 volumio go-librespot[414]: time="2026-01-28T07:46:01+07:00" level=debug msg="app state loaded" Jan 28 07:46:01 volumio go-librespot[414]: time="2026-01-28T07:46:01+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 07:46:01 volumio volumio[32559]: info: go-librespot daemon successfully initialized Jan 28 07:46:01 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 07:46:01 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 07:46:01 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 07:46:01 volumio mpd[312]: 2026-01-28T07:46:01 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 28 07:46:01 volumio systemd[1]: Started mpd.service - Music Player Daemon. Jan 28 07:46:01 volumio sudo[32739]: pam_unix(sudo:session): session closed for user root Jan 28 07:46:01 volumio sudo[32750]: pam_unix(sudo:session): session closed for user root Jan 28 07:46:01 volumio go-librespot[414]: time="2026-01-28T07:46:01+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 07:46:01 volumio go-librespot[414]: time="2026-01-28T07:46:01+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 28 07:46:01 volumio go-librespot[414]: time="2026-01-28T07:46:01+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 28 07:46:01 volumio go-librespot[414]: time="2026-01-28T07:46:01+07:00" level=info msg="zeroconf server listening on port 46075" Jan 28 07:46:01 volumio volumio[32559]: error: MPD error: The expression evaluated to a falsy value: Jan 28 07:46:01 volumio volumio[32559]: assert.ok(self.idling) Jan 28 07:46:01 volumio volumio[32559]: error: The expression evaluated to a falsy value: Jan 28 07:46:01 volumio volumio[32559]: assert.ok(self.idling) Jan 28 07:46:01 volumio go-librespot[414]: time="2026-01-28T07:46:01+07:00" level=debug msg="obtained new client token: AAAUj+ZvcBDjnHX6/DTsd6+hOkXK3HzMqL66NEQYj+1fjQL4gO4eVN1fFxrawfgx99g8zvLrV1PhaTEUFzDiTx+0Ud2TW9IpT6o29fX1R7nVXmxG58NJOp9Futzksg+TPDseyshKriUpiRuDd+Lew0wEtIWv/c5wKgoql1BuxRxtRYZ3QNhi5ixaRXOjVKrWXOtn+oTCNtsRBusGPZam5YEwnS6YHKHPwbGY3oZMlYENu7xtyTMPIzXJrlk=" Jan 28 07:46:02 volumio volumio[32559]: info: Completed starting Core Plugins Jan 28 07:46:02 volumio volumio[32559]: info: ------------------------------------------- Jan 28 07:46:02 volumio volumio[32559]: info: ----- MyVolumio plugins startup ---- Jan 28 07:46:02 volumio volumio[32559]: info: ------------------------------------------- Jan 28 07:46:02 volumio volumio[32559]: info: [MyVolumio PluginManager] Fetching plans data.... Jan 28 07:46:02 volumio volumio[32559]: info: MPD running with PID312 Jan 28 07:46:02 volumio volumio[32559]: ,establishing connection Jan 28 07:46:02 volumio volumio[32559]: error: updateQueue error: null Jan 28 07:46:02 volumio volumio[32559]: error: updateQueue error: null Jan 28 07:46:02 volumio go-librespot[414]: time="2026-01-28T07:46:02+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 07:46:02 volumio go-librespot[414]: time="2026-01-28T07:46:02+07:00" level=debug msg="completed keyexchange" Jan 28 07:46:02 volumio go-librespot[414]: time="2026-01-28T07:46:02+07:00" level=debug msg="completed challenge" Jan 28 07:46:02 volumio go-librespot[414]: time="2026-01-28T07:46:02+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 07:46:02 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 07:46:02 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 07:46:03 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 07:46:03 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 07:46:03 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 07:46:04 volumio volumio[32559]: info: Initializing connection to go-librespot Websocket Jan 28 07:46:04 volumio volumio[32559]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 28 07:46:05 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Jan 28 07:46:05 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 07:46:05 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 07:46:05 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 07:46:05 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 07:46:05 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 07:46:05 volumio go-librespot[426]: go-librespot daemon starting... Jan 28 07:46:05 volumio go-librespot[427]: time="2026-01-28T07:46:05+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 07:46:05 volumio go-librespot[427]: time="2026-01-28T07:46:05+07:00" level=debug msg="app state loaded" Jan 28 07:46:05 volumio go-librespot[427]: time="2026-01-28T07:46:05+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 07:46:06 volumio go-librespot[427]: time="2026-01-28T07:46:06+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 28 07:46:06 volumio go-librespot[427]: time="2026-01-28T07:46:06+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 07:46:06 volumio go-librespot[427]: time="2026-01-28T07:46:06+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 07:46:06 volumio go-librespot[427]: time="2026-01-28T07:46:06+07:00" level=info msg="zeroconf server listening on port 33223" Jan 28 07:46:06 volumio go-librespot[427]: time="2026-01-28T07:46:06+07:00" level=debug msg="obtained new client token: AACqK0TEv7DkgmCOys/OOzPAApBKIg0d8qN2Dnjnv2+mAkqTsB926Lw1rDcs7sgukc5sRbXrkDY5DnrUiJnaHBwGdn5dn+E8lLu0KXs98bVyRHyKbtR3xcZfCXZXUeu9x3fsNjKsF1iX/qKoqy1id5tfWwH7ZF9zQtNWPtWPtcJXFS96oAyDyAFHeTI3gZhNIAp6CpNt1YZsk9xrfwd8Tgc5XkEmbPI/6P01PY0V2tUy6aAe+oY0A99hNqo=" Jan 28 07:46:06 volumio go-librespot[427]: time="2026-01-28T07:46:06+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 07:46:06 volumio go-librespot[427]: time="2026-01-28T07:46:06+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Jan 28 07:46:06 volumio go-librespot[427]: time="2026-01-28T07:46:06+07:00" level=debug msg="completed keyexchange" Jan 28 07:46:06 volumio go-librespot[427]: time="2026-01-28T07:46:06+07:00" level=debug msg="completed challenge" Jan 28 07:46:06 volumio go-librespot[427]: time="2026-01-28T07:46:06+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 07:46:06 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 07:46:06 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 07:46:06 volumio volumio[32559]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Jan 28 07:46:07 volumio volumio[32559]: info: Initializing connection to go-librespot Websocket Jan 28 07:46:07 volumio volumio[32559]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 28 07:46:07 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 07:46:07 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 07:46:07 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 07:46:09 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 07:46:09 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 07:46:09 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 07:46:09 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Jan 28 07:46:09 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 07:46:09 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 07:46:09 volumio go-librespot[438]: go-librespot daemon starting... Jan 28 07:46:09 volumio go-librespot[439]: time="2026-01-28T07:46:09+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 07:46:09 volumio go-librespot[439]: time="2026-01-28T07:46:09+07:00" level=debug msg="app state loaded" Jan 28 07:46:09 volumio go-librespot[439]: time="2026-01-28T07:46:09+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 07:46:10 volumio volumio[32559]: info: Initializing connection to go-librespot Websocket Jan 28 07:46:10 volumio go-librespot[439]: time="2026-01-28T07:46:10+07:00" level=debug msg="new websocket client" Jan 28 07:46:10 volumio volumio[32559]: info: Connection to go-librespot Websocket established Jan 28 07:46:10 volumio go-librespot[439]: time="2026-01-28T07:46:10+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 07:46:10 volumio go-librespot[439]: time="2026-01-28T07:46:10+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 28 07:46:10 volumio go-librespot[439]: time="2026-01-28T07:46:10+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 28 07:46:10 volumio go-librespot[439]: time="2026-01-28T07:46:10+07:00" level=info msg="zeroconf server listening on port 41259" Jan 28 07:46:10 volumio go-librespot[439]: time="2026-01-28T07:46:10+07:00" level=debug msg="obtained new client token: AAClaLgUaesueR8TuN7r85ya7cxCbwAcfQB4/rDY43uVgG6DS/hf22WULLFkhmktXCCcvtEukhvz3ovqA7zBeK1ua5v6/+hl2UG9CoiUpJidpHOZiIM2GO1Cs5Y/17XPsTPkGjSvbmBuaa72VpKfAUFKIUQLpr6YTzBd5ENUM4g6G76bxeSOVpnZOQV9JLcLN8uoK7ocyv3IWUlQkmxct5GZ1Y/WoTtgTHJ9v4BE03xrBMDem5WpajBFVlo=" Jan 28 07:46:10 volumio go-librespot[439]: time="2026-01-28T07:46:10+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 07:46:10 volumio go-librespot[439]: time="2026-01-28T07:46:10+07:00" level=debug msg="completed keyexchange" Jan 28 07:46:10 volumio go-librespot[439]: time="2026-01-28T07:46:10+07:00" level=debug msg="completed challenge" Jan 28 07:46:10 volumio volumio[32559]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Jan 28 07:46:10 volumio volumio[32559]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Jan 28 07:46:10 volumio volumio[32559]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Jan 28 07:46:10 volumio volumio[32559]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Jan 28 07:46:10 volumio volumio[32559]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Jan 28 07:46:10 volumio volumio[32559]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Jan 28 07:46:10 volumio volumio[32559]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Jan 28 07:46:10 volumio volumio[32559]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Jan 28 07:46:10 volumio volumio[32559]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Jan 28 07:46:10 volumio volumio[32559]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Jan 28 07:46:10 volumio volumio[32559]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Jan 28 07:46:10 volumio volumio[32559]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Jan 28 07:46:10 volumio volumio[32559]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Jan 28 07:46:10 volumio volumio[32559]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Jan 28 07:46:10 volumio volumio[32559]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Jan 28 07:46:10 volumio volumio[32559]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Jan 28 07:46:10 volumio volumio[32559]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Jan 28 07:46:10 volumio volumio[32559]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Jan 28 07:46:10 volumio volumio[32559]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Jan 28 07:46:10 volumio volumio[32559]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Jan 28 07:46:10 volumio volumio[32559]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Jan 28 07:46:10 volumio volumio[32559]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Jan 28 07:46:10 volumio volumio[32559]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Jan 28 07:46:10 volumio volumio[32559]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Jan 28 07:46:10 volumio volumio[32559]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Jan 28 07:46:10 volumio volumio[32559]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Jan 28 07:46:10 volumio volumio[32559]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Jan 28 07:46:10 volumio volumio[32559]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Jan 28 07:46:10 volumio volumio[32559]: info: Adding plugin bluetooth to MyMusic Plugins Jan 28 07:46:10 volumio volumio[32559]: info: Adding plugin multiroom to MyMusic Plugins Jan 28 07:46:10 volumio volumio[32559]: info: Adding plugin metavolumio to MyMusic Plugins Jan 28 07:46:10 volumio volumio[32559]: info: Adding plugin cd_controller to MyMusic Plugins Jan 28 07:46:10 volumio volumio[32559]: info: Adding plugin qobuzconnect to MyMusic Plugins Jan 28 07:46:10 volumio volumio[32559]: info: Adding plugin smart_inputs to MyMusic Plugins Jan 28 07:46:10 volumio volumio[32559]: info: Adding plugin tidalconnect to MyMusic Plugins Jan 28 07:46:10 volumio volumio[32559]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Jan 28 07:46:10 volumio go-librespot[439]: time="2026-01-28T07:46:10+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 07:46:10 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 07:46:10 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 07:46:11 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 07:46:11 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 07:46:11 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 07:46:12 volumio volumio[32559]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Jan 28 07:46:12 volumio volumio[32559]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Jan 28 07:46:12 volumio volumio[32559]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 07:46:12 volumio volumio[32559]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 07:46:12 volumio volumio[32559]: info: Starting MyVolumio Remote Streaming Endpoints Jan 28 07:46:12 volumio volumio[32559]: info: MyVolumio login type: Token Jan 28 07:46:12 volumio volumio[32559]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Jan 28 07:46:12 volumio volumio[32559]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Jan 28 07:46:13 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 07:46:13 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 07:46:13 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 07:46:13 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Jan 28 07:46:13 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 07:46:14 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 07:46:14 volumio go-librespot[460]: go-librespot daemon starting... Jan 28 07:46:14 volumio go-librespot[461]: time="2026-01-28T07:46:14+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 07:46:14 volumio go-librespot[461]: time="2026-01-28T07:46:14+07:00" level=debug msg="app state loaded" Jan 28 07:46:14 volumio go-librespot[461]: time="2026-01-28T07:46:14+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 07:46:14 volumio volumio[32559]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Jan 28 07:46:14 volumio volumio[32559]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Jan 28 07:46:14 volumio volumio[32559]: info: Streaming services startup Jan 28 07:46:14 volumio volumio[32559]: info: Starting Streaming Daemon Jan 28 07:46:14 volumio sudo[469]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jan 28 07:46:14 volumio sudo[469]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 07:46:14 volumio volumio[32559]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Jan 28 07:46:14 volumio go-librespot[461]: time="2026-01-28T07:46:14+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 07:46:14 volumio go-librespot[461]: time="2026-01-28T07:46:14+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 28 07:46:14 volumio go-librespot[461]: time="2026-01-28T07:46:14+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 28 07:46:14 volumio go-librespot[461]: time="2026-01-28T07:46:14+07:00" level=info msg="zeroconf server listening on port 45475" Jan 28 07:46:14 volumio sudo[469]: pam_unix(sudo:session): session closed for user root Jan 28 07:46:14 volumio volumio[32559]: info: Getting Spotify volume Jan 28 07:46:14 volumio volumio[32559]: info: Connection to go-librespot Websocket closed Jan 28 07:46:14 volumio volumio[32559]: error: Cannot start Volumio Streaming Daemon Jan 28 07:46:14 volumio volumio[32559]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Jan 28 07:46:14 volumio volumio[32559]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Jan 28 07:46:14 volumio volumio[32559]: 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 07:46:14 volumio go-librespot[461]: time="2026-01-28T07:46:14+07:00" level=debug msg="obtained new client token: AADugP4I3snAVBwrJqGuDN1U9ZGfW6y4lTtZxFWXvSskY8yzA2DNDYzA7oKNuolaGcLAbAho47W7Rf/iWpSYalYimf/bSQT17oTxmaRJZJLRCmKAJxl3FeK+HAEIXujfmanxUQ6WBFvuhBxQlK/YBXqw+IwEEVQyZ9KPAPwJ5dY8xhzQguvCXwwg6vPEKxGRsyFl2Z0I56DSTuIJI7T1KqCDAGO8xDE6GnVlyZfqEKRn9s8As//RJcr3hg4=" Jan 28 07:46:14 volumio volumio[32559]: info: CoreCommandRouter::volumioGetState Jan 28 07:46:14 volumio volumio[32559]: info: CorePlayQueue::getTrack 0 Jan 28 07:46:15 volumio volumio[32559]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jan 28 07:46:15 volumio volumio[32559]: SPOTIFY: SPOTIFY VOLUME undefined Jan 28 07:46:15 volumio volumio[32559]: SPOTIFY: VOLUMIO VOLUME 100 Jan 28 07:46:15 volumio volumio[32559]: info: Aligning Spotify Volume to Volumio Volume Jan 28 07:46:15 volumio volumio[32559]: info: CoreCommandRouter::volumioGetState Jan 28 07:46:15 volumio volumio[32559]: info: CorePlayQueue::getTrack 0 Jan 28 07:46:15 volumio volumio[32559]: info: Setting Spotify Volume from Volumio: 100 Jan 28 07:46:15 volumio go-librespot[461]: time="2026-01-28T07:46:15+07:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:4070, retrying with a different AP" error="dial tcp 104.199.241.202:4070: connect: connection refused" Jan 28 07:46:15 volumio go-librespot[461]: time="2026-01-28T07:46:15+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Jan 28 07:46:15 volumio go-librespot[461]: time="2026-01-28T07:46:15+07:00" level=debug msg="completed keyexchange" Jan 28 07:46:15 volumio go-librespot[461]: time="2026-01-28T07:46:15+07:00" level=debug msg="completed challenge" Jan 28 07:46:15 volumio go-librespot[461]: time="2026-01-28T07:46:15+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 07:46:15 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 07:46:15 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 07:46:15 volumio volumio[32559]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 28 07:46:15 volumio volumio[32559]: Error: socket hang up Jan 28 07:46:15 volumio volumio[32559]: at connResetException (node:internal/errors:720:14) Jan 28 07:46:15 volumio volumio[32559]: at Socket.socketOnEnd (node:_http_client:519:23) Jan 28 07:46:15 volumio volumio[32559]: at Socket.emit (node:events:526:35) Jan 28 07:46:15 volumio volumio[32559]: at endReadableNT (node:internal/streams/readable:1376:12) Jan 28 07:46:15 volumio volumio[32559]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Jan 28 07:46:15 volumio volumio[32559]: code: 'ECONNRESET', Jan 28 07:46:15 volumio volumio[32559]: response: undefined Jan 28 07:46:15 volumio volumio[32559]: } Jan 28 07:46:15 volumio volumio[32559]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 28 07:46:15 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 07:46:15 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 07:46:15 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 07:46:16 volumio sudo[491]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-01-28 07:45' Jan 28 07:46:16 volumio sudo[491]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 07:46:17 volumio sudo[491]: pam_unix(sudo:session): session closed for user root Jan 28 07:46:17 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Jan 28 07:46:17 volumio volumio-remote-updater[628]: [2026-01-28 07:46:17] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Jan 28 07:46:17 volumio volumio-remote-updater[628]: [2026-01-28 07:46:17] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Jan 28 07:46:17 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Jan 28 07:46:17 volumio systemd[1]: volumio.service: Consumed 59.183s CPU time. Jan 28 07:46:17 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 28 07:46:17 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Jan 28 07:46:17 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 9814. Jan 28 07:46:17 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 28 07:46:17 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Jan 28 07:46:17 volumio systemd[1]: volumio.service: Consumed 59.183s CPU time. Jan 28 07:46:17 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Jan 28 07:46:17 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Jan 28 07:46:17 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 07:46:17 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 07:46:17 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 07:46:18 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Jan 28 07:46:18 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 07:46:18 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 07:46:18 volumio go-librespot[525]: go-librespot daemon starting... Jan 28 07:46:18 volumio go-librespot[526]: time="2026-01-28T07:46:18+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 07:46:18 volumio go-librespot[526]: time="2026-01-28T07:46:18+07:00" level=debug msg="app state loaded" Jan 28 07:46:18 volumio go-librespot[526]: time="2026-01-28T07:46:18+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 07:46:19 volumio go-librespot[526]: time="2026-01-28T07:46:19+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 28 07:46:19 volumio go-librespot[526]: time="2026-01-28T07:46:19+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Jan 28 07:46:19 volumio go-librespot[526]: time="2026-01-28T07:46:19+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Jan 28 07:46:19 volumio go-librespot[526]: time="2026-01-28T07:46:19+07:00" level=info msg="zeroconf server listening on port 44817" Jan 28 07:46:19 volumio go-librespot[526]: time="2026-01-28T07:46:19+07:00" level=debug msg="obtained new client token: AAAOglIAI+sA/czrf4Qe9ruvUKSV3rxiu2yTdlLVsWdchVShlC1MqKdBmUj6N7Gb9jvB18QCtgMOO+GnEJDXYvgoUilGX46pwp1j0mxvrDyXPnvsZICR6AUNpshxRGpYzVaJGHHGk4thRdE6uBonLeZveHsNZhsCe6MdrMoJAy0RtjDfu3EkXEz46RgC31IVJm93VyynsIIOamGim/Xg++uyGo4+uJBYNR7Wh+g5F4DWhRWe0cdbWjTizlY=" Jan 28 07:46:19 volumio go-librespot[526]: time="2026-01-28T07:46:19+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 07:46:19 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 07:46:19 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 07:46:19 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 07:46:19 volumio go-librespot[526]: time="2026-01-28T07:46:19+07:00" level=debug msg="completed keyexchange" Jan 28 07:46:19 volumio go-librespot[526]: time="2026-01-28T07:46:19+07:00" level=debug msg="completed challenge" Jan 28 07:46:19 volumio go-librespot[526]: time="2026-01-28T07:46:19+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 07:46:19 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 07:46:19 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 07:46:21 volumio volumio[509]: info: ------------------------------------------- Jan 28 07:46:21 volumio volumio[509]: info: ----- Volumio3 ---- Jan 28 07:46:21 volumio volumio[509]: info: ------------------------------------------- Jan 28 07:46:21 volumio volumio[509]: info: ----- System startup ---- Jan 28 07:46:21 volumio volumio[509]: info: ------------------------------------------- Jan 28 07:46:21 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 07:46:21 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 07:46:21 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 07:46:22 volumio volumio-remote-updater[628]: [2026-01-28 07:46:22] [connect] Successful connection Jan 28 07:46:22 volumio volumio[509]: info: MYVOLUMIO Environment detected Jan 28 07:46:22 volumio volumio[509]: info: Plugin folders cleanup Jan 28 07:46:22 volumio volumio[509]: info: Scanning into folder /volumio/app/plugins/ Jan 28 07:46:22 volumio volumio[509]: info: Scanning category audio_interface Jan 28 07:46:22 volumio volumio[509]: info: Scanning category miscellanea Jan 28 07:46:22 volumio volumio[509]: info: Scanning category music_service Jan 28 07:46:22 volumio volumio[509]: info: Scanning category plugins.json Jan 28 07:46:22 volumio volumio[509]: info: Scanning category system_controller Jan 28 07:46:22 volumio volumio[509]: info: Scanning category user_interface Jan 28 07:46:22 volumio volumio[509]: info: Scanning into folder /data/plugins/ Jan 28 07:46:22 volumio volumio[509]: info: Scanning category music_service Jan 28 07:46:22 volumio volumio[509]: info: Plugin folders cleanup completed Jan 28 07:46:22 volumio volumio[509]: info: ------------------------------------------- Jan 28 07:46:22 volumio volumio[509]: info: ----- Core plugins startup ---- Jan 28 07:46:22 volumio volumio[509]: info: ------------------------------------------- Jan 28 07:46:22 volumio volumio[509]: info: Loading plugins from folder /volumio/app/plugins/ Jan 28 07:46:22 volumio volumio[509]: info: Adding plugin upnp to MyMusic Plugins Jan 28 07:46:22 volumio volumio[509]: info: Adding plugin airplay_emulation to MyMusic Plugins Jan 28 07:46:22 volumio volumio[509]: info: Adding plugin upnp_browser to MyMusic Plugins Jan 28 07:46:22 volumio volumio[509]: info: Loading plugins from folder /data/plugins/ Jan 28 07:46:22 volumio volumio[509]: info: Loading plugin "system"... Jan 28 07:46:22 volumio volumio[509]: info: Loading plugin "appearance"... Jan 28 07:46:22 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Jan 28 07:46:22 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 07:46:23 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 07:46:23 volumio go-librespot[545]: go-librespot daemon starting... Jan 28 07:46:23 volumio go-librespot[546]: time="2026-01-28T07:46:23+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 07:46:23 volumio go-librespot[546]: time="2026-01-28T07:46:23+07:00" level=debug msg="app state loaded" Jan 28 07:46:23 volumio go-librespot[546]: time="2026-01-28T07:46:23+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 07:46:23 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 07:46:23 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 07:46:23 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 07:46:23 volumio go-librespot[546]: time="2026-01-28T07:46:23+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 07:46:23 volumio go-librespot[546]: time="2026-01-28T07:46:23+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 28 07:46:23 volumio go-librespot[546]: time="2026-01-28T07:46:23+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 28 07:46:23 volumio go-librespot[546]: time="2026-01-28T07:46:23+07:00" level=info msg="zeroconf server listening on port 33107" Jan 28 07:46:23 volumio go-librespot[546]: time="2026-01-28T07:46:23+07:00" level=debug msg="obtained new client token: AAD9yAf9QDnJ61BD3CpG5EjSxp7u5o9FCfX+IY+bFtCc5qURdh3ohsn3vXUYyY8+y7PRyTLT+ke4oPCx79aNackoL1XtDYWtuhRLZ4I40EQSPVEpgcagQl0OzjyReuiSaqLcPNjU/V3qcN8lqUVPNsFohK6WlIHsFuD74Yd0NZpzq/P/U7QObgDsf6qQpHVwccz3it6qW2bKJ7pXPtMWGouI/ljV+aHokbthX4ZFFg9E+qHJViKYpqmFrdc=" Jan 28 07:46:24 volumio go-librespot[546]: time="2026-01-28T07:46:24+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 07:46:24 volumio go-librespot[546]: time="2026-01-28T07:46:24+07:00" level=debug msg="completed keyexchange" Jan 28 07:46:24 volumio go-librespot[546]: time="2026-01-28T07:46:24+07:00" level=debug msg="completed challenge" Jan 28 07:46:24 volumio go-librespot[546]: time="2026-01-28T07:46:24+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 07:46:24 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 07:46:24 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 07:46:24 volumio volumio[509]: info: Loading plugin "network"... Jan 28 07:46:24 volumio volumio[509]: info: Refreshing Cached IP Addresses Jan 28 07:46:24 volumio sudo[554]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 28 07:46:24 volumio sudo[554]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 07:46:24 volumio sudo[556]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 28 07:46:24 volumio sudo[554]: pam_unix(sudo:session): session closed for user root Jan 28 07:46:24 volumio sudo[556]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 07:46:24 volumio volumio[509]: info: Loading plugin "services"... Jan 28 07:46:24 volumio volumio[509]: info: Loading plugin "alsa_controller"... Jan 28 07:46:24 volumio sudo[556]: pam_unix(sudo:session): session closed for user root Jan 28 07:46:24 volumio sudo[566]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Jan 28 07:46:24 volumio sudo[566]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 07:46:24 volumio volumio[509]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 28 07:46:24 volumio volumio[509]: info: Loading plugin "wizard"... Jan 28 07:46:24 volumio volumio[509]: info: Loading plugin "networkfs"... Jan 28 07:46:24 volumio volumio[509]: info: Starting Udev Watcher for removable devices Jan 28 07:46:24 volumio volumio[509]: info: Ignoring mount for partition: boot Jan 28 07:46:24 volumio volumio[509]: info: Ignoring mount for partition: volumio Jan 28 07:46:24 volumio volumio[509]: info: Ignoring mount for partition: volumio_data Jan 28 07:46:24 volumio volumio[509]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 28 07:46:24 volumio volumio[509]: info: Loading plugin "volumio_command_line_client"... Jan 28 07:46:25 volumio volumio[509]: info: Loading plugin "upnp"... Jan 28 07:46:25 volumio volumio[509]: info: [1769561185014] Starting Upmpd Daemon Jan 28 07:46:25 volumio volumio[509]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 28 07:46:25 volumio volumio[509]: info: Loading plugin "my_music"... Jan 28 07:46:25 volumio volumio[509]: info: Loading plugin "mpd"... Jan 28 07:46:25 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 07:46:25 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 07:46:25 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 07:46:25 volumio volumio[509]: info: Loading plugin "upnp_browser"... Jan 28 07:46:27 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Jan 28 07:46:27 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 07:46:27 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 07:46:27 volumio go-librespot[590]: go-librespot daemon starting... Jan 28 07:46:27 volumio go-librespot[591]: time="2026-01-28T07:46:27+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 07:46:27 volumio go-librespot[591]: time="2026-01-28T07:46:27+07:00" level=debug msg="app state loaded" Jan 28 07:46:27 volumio go-librespot[591]: time="2026-01-28T07:46:27+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 07:46:27 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 07:46:27 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 07:46:27 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 07:46:27 volumio sudo[566]: pam_unix(sudo:session): session closed for user root Jan 28 07:46:27 volumio go-librespot[591]: time="2026-01-28T07:46:27+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 07:46:27 volumio go-librespot[591]: time="2026-01-28T07:46:27+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 07:46:27 volumio go-librespot[591]: time="2026-01-28T07:46:27+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 07:46:27 volumio go-librespot[591]: time="2026-01-28T07:46:27+07:00" level=info msg="zeroconf server listening on port 46695" Jan 28 07:46:28 volumio go-librespot[591]: time="2026-01-28T07:46:28+07:00" level=debug msg="obtained new client token: AABfex61z05YI1NDAj/TMAWTXQEYALak4XzlQBpdcBzhIA8XNKhcuwJIQMrwX1Kzzhjkt3ewB3a7h2mNn0Q9pn8Zqa498+ay0eCCXnGzlAdqCdWBthObajc24BKFUE6cRWggjCnfbzPLEKWwsn84k7/l2mm1dO99aqmiRkejzJ7SbheFNKI2lQIz4xvz8d0TXH7n9B4BMJcr73Wp3xBSg0AWlDdm+e+SqjG/LL/LYU75NPLr41jJ+CH8" Jan 28 07:46:28 volumio go-librespot[591]: time="2026-01-28T07:46:28+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 07:46:28 volumio go-librespot[591]: time="2026-01-28T07:46:28+07:00" level=debug msg="completed keyexchange" Jan 28 07:46:28 volumio go-librespot[591]: time="2026-01-28T07:46:28+07:00" level=debug msg="completed challenge" Jan 28 07:46:28 volumio go-librespot[591]: time="2026-01-28T07:46:28+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 07:46:28 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 07:46:28 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 07:46:28 volumio volumio[509]: info: Starting UPNP Browser Jan 28 07:46:28 volumio volumio[509]: info: Loading plugin "alarm-clock"... Jan 28 07:46:28 volumio volumio[509]: info: Loading plugin "airplay_emulation"... Jan 28 07:46:28 volumio volumio[509]: info: Starting Shairport Sync Jan 28 07:46:28 volumio volumio[509]: info: Loading plugin "last_100"... Jan 28 07:46:28 volumio volumio[509]: info: Loading plugin "webradio"... Jan 28 07:46:29 volumio volumio[509]: info: Loading plugin "i2s_dacs"... Jan 28 07:46:29 volumio volumio[509]: info: Loading plugin "volumiodiscovery"... Jan 28 07:46:29 volumio volumio[509]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 28 07:46:29 volumio volumio[509]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 07:46:29 volumio volumio[509]: *** WARNING *** For more information see Jan 28 07:46:29 volumio volumio[509]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 28 07:46:29 volumio volumio[509]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 07:46:29 volumio volumio[509]: *** WARNING *** For more information see Jan 28 07:46:29 volumio node[509]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 28 07:46:29 volumio node[509]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 07:46:29 volumio node[509]: *** WARNING *** For more information see Jan 28 07:46:29 volumio node[509]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 28 07:46:29 volumio node[509]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 07:46:29 volumio node[509]: *** WARNING *** For more information see Jan 28 07:46:29 volumio volumio[509]: info: Applying required configuration parameters for plugin volumiodiscovery Jan 28 07:46:29 volumio volumio[509]: info: Discovery: Started advertising with name: Volumio Jan 28 07:46:29 volumio volumio[509]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 28 07:46:29 volumio volumio[509]: info: Loading plugin "spop"... Jan 28 07:46:29 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 07:46:29 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 07:46:29 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 07:46:31 volumio volumio[509]: info: Loading plugin "ytcr"... Jan 28 07:46:31 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 07:46:31 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 07:46:31 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 07:46:31 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Jan 28 07:46:31 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 07:46:31 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 07:46:31 volumio go-librespot[602]: go-librespot daemon starting... Jan 28 07:46:31 volumio go-librespot[603]: time="2026-01-28T07:46:31+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 07:46:31 volumio go-librespot[603]: time="2026-01-28T07:46:31+07:00" level=debug msg="app state loaded" Jan 28 07:46:31 volumio go-librespot[603]: time="2026-01-28T07:46:31+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 07:46:32 volumio go-librespot[603]: time="2026-01-28T07:46:32+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 07:46:32 volumio go-librespot[603]: time="2026-01-28T07:46:32+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 28 07:46:32 volumio go-librespot[603]: time="2026-01-28T07:46:32+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 28 07:46:32 volumio go-librespot[603]: time="2026-01-28T07:46:32+07:00" level=info msg="zeroconf server listening on port 35107" Jan 28 07:46:32 volumio go-librespot[603]: time="2026-01-28T07:46:32+07:00" level=debug msg="obtained new client token: AABw4cAAWIpSt6DY2dP9Tr57JZKlcZganx5NFg42tMk/28/9OGCHzTs6eTjDh9hJnIAX4uCZ3/zacieB9yxY6O7jK0LKXQJJ1U6hKxKQ0O1msnfAgfIk96b7hHSD/ywE2luDiKgL4T/KB6l8GyQbDdgHBXtGQGJmBj80WVAh7hlTdOd313mZpth5FeNxbB/+k9bMpxh1bjj+d633xLAKIwwjkCc4rzjxIC6BC0lb98GJiXu+R/j2Ovdq9Qw=" Jan 28 07:46:32 volumio go-librespot[603]: time="2026-01-28T07:46:32+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 07:46:32 volumio go-librespot[603]: time="2026-01-28T07:46:32+07:00" level=debug msg="completed keyexchange" Jan 28 07:46:32 volumio go-librespot[603]: time="2026-01-28T07:46:32+07:00" level=debug msg="completed challenge" Jan 28 07:46:32 volumio go-librespot[603]: time="2026-01-28T07:46:32+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 07:46:32 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 07:46:32 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 07:46:33 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 07:46:33 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 07:46:33 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 07:46:33 volumio volumio[509]: info: Loading plugin "ytmusic"... Jan 28 07:46:34 volumio volumio-remote-updater[628]: [2026-01-28 07:46:34] [connect] Successful connection Jan 28 07:46:34 volumio volumio[509]: info: Loading plugin "outputs"... Jan 28 07:46:34 volumio volumio[509]: info: Loading plugin "albumart"... Jan 28 07:46:34 volumio volumio[509]: info: Plugin example_plugin is not enabled Jan 28 07:46:34 volumio volumio[509]: info: Loading plugin "inputs"... Jan 28 07:46:34 volumio volumio[509]: info: Loading plugin "updater_comm"... Jan 28 07:46:35 volumio volumio[509]: info: Plugin mpdemulation is not enabled Jan 28 07:46:35 volumio volumio[509]: info: Loading plugin "rest_api"... Jan 28 07:46:35 volumio volumio[509]: info: Loading plugin "websocket"... Jan 28 07:46:35 volumio volumio[509]: info: Starting Socket.io Server version 1.7.4 Jan 28 07:46:35 volumio volumio[509]: info: Loading plugin "RoonBridge"... Jan 28 07:46:35 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 07:46:35 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 07:46:35 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 07:46:35 volumio volumio[509]: info: Applying required configuration parameters for plugin RoonBridge Jan 28 07:46:35 volumio volumio[509]: info: Loading i18n strings for locale en Jan 28 07:46:35 volumio volumio[509]: Updating browse sources language Jan 28 07:46:35 volumio volumio[509]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 07:46:35 volumio volumio[629]: Forking 3 albumart workers Jan 28 07:46:35 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Jan 28 07:46:35 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 07:46:36 volumio volumio[509]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 28 07:46:36 volumio volumio[509]: info: CoreCommandRouter::initPlayerControls Jan 28 07:46:36 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 07:46:36 volumio go-librespot[664]: go-librespot daemon starting... Jan 28 07:46:36 volumio volumio[509]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 07:46:36 volumio volumio[509]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 07:46:36 volumio volumio[509]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 07:46:36 volumio volumio[509]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 07:46:36 volumio volumio[509]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 07:46:36 volumio volumio[509]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 07:46:36 volumio volumio[509]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 07:46:36 volumio volumio[509]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 07:46:36 volumio volumio[509]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 28 07:46:36 volumio go-librespot[667]: time="2026-01-28T07:46:36+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 07:46:36 volumio go-librespot[667]: time="2026-01-28T07:46:36+07:00" level=debug msg="app state loaded" Jan 28 07:46:36 volumio go-librespot[667]: time="2026-01-28T07:46:36+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 07:46:36 volumio volumio[509]: Express server listening on port 3000 Jan 28 07:46:36 volumio volumio[509]: [Metrics] WebUI: 15s 988.58ms Jan 28 07:46:36 volumio volumio[509]: info: CoreStateMachine::resetVolumioState Jan 28 07:46:36 volumio volumio[509]: info: CoreStateMachine::getcurrentVolume Jan 28 07:46:36 volumio volumio[509]: info: CoreCommandRouter::volumioRetrievevolume Jan 28 07:46:36 volumio sudo[691]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 28 07:46:36 volumio sudo[691]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 07:46:36 volumio sudo[691]: pam_unix(sudo:session): session closed for user root Jan 28 07:46:36 volumio sudo[689]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 28 07:46:36 volumio sudo[689]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 07:46:36 volumio sudo[689]: pam_unix(sudo:session): session closed for user root Jan 28 07:46:36 volumio volumio[509]: info: Volumio Network Manager: Network status updated: 1 Jan 28 07:46:36 volumio go-librespot[667]: time="2026-01-28T07:46:36+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 07:46:36 volumio go-librespot[667]: time="2026-01-28T07:46:36+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 28 07:46:36 volumio go-librespot[667]: time="2026-01-28T07:46:36+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 28 07:46:36 volumio go-librespot[667]: time="2026-01-28T07:46:36+07:00" level=info msg="zeroconf server listening on port 40981" Jan 28 07:46:36 volumio volumio[509]: info: VolumeController:: Volume=100 Mute =false Jan 28 07:46:36 volumio volumio[509]: info: CoreStateMachine::pushState Jan 28 07:46:36 volumio volumio[509]: info: CorePlayQueue::getTrack 0 Jan 28 07:46:36 volumio volumio[509]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 28 07:46:36 volumio volumio[509]: info: CoreCommandRouter::volumioPushState Jan 28 07:46:36 volumio volumio[509]: info: CoreStateMachine::updateTrackBlock Jan 28 07:46:36 volumio volumio[509]: info: CorePlayQueue::getTrackBlock Jan 28 07:46:36 volumio volumio[509]: info: CoreCommandRouter::volumioRetrievevolume Jan 28 07:46:36 volumio volumio-remote-updater[628]: [2026-01-28 07:46:36] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1769561194 101 Jan 28 07:46:36 volumio go-librespot[667]: time="2026-01-28T07:46:36+07:00" level=debug msg="obtained new client token: AAAag+0P1NnwkXXkXjlzlTMcR30yOej51xJnAAgn93oIr1FunJr4ebZlVckfuo3vNZH7rBvE093M+KNtGv6+saQTIdHlalLi++aVO9pbbM7myzel9HyIZaFy+3DEteilmsqXxbXM5zm+sF4KPjx6n4inn8vVlwB3aJ5w+vmMft6vz8FtReX44heHC1CoVlELgztm1J2/KXk1LFVQ69WSCGkWoFKjVTk9NUk7WILiydaTBZtcaFqhcEHM2NY=" Jan 28 07:46:37 volumio volumio[509]: 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 07:46:37 volumio go-librespot[667]: time="2026-01-28T07:46:37+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 07:46:37 volumio volumio[509]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 07:46:37 volumio volumio[509]: info: Reloading queue from file Jan 28 07:46:37 volumio volumio[509]: info: CoreStateMachine::setRepeat null single undefined Jan 28 07:46:37 volumio volumio[509]: info: CoreStateMachine::pushState Jan 28 07:46:37 volumio volumio[509]: info: CorePlayQueue::getTrack 0 Jan 28 07:46:37 volumio volumio[509]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 28 07:46:37 volumio volumio[509]: info: CoreCommandRouter::volumioPushState Jan 28 07:46:37 volumio volumio[509]: info: CoreStateMachine::setRandom null Jan 28 07:46:37 volumio volumio[509]: info: CoreStateMachine::pushState Jan 28 07:46:37 volumio volumio[509]: info: CorePlayQueue::getTrack 0 Jan 28 07:46:37 volumio volumio[509]: info: CoreCommandRouter::volumioPushState Jan 28 07:46:37 volumio go-librespot[667]: time="2026-01-28T07:46:37+07:00" level=debug msg="completed keyexchange" Jan 28 07:46:37 volumio go-librespot[667]: time="2026-01-28T07:46:37+07:00" level=debug msg="completed challenge" Jan 28 07:46:37 volumio volumio[509]: info: Setting Device type: Raspberry PI Jan 28 07:46:37 volumio volumio[509]: info: Completed loading Core Plugins Jan 28 07:46:37 volumio volumio[509]: info: Preparing to generate the ALSA configuration file Jan 28 07:46:37 volumio go-librespot[667]: time="2026-01-28T07:46:37+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 07:46:37 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 07:46:37 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 07:46:37 volumio volumio[509]: info: VolumeController:: Volume=100 Mute =false Jan 28 07:46:37 volumio volumio[509]: info: CoreStateMachine::pushState Jan 28 07:46:37 volumio volumio[509]: info: CorePlayQueue::getTrack 0 Jan 28 07:46:37 volumio volumio[509]: info: CoreCommandRouter::volumioPushState Jan 28 07:46:37 volumio volumio[509]: info: Asound.conf file unchanged, so no further update is needed Jan 28 07:46:37 volumio volumio[509]: info: Output device has changed, restarting MPD Jan 28 07:46:37 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 07:46:37 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 07:46:37 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 07:46:37 volumio sudo[709]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Jan 28 07:46:37 volumio sudo[709]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 07:46:37 volumio volumio[509]: info: Output device has changed, restarting Shairport Sync Jan 28 07:46:37 volumio volumio[509]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 07:46:37 volumio volumio[509]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 07:46:37 volumio sudo[711]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 28 07:46:37 volumio sudo[714]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 28 07:46:37 volumio sudo[714]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 07:46:37 volumio sudo[711]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 07:46:37 volumio sudo[709]: pam_unix(sudo:session): session closed for user root Jan 28 07:46:37 volumio sudo[711]: pam_unix(sudo:session): session closed for user root Jan 28 07:46:37 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Jan 28 07:46:37 volumio volumio[509]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 28 07:46:37 volumio volumio[509]: info: ___________ START PLUGINS ___________ Jan 28 07:46:37 volumio volumio[509]: info: ControllerMpd::onStart: Initializing MPD Jan 28 07:46:37 volumio volumio[509]: info: Creating MPD Configuration file Jan 28 07:46:37 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 28 07:46:37 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 28 07:46:37 volumio systemd[1]: mpd.service: Consumed 7.470s CPU time. Jan 28 07:46:37 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 28 07:46:37 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 28 07:46:37 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 28 07:46:37 volumio volumio[509]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 28 07:46:37 volumio volumio[509]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 07:46:37 volumio volumio[509]: info: [1769561197934] CoreMusicLibrary::Adding element Media Servers Jan 28 07:46:37 volumio volumio[509]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 07:46:37 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 28 07:46:37 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 28 07:46:37 volumio volumio[509]: info: UPNP Browser: Client initialized successfully Jan 28 07:46:38 volumio sudo[723]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 28 07:46:38 volumio sudo[723]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 07:46:38 volumio sudo[723]: pam_unix(sudo:session): session closed for user root Jan 28 07:46:38 volumio sudo[725]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 28 07:46:38 volumio sudo[725]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 07:46:38 volumio volumio[509]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 07:46:38 volumio volumio[509]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 07:46:38 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 28 07:46:38 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 28 07:46:38 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 28 07:46:38 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 28 07:46:38 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 28 07:46:38 volumio volumio[509]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 28 07:46:38 volumio volumio[509]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 07:46:38 volumio volumio[509]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 07:46:38 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 28 07:46:38 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 28 07:46:38 volumio volumio[509]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 28 07:46:38 volumio volumio[509]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 07:46:38 volumio volumio[509]: info: [1769561198304] CoreMusicLibrary::Adding element Last_100 Jan 28 07:46:38 volumio volumio[509]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 07:46:38 volumio volumio[509]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 07:46:38 volumio volumio[509]: info: [1769561198323] CoreMusicLibrary::Adding element Webradio Jan 28 07:46:38 volumio volumio[509]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 07:46:38 volumio volumio[509]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 28 07:46:38 volumio volumio[509]: info: Initializing BBC Radios Jan 28 07:46:38 volumio volumio[509]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 28 07:46:38 volumio volumio[509]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 07:46:38 volumio volumio[509]: info: Creating Spotify config file Jan 28 07:46:38 volumio volumio[509]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 07:46:38 volumio sudo[738]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 28 07:46:38 volumio sudo[738]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jan 28 07:46:38 volumio sudo[738]: pam_unix(sudo:session): session closed for user root Jan 28 07:46:39 volumio volumio[642]: Starting albumart workers Jan 28 07:46:39 volumio volumio[641]: Starting albumart workers Jan 28 07:46:39 volumio volumio[643]: Starting albumart workers Jan 28 07:46:39 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 07:46:39 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 07:46:39 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 07:46:39 volumio volumio[509]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 07:46:39 volumio volumio[509]: info: [1769561199680] CoreMusicLibrary::Adding element YouTube Music Jan 28 07:46:39 volumio volumio[509]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 07:46:39 volumio volumio[509]: Cannot find translation for source YouTube Music Jan 28 07:46:39 volumio volumio[509]: info: Volumio Calling Home Jan 28 07:46:39 volumio sudo[763]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Jan 28 07:46:39 volumio sudo[763]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 07:46:40 volumio sudo[763]: pam_unix(sudo:session): session closed for user root Jan 28 07:46:40 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Jan 28 07:46:40 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 07:46:40 volumio volumio[509]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Jan 28 07:46:40 volumio volumio[509]: info: Discovery: Found device Volumio Jan 28 07:46:40 volumio volumio[509]: info: CoreCommandRouter::volumioGetState Jan 28 07:46:40 volumio volumio[509]: info: CorePlayQueue::getTrack 0 Jan 28 07:46:40 volumio volumio[509]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Jan 28 07:46:40 volumio volumio[509]: info: Discovery: Found device Volumio Jan 28 07:46:40 volumio volumio[509]: info: CoreCommandRouter::volumioGetState Jan 28 07:46:40 volumio volumio[509]: info: CorePlayQueue::getTrack 0 Jan 28 07:46:40 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 07:46:40 volumio go-librespot[770]: go-librespot daemon starting... Jan 28 07:46:40 volumio volumio[509]: info: MPD Permissions set Jan 28 07:46:40 volumio volumio[509]: info: MPD Permissions set Jan 28 07:46:40 volumio volumio[509]: info: Upmpdcli Daemon Started Jan 28 07:46:40 volumio go-librespot[771]: time="2026-01-28T07:46:40+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 07:46:40 volumio go-librespot[771]: time="2026-01-28T07:46:40+07:00" level=debug msg="app state loaded" Jan 28 07:46:40 volumio go-librespot[771]: time="2026-01-28T07:46:40+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 07:46:40 volumio volumio[509]: info: Volumio called home Jan 28 07:46:40 volumio volumio[509]: info: Spotify config file written Jan 28 07:46:41 volumio sudo[778]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jan 28 07:46:41 volumio sudo[778]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 07:46:41 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Jan 28 07:46:41 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Jan 28 07:46:41 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 07:46:41 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 07:46:41 volumio go-librespot[787]: go-librespot daemon starting... Jan 28 07:46:41 volumio sudo[778]: pam_unix(sudo:session): session closed for user root Jan 28 07:46:41 volumio go-librespot[788]: time="2026-01-28T07:46:41+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 07:46:41 volumio go-librespot[788]: time="2026-01-28T07:46:41+07:00" level=debug msg="app state loaded" Jan 28 07:46:41 volumio go-librespot[788]: time="2026-01-28T07:46:41+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 07:46:41 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 07:46:41 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 07:46:41 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 07:46:41 volumio volumio[509]: 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 07:46:41 volumio volumio[509]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 07:46:41 volumio volumio[509]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 07:46:41 volumio volumio[509]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 07:46:41 volumio volumio[509]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 07:46:41 volumio volumio[509]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 07:46:41 volumio volumio[509]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 07:46:41 volumio volumio[509]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 07:46:41 volumio volumio[509]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 07:46:41 volumio volumio[509]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 07:46:41 volumio volumio[509]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 07:46:41 volumio volumio[509]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 07:46:41 volumio volumio[509]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 07:46:41 volumio volumio[509]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 07:46:41 volumio volumio[509]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 07:46:41 volumio volumio[509]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 07:46:41 volumio volumio[509]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 07:46:41 volumio volumio[509]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 07:46:41 volumio volumio[509]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 07:46:41 volumio volumio[509]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 07:46:41 volumio volumio[509]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 07:46:41 volumio volumio[509]: info: No need to fix Spotify hosts Jan 28 07:46:42 volumio go-librespot[788]: time="2026-01-28T07:46:42+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 28 07:46:42 volumio go-librespot[788]: time="2026-01-28T07:46:42+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 07:46:42 volumio go-librespot[788]: time="2026-01-28T07:46:42+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 07:46:42 volumio go-librespot[788]: time="2026-01-28T07:46:42+07:00" level=info msg="zeroconf server listening on port 42919" Jan 28 07:46:42 volumio go-librespot[788]: time="2026-01-28T07:46:42+07:00" level=debug msg="obtained new client token: AACnUC7yttYDGlKfTXs4AfXQo5+LDfW+fLyNmtwTLOk73J6f6EYeBw6My3k51ccGAiyf9eUhUcPhkEIb44U2iwn1FvlaGuwMIEpi9v5cRzf+U+gqzRsz8hoIL0xYlPBI86xpW8rGmI3oMOLjdwlKUeXqo2OdpVYRjd0tpZMId+s5ao1ITW3k/6zr9n1uNxP9S7Y2zb4raMyVKtmaVr6BZb47frC/lpPL+8mmzIC0MFKcBJlj2nwgZ8mS" Jan 28 07:46:42 volumio volumio[509]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 28 07:46:42 volumio volumio[509]: SPOTIFY: BQD3kENBpvc60cs6yKuztPc6jDZW6NdPW0j8VVaGYFtdWtusqlT_9iOpWdbLz6LmVKT0t3FBP5ublDi4kr61m6zkPq2dUq8P_YBnzebwvz859qqgLnGatV4evn_Iy03XY_VOJtXQHLVZNazWAgibUebn9ovYd1xcEfET1tcR4TOzqiyCXrVyxjR4euCkk13Mnz0jLYVt3tktJz9_h6f4OoWduTZBsR4LJJ7-MZIyLB-pQXoPeBbZCGQbSUmPiE92ZX9ZvHdi71-rhEbqw9-GNJ0TptUHvW037GJVoxF2LV0vdUWS8TXYW41w Jan 28 07:46:42 volumio volumio[509]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 28 07:46:42 volumio volumio[509]: info: New Spotify access token = BQD3kENBpvc60cs6yKuztPc6jDZW6NdPW0j8VVaGYFtdWtusqlT_9iOpWdbLz6LmVKT0t3FBP5ublDi4kr61m6zkPq2dUq8P_YBnzebwvz859qqgLnGatV4evn_Iy03XY_VOJtXQHLVZNazWAgibUebn9ovYd1xcEfET1tcR4TOzqiyCXrVyxjR4euCkk13Mnz0jLYVt3tktJz9_h6f4OoWduTZBsR4LJJ7-MZIyLB-pQXoPeBbZCGQbSUmPiE92ZX9ZvHdi71-rhEbqw9-GNJ0TptUHvW037GJVoxF2LV0vdUWS8TXYW41w Jan 28 07:46:42 volumio volumio[509]: info: Spotify credentials grant success - running version from March 24, 2019 Jan 28 07:46:42 volumio volumio[509]: info: Starting Shairport Sync Jan 28 07:46:42 volumio go-librespot[788]: time="2026-01-28T07:46:42+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 07:46:42 volumio volumio[509]: info: Starting Shairport Sync Jan 28 07:46:42 volumio volumio[509]: info: Starting Shairport Sync Jan 28 07:46:42 volumio sudo[824]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 28 07:46:42 volumio sudo[824]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 07:46:42 volumio go-librespot[788]: time="2026-01-28T07:46:42+07:00" level=debug msg="completed keyexchange" Jan 28 07:46:42 volumio go-librespot[788]: time="2026-01-28T07:46:42+07:00" level=debug msg="completed challenge" Jan 28 07:46:42 volumio sudo[827]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 28 07:46:42 volumio sudo[827]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 07:46:42 volumio sudo[829]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 28 07:46:42 volumio sudo[829]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 07:46:42 volumio go-librespot[788]: time="2026-01-28T07:46:42+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 07:46:42 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 07:46:42 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 07:46:42 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 28 07:46:42 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Jan 28 07:46:42 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 28 07:46:42 volumio systemd[1]: shairport-sync.service: Consumed 2.324s CPU time. Jan 28 07:46:42 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 28 07:46:42 volumio sudo[824]: pam_unix(sudo:session): session closed for user root Jan 28 07:46:42 volumio sudo[827]: pam_unix(sudo:session): session closed for user root Jan 28 07:46:42 volumio sudo[829]: pam_unix(sudo:session): session closed for user root Jan 28 07:46:43 volumio volumio[509]: info: CoreCommandRouter::volumioGetState Jan 28 07:46:43 volumio volumio[509]: info: CorePlayQueue::getTrack 0 Jan 28 07:46:43 volumio volumio[509]: info: Shairport-Sync Started Jan 28 07:46:43 volumio volumio[509]: Error adding Membership: Error: addMembership EINVAL Jan 28 07:46:43 volumio volumio[509]: info: Shairport-Sync Started Jan 28 07:46:43 volumio volumio[509]: info: Shairport-Sync Started Jan 28 07:46:43 volumio volumio[509]: 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 07:46:43 volumio volumio[509]: info: Spotify Successfully logged in Jan 28 07:46:43 volumio volumio[509]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 07:46:43 volumio volumio[509]: info: [1769561203280] CoreMusicLibrary::Adding element Spotify Jan 28 07:46:43 volumio volumio[509]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 07:46:43 volumio volumio[509]: Cannot find translation for source YouTube Music Jan 28 07:46:43 volumio volumio[509]: Cannot find translation for source Spotify Jan 28 07:46:43 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 07:46:43 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 07:46:43 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 07:46:43 volumio volumio[509]: info: [yt-cast-receiver] DIAL server listening on port 8098 Jan 28 07:46:43 volumio volumio[509]: info: CoreCommandRouter::volumioRetrievevolume Jan 28 07:46:44 volumio volumio[509]: info: VolumeController:: Volume=100 Mute =false Jan 28 07:46:44 volumio volumio[509]: info: CoreCommandRouter::volumioGetState Jan 28 07:46:44 volumio volumio[509]: info: CorePlayQueue::getTrack 0 Jan 28 07:46:44 volumio volumio[509]: info: CoreStateMachine::pushState Jan 28 07:46:44 volumio volumio[509]: info: CorePlayQueue::getTrack 0 Jan 28 07:46:44 volumio volumio[509]: info: CoreCommandRouter::volumioPushState Jan 28 07:46:45 volumio volumio[509]: info: go-librespot daemon successfully initialized Jan 28 07:46:45 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 07:46:45 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 07:46:45 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 07:46:45 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Jan 28 07:46:45 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 07:46:45 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 07:46:45 volumio go-librespot[876]: go-librespot daemon starting... Jan 28 07:46:45 volumio go-librespot[877]: time="2026-01-28T07:46:45+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 07:46:45 volumio go-librespot[877]: time="2026-01-28T07:46:45+07:00" level=debug msg="app state loaded" Jan 28 07:46:45 volumio go-librespot[877]: time="2026-01-28T07:46:45+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 07:46:45 volumio mpd[761]: 2026-01-28T07:46:45 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 28 07:46:46 volumio systemd[1]: Started mpd.service - Music Player Daemon. Jan 28 07:46:46 volumio sudo[725]: pam_unix(sudo:session): session closed for user root Jan 28 07:46:46 volumio sudo[714]: pam_unix(sudo:session): session closed for user root Jan 28 07:46:46 volumio volumio[509]: error: MPD error: The expression evaluated to a falsy value: Jan 28 07:46:46 volumio volumio[509]: assert.ok(self.idling) Jan 28 07:46:46 volumio volumio[509]: error: The expression evaluated to a falsy value: Jan 28 07:46:46 volumio volumio[509]: assert.ok(self.idling) Jan 28 07:46:46 volumio volumio[509]: error: updateQueue error: null Jan 28 07:46:46 volumio volumio[509]: info: MPD running with PID761 Jan 28 07:46:46 volumio volumio[509]: ,establishing connection Jan 28 07:46:46 volumio volumio[509]: info: Completed starting Core Plugins Jan 28 07:46:46 volumio volumio[509]: info: ------------------------------------------- Jan 28 07:46:46 volumio volumio[509]: info: ----- MyVolumio plugins startup ---- Jan 28 07:46:46 volumio volumio[509]: info: ------------------------------------------- Jan 28 07:46:46 volumio volumio[509]: info: [MyVolumio PluginManager] Fetching plans data.... Jan 28 07:46:46 volumio volumio[509]: error: updateQueue error: null Jan 28 07:46:46 volumio go-librespot[877]: time="2026-01-28T07:46:46+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 07:46:46 volumio go-librespot[877]: time="2026-01-28T07:46:46+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 07:46:46 volumio go-librespot[877]: time="2026-01-28T07:46:46+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 07:46:46 volumio go-librespot[877]: time="2026-01-28T07:46:46+07:00" level=info msg="zeroconf server listening on port 42899" Jan 28 07:46:46 volumio go-librespot[877]: time="2026-01-28T07:46:46+07:00" level=debug msg="obtained new client token: AAAMem4aWQllH5HeZtBujrfLopZXgikC0UyAn7XFDbvNnfL6L4d6UbbgA0lW+ooz7bTUOuUKI4a0jdMfL6oUZJhjlAtLrSn97zxhSZFd1vZ6tIdFuygekm8jDo0k/9JwTFCs88k7JjWMr5axv1Mifl/6NhNlo/qZki42KvRK2CJgXBNlVjuFvbA5MOZ4xfb9U5xOwL+CZBKqcbFySUeSMRDDJRGE/H79nCeZWwAfqIF9OJ3MWM/aysCnr44=" Jan 28 07:46:46 volumio go-librespot[877]: time="2026-01-28T07:46:46+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 07:46:46 volumio go-librespot[877]: time="2026-01-28T07:46:46+07:00" level=debug msg="completed keyexchange" Jan 28 07:46:46 volumio go-librespot[877]: time="2026-01-28T07:46:46+07:00" level=debug msg="completed challenge" Jan 28 07:46:47 volumio go-librespot[877]: time="2026-01-28T07:46:47+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 07:46:47 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 07:46:47 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 07:46:47 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 07:46:47 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 07:46:47 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 07:46:48 volumio volumio[509]: info: Initializing connection to go-librespot Websocket Jan 28 07:46:48 volumio volumio[509]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 28 07:46:49 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 07:46:49 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 07:46:49 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 07:46:50 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Jan 28 07:46:50 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 07:46:50 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 07:46:50 volumio go-librespot[890]: go-librespot daemon starting... Jan 28 07:46:50 volumio go-librespot[891]: time="2026-01-28T07:46:50+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 07:46:50 volumio go-librespot[891]: time="2026-01-28T07:46:50+07:00" level=debug msg="app state loaded" Jan 28 07:46:50 volumio go-librespot[891]: time="2026-01-28T07:46:50+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 07:46:50 volumio go-librespot[891]: time="2026-01-28T07:46:50+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 28 07:46:50 volumio go-librespot[891]: time="2026-01-28T07:46:50+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 07:46:50 volumio go-librespot[891]: time="2026-01-28T07:46:50+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 07:46:50 volumio go-librespot[891]: time="2026-01-28T07:46:50+07:00" level=info msg="zeroconf server listening on port 37751" Jan 28 07:46:51 volumio go-librespot[891]: time="2026-01-28T07:46:51+07:00" level=debug msg="obtained new client token: AABuz1NbNeDNam20HJI51MvvVHEQioWSKcsjMAXBjgGVQMCawFe9+gxs5+qudKXCV/TFKKMEVx2ilN/RuciWhAepDHzojsQxhY5MQcP0QPbrXHh0bKwAtAcPFrSb4/1bKzBzVRYouYUYN+2iCwKRrnjwGbJsTsLiJLvmJ/em3g9OGDvuCox5y2ubJ5T9IH8y+sga0Sx00yCxRpKFDV6ruMc1cZPV6tMbwoHMLq7oFzvqvMd56jdjQRviyj4=" Jan 28 07:46:51 volumio go-librespot[891]: time="2026-01-28T07:46:51+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 07:46:51 volumio volumio[509]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Jan 28 07:46:51 volumio go-librespot[891]: time="2026-01-28T07:46:51+07:00" level=debug msg="completed keyexchange" Jan 28 07:46:51 volumio go-librespot[891]: time="2026-01-28T07:46:51+07:00" level=debug msg="completed challenge" Jan 28 07:46:51 volumio volumio[509]: info: Initializing connection to go-librespot Websocket Jan 28 07:46:51 volumio go-librespot[891]: time="2026-01-28T07:46:51+07:00" level=debug msg="new websocket client" Jan 28 07:46:51 volumio volumio[509]: info: Connection to go-librespot Websocket established Jan 28 07:46:51 volumio go-librespot[891]: time="2026-01-28T07:46:51+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 07:46:51 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 07:46:51 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 07:46:51 volumio volumio[509]: info: Connection to go-librespot Websocket closed Jan 28 07:46:51 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 07:46:51 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 07:46:51 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 07:46:53 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 07:46:53 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 07:46:53 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 07:46:54 volumio volumio[509]: info: Getting Spotify volume Jan 28 07:46:54 volumio volumio[509]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 28 07:46:54 volumio volumio[509]: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 28 07:46:54 volumio volumio[509]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Jan 28 07:46:54 volumio volumio[509]: errno: -111, Jan 28 07:46:54 volumio volumio[509]: code: 'ECONNREFUSED', Jan 28 07:46:54 volumio volumio[509]: syscall: 'connect', Jan 28 07:46:54 volumio volumio[509]: address: '127.0.0.1', Jan 28 07:46:54 volumio volumio[509]: port: 9879, Jan 28 07:46:54 volumio volumio[509]: response: undefined Jan 28 07:46:54 volumio volumio[509]: } Jan 28 07:46:54 volumio volumio[509]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 28 07:46:54 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Jan 28 07:46:54 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 07:46:54 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 07:46:54 volumio go-librespot[910]: go-librespot daemon starting... Jan 28 07:46:54 volumio go-librespot[911]: time="2026-01-28T07:46:54+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 07:46:54 volumio go-librespot[911]: time="2026-01-28T07:46:54+07:00" level=debug msg="app state loaded" Jan 28 07:46:54 volumio go-librespot[911]: time="2026-01-28T07:46:54+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 07:46:55 volumio go-librespot[911]: time="2026-01-28T07:46: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 07:46:55 volumio go-librespot[911]: time="2026-01-28T07:46: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 07:46:55 volumio go-librespot[911]: time="2026-01-28T07:46: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 07:46:55 volumio go-librespot[911]: time="2026-01-28T07:46:55+07:00" level=info msg="zeroconf server listening on port 36713" Jan 28 07:46:55 volumio go-librespot[911]: time="2026-01-28T07:46:55+07:00" level=debug msg="obtained new client token: AABJu5R7DhfpIdiG1BboonX+gr5skjSGREvFLpr3mZ8pL2vaOwFcSKamdDYBzlLLN471ThrcbqyVKu9wZB/3pK6EEHSCp7NjwL6TRxEOLP1yq8/XfQvAVTscHJbMXGFKz3p7NmpWgaQLHXwMsnT1K/WgxGH6K1/EtNX+FnmICepKf8IkTSsbQkft8YBiynQs+YNQyn13BwPbdetIk4H3HjEW3Q2PwUDm0wA2oNnEx0FSQZydix5limYrd4A=" Jan 28 07:46:55 volumio go-librespot[911]: time="2026-01-28T07:46:55+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 07:46:55 volumio go-librespot[911]: time="2026-01-28T07:46:55+07:00" level=debug msg="completed keyexchange" Jan 28 07:46:55 volumio go-librespot[911]: time="2026-01-28T07:46:55+07:00" level=debug msg="completed challenge" Jan 28 07:46:55 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 07:46:55 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 07:46:55 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 07:46:55 volumio go-librespot[911]: time="2026-01-28T07:46:55+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 07:46:55 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 07:46:55 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 07:46:55 volumio sudo[935]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-01-28 07:45' Jan 28 07:46:55 volumio sudo[935]: 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"