Jan 26 12:45:00 volumio volumio-remote-updater[628]: [2026-01-26 12:45:00] [connect] Successful connection Jan 26 12:45:00 volumio volumio[567]: info: Loading plugin "outputs"... Jan 26 12:45:00 volumio volumio[567]: info: Loading plugin "albumart"... Jan 26 12:45:00 volumio volumio[567]: info: Plugin example_plugin is not enabled Jan 26 12:45:00 volumio volumio[567]: info: Loading plugin "inputs"... Jan 26 12:45:00 volumio volumio[567]: info: Loading plugin "updater_comm"... Jan 26 12:45:00 volumio volumio[567]: info: Plugin mpdemulation is not enabled Jan 26 12:45:00 volumio volumio[567]: info: Loading plugin "rest_api"... Jan 26 12:45:00 volumio volumio[567]: info: Loading plugin "websocket"... Jan 26 12:45:00 volumio volumio[567]: info: Starting Socket.io Server version 1.7.4 Jan 26 12:45:00 volumio volumio[567]: info: Loading plugin "RoonBridge"... Jan 26 12:45:01 volumio volumio[567]: info: Applying required configuration parameters for plugin RoonBridge Jan 26 12:45:01 volumio volumio[567]: info: Loading i18n strings for locale en Jan 26 12:45:01 volumio volumio[567]: Updating browse sources language Jan 26 12:45:01 volumio volumio[567]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 26 12:45:01 volumio volumio[567]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 26 12:45:01 volumio volumio[567]: info: CoreCommandRouter::initPlayerControls Jan 26 12:45:01 volumio volumio[567]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 12:45:01 volumio volumio[567]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 12:45:01 volumio volumio[567]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 12:45:01 volumio volumio[567]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 12:45:01 volumio volumio[567]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 12:45:01 volumio volumio[567]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 12:45:01 volumio volumio[567]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 12:45:01 volumio volumio[567]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 12:45:01 volumio volumio[699]: Forking 3 albumart workers Jan 26 12:45:01 volumio volumio[567]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 26 12:45:01 volumio volumio[567]: Express server listening on port 3000 Jan 26 12:45:01 volumio volumio[567]: [Metrics] WebUI: 15s 973.95ms Jan 26 12:45:01 volumio volumio[567]: info: CoreStateMachine::resetVolumioState Jan 26 12:45:01 volumio volumio[567]: info: CoreStateMachine::getcurrentVolume Jan 26 12:45:01 volumio volumio[567]: info: CoreCommandRouter::volumioRetrievevolume Jan 26 12:45:01 volumio sudo[748]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 26 12:45:01 volumio sudo[748]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 12:45:01 volumio volumio[567]: info: Volumio Network Manager: Network status updated: 1 Jan 26 12:45:01 volumio sudo[744]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 26 12:45:01 volumio sudo[744]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 12:45:01 volumio sudo[748]: pam_unix(sudo:session): session closed for user root Jan 26 12:45:01 volumio sudo[744]: pam_unix(sudo:session): session closed for user root Jan 26 12:45:01 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 12:45:01 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 12:45:01 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 12:45:02 volumio volumio[567]: info: VolumeController:: Volume=100 Mute =false Jan 26 12:45:02 volumio volumio[567]: info: CoreStateMachine::pushState Jan 26 12:45:02 volumio volumio[567]: info: CorePlayQueue::getTrack 0 Jan 26 12:45:02 volumio volumio[567]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 26 12:45:02 volumio volumio[567]: info: CoreCommandRouter::volumioPushState Jan 26 12:45:02 volumio volumio[567]: info: CoreStateMachine::updateTrackBlock Jan 26 12:45:02 volumio volumio[567]: info: CorePlayQueue::getTrackBlock Jan 26 12:45:02 volumio volumio[567]: info: CoreCommandRouter::volumioRetrievevolume Jan 26 12:45:02 volumio volumio-remote-updater[628]: [2026-01-26 12:45:02] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1769406300 101 Jan 26 12:45:02 volumio volumio[567]: 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 26 12:45:02 volumio volumio[567]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 12:45:02 volumio volumio[567]: info: Reloading queue from file Jan 26 12:45:02 volumio volumio[567]: info: CoreStateMachine::setRepeat null single undefined Jan 26 12:45:02 volumio volumio[567]: info: CoreStateMachine::pushState Jan 26 12:45:02 volumio volumio[567]: info: CorePlayQueue::getTrack 0 Jan 26 12:45:02 volumio volumio[567]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 26 12:45:02 volumio volumio[567]: info: CoreCommandRouter::volumioPushState Jan 26 12:45:02 volumio volumio[567]: info: CoreStateMachine::setRandom null Jan 26 12:45:02 volumio volumio[567]: info: CoreStateMachine::pushState Jan 26 12:45:02 volumio volumio[567]: info: CorePlayQueue::getTrack 0 Jan 26 12:45:02 volumio volumio[567]: info: CoreCommandRouter::volumioPushState Jan 26 12:45:02 volumio volumio[567]: info: Setting Device type: Raspberry PI Jan 26 12:45:02 volumio volumio[567]: info: Completed loading Core Plugins Jan 26 12:45:02 volumio volumio[567]: info: Preparing to generate the ALSA configuration file Jan 26 12:45:02 volumio volumio[567]: info: VolumeController:: Volume=100 Mute =false Jan 26 12:45:02 volumio volumio[567]: info: CoreStateMachine::pushState Jan 26 12:45:02 volumio volumio[567]: info: CorePlayQueue::getTrack 0 Jan 26 12:45:02 volumio volumio[567]: info: CoreCommandRouter::volumioPushState Jan 26 12:45:02 volumio volumio[567]: info: Asound.conf file unchanged, so no further update is needed Jan 26 12:45:02 volumio volumio[567]: info: Output device has changed, restarting MPD Jan 26 12:45:02 volumio sudo[766]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Jan 26 12:45:02 volumio volumio[567]: info: Output device has changed, restarting Shairport Sync Jan 26 12:45:02 volumio volumio[567]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 12:45:02 volumio sudo[766]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 12:45:02 volumio volumio[567]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 12:45:02 volumio sudo[768]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 26 12:45:02 volumio sudo[768]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 12:45:02 volumio sudo[768]: pam_unix(sudo:session): session closed for user root Jan 26 12:45:02 volumio sudo[770]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 26 12:45:02 volumio sudo[770]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 12:45:02 volumio volumio[567]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 26 12:45:02 volumio volumio[567]: info: ___________ START PLUGINS ___________ Jan 26 12:45:02 volumio sudo[766]: pam_unix(sudo:session): session closed for user root Jan 26 12:45:02 volumio volumio[567]: info: ControllerMpd::onStart: Initializing MPD Jan 26 12:45:02 volumio volumio[567]: info: Creating MPD Configuration file Jan 26 12:45:02 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Jan 26 12:45:02 volumio volumio[567]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 26 12:45:02 volumio volumio[567]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 26 12:45:02 volumio volumio[567]: info: [1769406302941] CoreMusicLibrary::Adding element Media Servers Jan 26 12:45:02 volumio volumio[567]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 26 12:45:02 volumio sudo[779]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 26 12:45:02 volumio volumio[567]: info: UPNP Browser: Client initialized successfully Jan 26 12:45:02 volumio sudo[779]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 12:45:03 volumio sudo[779]: pam_unix(sudo:session): session closed for user root Jan 26 12:45:03 volumio volumio[567]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 12:45:03 volumio volumio[567]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 12:45:03 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 26 12:45:03 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 26 12:45:03 volumio systemd[1]: mpd.service: Consumed 7.422s CPU time. Jan 26 12:45:03 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 26 12:45:03 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 26 12:45:03 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 26 12:45:03 volumio sudo[781]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 26 12:45:03 volumio sudo[781]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 12:45:03 volumio volumio[567]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 26 12:45:03 volumio volumio[567]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 12:45:03 volumio volumio[567]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 12:45:03 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 26 12:45:03 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 26 12:45:03 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 26 12:45:03 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 26 12:45:03 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 26 12:45:03 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 26 12:45:03 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 26 12:45:03 volumio volumio[567]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 26 12:45:03 volumio volumio[567]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 26 12:45:03 volumio volumio[567]: info: [1769406303290] CoreMusicLibrary::Adding element Last_100 Jan 26 12:45:03 volumio volumio[567]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 26 12:45:03 volumio volumio[567]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 26 12:45:03 volumio volumio[567]: info: [1769406303301] CoreMusicLibrary::Adding element Webradio Jan 26 12:45:03 volumio volumio[567]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 26 12:45:03 volumio volumio[567]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 26 12:45:03 volumio volumio[567]: info: Initializing BBC Radios Jan 26 12:45:03 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 26 12:45:03 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 26 12:45:03 volumio volumio[567]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 26 12:45:03 volumio volumio[567]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 12:45:03 volumio volumio[567]: info: Creating Spotify config file Jan 26 12:45:03 volumio volumio[567]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 12:45:03 volumio sudo[798]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 26 12:45:03 volumio sudo[798]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jan 26 12:45:03 volumio sudo[798]: pam_unix(sudo:session): session closed for user root Jan 26 12:45:03 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 12:45:03 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 12:45:03 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 12:45:04 volumio volumio[712]: Starting albumart workers Jan 26 12:45:04 volumio volumio[709]: Starting albumart workers Jan 26 12:45:04 volumio volumio[567]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 26 12:45:04 volumio volumio[567]: info: [1769406304820] CoreMusicLibrary::Adding element YouTube Music Jan 26 12:45:04 volumio volumio[567]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 26 12:45:04 volumio volumio[567]: Cannot find translation for source YouTube Music Jan 26 12:45:04 volumio volumio[567]: info: Volumio Calling Home Jan 26 12:45:04 volumio sudo[816]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Jan 26 12:45:04 volumio sudo[816]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 12:45:04 volumio volumio[710]: Starting albumart workers Jan 26 12:45:05 volumio sudo[816]: pam_unix(sudo:session): session closed for user root Jan 26 12:45:05 volumio volumio[567]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Jan 26 12:45:05 volumio volumio[567]: info: Discovery: Found device Volumio Jan 26 12:45:05 volumio volumio[567]: info: CoreCommandRouter::volumioGetState Jan 26 12:45:05 volumio volumio[567]: info: CorePlayQueue::getTrack 0 Jan 26 12:45:05 volumio volumio[567]: info: MPD Permissions set Jan 26 12:45:05 volumio volumio[567]: info: MPD Permissions set Jan 26 12:45:05 volumio volumio[567]: info: Upmpdcli Daemon Started Jan 26 12:45:05 volumio volumio[567]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Jan 26 12:45:05 volumio volumio[567]: info: Discovery: Found device Volumio Jan 26 12:45:05 volumio volumio[567]: info: CoreCommandRouter::volumioGetState Jan 26 12:45:05 volumio volumio[567]: info: CorePlayQueue::getTrack 0 Jan 26 12:45:05 volumio volumio[567]: info: Volumio called home Jan 26 12:45:05 volumio volumio[567]: info: Spotify config file written Jan 26 12:45:05 volumio sudo[824]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jan 26 12:45:05 volumio sudo[824]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 12:45:05 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 12:45:05 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 12:45:05 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 12:45:05 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Jan 26 12:45:05 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Jan 26 12:45:05 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 26 12:45:06 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 26 12:45:06 volumio go-librespot[827]: go-librespot daemon starting... Jan 26 12:45:06 volumio sudo[824]: pam_unix(sudo:session): session closed for user root Jan 26 12:45:06 volumio go-librespot[828]: time="2026-01-26T12:45:06+07:00" level=info msg="running go-librespot 0.4.0" Jan 26 12:45:06 volumio go-librespot[828]: time="2026-01-26T12:45:06+07:00" level=debug msg="app state loaded" Jan 26 12:45:06 volumio go-librespot[828]: time="2026-01-26T12:45:06+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 26 12:45:06 volumio volumio[567]: 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 26 12:45:06 volumio volumio[567]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 12:45:06 volumio volumio[567]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 12:45:06 volumio volumio[567]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 12:45:06 volumio volumio[567]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 12:45:06 volumio volumio[567]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 12:45:06 volumio volumio[567]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 12:45:06 volumio volumio[567]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 12:45:06 volumio volumio[567]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 12:45:06 volumio volumio[567]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 12:45:06 volumio volumio[567]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 12:45:06 volumio volumio[567]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 12:45:06 volumio volumio[567]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 12:45:06 volumio volumio[567]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 12:45:06 volumio volumio[567]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 12:45:06 volumio volumio[567]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 12:45:06 volumio volumio[567]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 12:45:06 volumio volumio[567]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 12:45:06 volumio volumio[567]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 12:45:06 volumio volumio[567]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 12:45:06 volumio volumio[567]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 12:45:06 volumio volumio[567]: info: No need to fix Spotify hosts Jan 26 12:45:06 volumio go-librespot[828]: time="2026-01-26T12:45: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 26 12:45:06 volumio go-librespot[828]: time="2026-01-26T12:45: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 26 12:45:06 volumio go-librespot[828]: time="2026-01-26T12:45: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 26 12:45:06 volumio go-librespot[828]: time="2026-01-26T12:45:06+07:00" level=info msg="zeroconf server listening on port 39561" Jan 26 12:45:07 volumio go-librespot[828]: time="2026-01-26T12:45:07+07:00" level=debug msg="obtained new client token: AABJrITP1O80sslZAqaQ2iIA9Ti7k/zD9KCCvOMY4/gtZkaTzUwn7VA7U3dzg3iXqomcSLEicIPizK4eaG5tBJG6Qq2ucewQ0kV9oO2YRCxz7M7ZCi/+qXyFQ83ZqNbGp2p9UGRWWvvy25ErYuCDc17QWjTUjSchGVrITWyvtEU6nCd2E3swvE7Q6tgkohcs9cqzWlumahzQDy5y9zG9nYqbtrnK/N4aZ9iZM1U3I6SAK+W2BueABqNE" Jan 26 12:45:07 volumio go-librespot[828]: time="2026-01-26T12:45:07+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 26 12:45:07 volumio go-librespot[828]: time="2026-01-26T12:45:07+07:00" level=debug msg="completed keyexchange" Jan 26 12:45:07 volumio go-librespot[828]: time="2026-01-26T12:45:07+07:00" level=debug msg="completed challenge" Jan 26 12:45:07 volumio go-librespot[828]: time="2026-01-26T12:45:07+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 26 12:45:07 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 26 12:45:07 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 26 12:45:07 volumio volumio[567]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 26 12:45:07 volumio volumio[567]: SPOTIFY: BQDdboqvFNCwLCnXKj9SLzLTw-J0MaoZ3WfPqNx08rurPTgILt2w-UUcHf_CNqEYdes3ZoTQIqe9Zqd5CUyf_sgEf9l_QKpSXkJDTknzZRIGbir5_JuxaO03Paju32hU34mYvvfUllCGmUZ9Huix8cNJwPH-UE10rNvsS8MroO332IciOyCioLpnxtqVWBbOnjJyC8oLPi3fGRJmbxceZ_3XfHTGEtzZdPnPQ77_PRu7BycLAxLn1sB7ocBUHdKVlmdzkeLM2JgQRdUf1y-ZNdgP5kDHn3ybO7qw0-YfJVIbXYekXQKYPm4N Jan 26 12:45:07 volumio volumio[567]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 26 12:45:07 volumio volumio[567]: info: New Spotify access token = BQDdboqvFNCwLCnXKj9SLzLTw-J0MaoZ3WfPqNx08rurPTgILt2w-UUcHf_CNqEYdes3ZoTQIqe9Zqd5CUyf_sgEf9l_QKpSXkJDTknzZRIGbir5_JuxaO03Paju32hU34mYvvfUllCGmUZ9Huix8cNJwPH-UE10rNvsS8MroO332IciOyCioLpnxtqVWBbOnjJyC8oLPi3fGRJmbxceZ_3XfHTGEtzZdPnPQ77_PRu7BycLAxLn1sB7ocBUHdKVlmdzkeLM2JgQRdUf1y-ZNdgP5kDHn3ybO7qw0-YfJVIbXYekXQKYPm4N Jan 26 12:45:07 volumio volumio[567]: info: Spotify credentials grant success - running version from March 24, 2019 Jan 26 12:45:07 volumio volumio[567]: info: Starting Shairport Sync Jan 26 12:45:07 volumio volumio[567]: info: Starting Shairport Sync Jan 26 12:45:07 volumio volumio[567]: info: Starting Shairport Sync Jan 26 12:45:07 volumio sudo[876]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 26 12:45:07 volumio sudo[876]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 12:45:07 volumio sudo[878]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 26 12:45:07 volumio sudo[878]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 12:45:07 volumio sudo[880]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 26 12:45:07 volumio sudo[880]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 12:45:07 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 26 12:45:07 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 12:45:07 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 12:45:07 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 12:45:07 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Jan 26 12:45:07 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 26 12:45:07 volumio systemd[1]: shairport-sync.service: Consumed 2.413s CPU time. Jan 26 12:45:08 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 26 12:45:08 volumio sudo[876]: pam_unix(sudo:session): session closed for user root Jan 26 12:45:08 volumio sudo[880]: pam_unix(sudo:session): session closed for user root Jan 26 12:45:08 volumio sudo[878]: pam_unix(sudo:session): session closed for user root Jan 26 12:45:08 volumio volumio[567]: info: CoreCommandRouter::volumioGetState Jan 26 12:45:08 volumio volumio[567]: info: CorePlayQueue::getTrack 0 Jan 26 12:45:08 volumio volumio[567]: info: Shairport-Sync Started Jan 26 12:45:08 volumio volumio[567]: Error adding Membership: Error: addMembership EINVAL Jan 26 12:45:08 volumio volumio[567]: info: Shairport-Sync Started Jan 26 12:45:08 volumio volumio[567]: info: Shairport-Sync Started Jan 26 12:45:08 volumio volumio[567]: 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 26 12:45:08 volumio volumio[567]: info: Spotify Successfully logged in Jan 26 12:45:08 volumio volumio[567]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 26 12:45:08 volumio volumio[567]: info: [1769406308430] CoreMusicLibrary::Adding element Spotify Jan 26 12:45:08 volumio volumio[567]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 26 12:45:08 volumio volumio[567]: Cannot find translation for source YouTube Music Jan 26 12:45:08 volumio volumio[567]: Cannot find translation for source Spotify Jan 26 12:45:09 volumio volumio[567]: info: [yt-cast-receiver] DIAL server listening on port 8098 Jan 26 12:45:09 volumio volumio[567]: info: CoreCommandRouter::volumioRetrievevolume Jan 26 12:45:09 volumio volumio[567]: info: VolumeController:: Volume=100 Mute =false Jan 26 12:45:09 volumio volumio[567]: info: CoreCommandRouter::volumioGetState Jan 26 12:45:09 volumio volumio[567]: info: CorePlayQueue::getTrack 0 Jan 26 12:45:09 volumio volumio[567]: info: CoreStateMachine::pushState Jan 26 12:45:09 volumio volumio[567]: info: CorePlayQueue::getTrack 0 Jan 26 12:45:09 volumio volumio[567]: info: CoreCommandRouter::volumioPushState Jan 26 12:45:09 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 12:45:09 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 12:45:09 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 12:45:10 volumio volumio[567]: info: go-librespot daemon successfully initialized Jan 26 12:45:10 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Jan 26 12:45:10 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 26 12:45:10 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 26 12:45:10 volumio go-librespot[920]: go-librespot daemon starting... Jan 26 12:45:10 volumio go-librespot[921]: time="2026-01-26T12:45:10+07:00" level=info msg="running go-librespot 0.4.0" Jan 26 12:45:10 volumio go-librespot[921]: time="2026-01-26T12:45:10+07:00" level=debug msg="app state loaded" Jan 26 12:45:10 volumio go-librespot[921]: time="2026-01-26T12:45:10+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 26 12:45:11 volumio mpd[814]: 2026-01-26T12:45:11 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 26 12:45:11 volumio systemd[1]: Started mpd.service - Music Player Daemon. Jan 26 12:45:11 volumio sudo[781]: pam_unix(sudo:session): session closed for user root Jan 26 12:45:11 volumio sudo[770]: pam_unix(sudo:session): session closed for user root Jan 26 12:45:11 volumio volumio[567]: error: MPD error: The expression evaluated to a falsy value: Jan 26 12:45:11 volumio volumio[567]: assert.ok(self.idling) Jan 26 12:45:11 volumio volumio[567]: error: The expression evaluated to a falsy value: Jan 26 12:45:11 volumio volumio[567]: assert.ok(self.idling) Jan 26 12:45:11 volumio go-librespot[921]: time="2026-01-26T12: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-gew1.spotify.com:80]" Jan 26 12:45:11 volumio go-librespot[921]: time="2026-01-26T12: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 gew1-dealer.spotify.com:443]" Jan 26 12:45:11 volumio go-librespot[921]: time="2026-01-26T12: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 gew1-spclient.spotify.com:443]" Jan 26 12:45:11 volumio go-librespot[921]: time="2026-01-26T12:45:11+07:00" level=info msg="zeroconf server listening on port 45135" Jan 26 12:45:11 volumio volumio[567]: info: Completed starting Core Plugins Jan 26 12:45:11 volumio volumio[567]: info: ------------------------------------------- Jan 26 12:45:11 volumio volumio[567]: info: ----- MyVolumio plugins startup ---- Jan 26 12:45:11 volumio volumio[567]: info: ------------------------------------------- Jan 26 12:45:11 volumio volumio[567]: info: [MyVolumio PluginManager] Fetching plans data.... Jan 26 12:45:11 volumio volumio[567]: info: MPD running with PID814 Jan 26 12:45:11 volumio volumio[567]: ,establishing connection Jan 26 12:45:11 volumio volumio[567]: error: updateQueue error: null Jan 26 12:45:11 volumio volumio[567]: error: updateQueue error: null Jan 26 12:45:11 volumio go-librespot[921]: time="2026-01-26T12:45:11+07:00" level=debug msg="obtained new client token: AABQatuQQSrKxs3zgznBs3ABRQ3s6B1hb0g+a6HwHAL5pyVmTMXwf/sTgQTvhpAVHWicKdyCCtBhOweIWt0wzskxlZH92cdHWDgtFRCneQKwwy1WOj6T2aK2CrKggRoX1+zQqX0DljTZG6oPUGzE7Pvd80FbHcipeLg6126zDmdNzFGFd2bf7YYmcR7aWofW9j0NiR+RdUc6lIBlAJzuXYD6WyxpqRo4DZrLGDVyTCphlnJ7MJeKhIfsfFY=" Jan 26 12:45:11 volumio go-librespot[921]: time="2026-01-26T12:45:11+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 26 12:45:11 volumio go-librespot[921]: time="2026-01-26T12:45:11+07:00" level=debug msg="completed keyexchange" Jan 26 12:45:11 volumio go-librespot[921]: time="2026-01-26T12:45:11+07:00" level=debug msg="completed challenge" Jan 26 12:45:11 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 12:45:11 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 12:45:11 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 12:45:12 volumio go-librespot[921]: time="2026-01-26T12: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 26 12:45:12 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 26 12:45:12 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 26 12:45:13 volumio volumio[567]: info: Initializing connection to go-librespot Websocket Jan 26 12:45:13 volumio volumio[567]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 26 12:45:13 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 12:45:13 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 12:45:13 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 12:45:15 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Jan 26 12:45:15 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 26 12:45:15 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 26 12:45:15 volumio go-librespot[933]: go-librespot daemon starting... Jan 26 12:45:15 volumio go-librespot[934]: time="2026-01-26T12:45:15+07:00" level=info msg="running go-librespot 0.4.0" Jan 26 12:45:15 volumio go-librespot[934]: time="2026-01-26T12:45:15+07:00" level=debug msg="app state loaded" Jan 26 12:45:15 volumio go-librespot[934]: time="2026-01-26T12:45:15+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 26 12:45:15 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 12:45:15 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 12:45:15 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 12:45:15 volumio go-librespot[934]: time="2026-01-26T12:45:15+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 26 12:45:15 volumio go-librespot[934]: time="2026-01-26T12:45:15+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 26 12:45:15 volumio go-librespot[934]: time="2026-01-26T12:45:15+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 26 12:45:16 volumio go-librespot[934]: time="2026-01-26T12:45:16+07:00" level=info msg="zeroconf server listening on port 35585" Jan 26 12:45:16 volumio go-librespot[934]: time="2026-01-26T12:45:16+07:00" level=debug msg="obtained new client token: AAAygPQ6wEo57Tl+56LS2KT8Cjrb6gu54gIuoaawfRqN/ifPHDWk1dZEHQblhGhrjjC1Wv31bCw+v4bYENx/Xa+qr2oOsErzqZU4ugOQ5dFa+Ki2avDWE3UewXdIAw05kclgRj1ewu2cspZdntFQqTvFVYqGko9ofOB8pA6QkKtt3bpJvrQ6MqSwYvDh0wvy8VI0oLn6oqb1otLZbmXAFQLCyJatl71CC3a6ft7gwPKShh+QQ6IagrhS" Jan 26 12:45:16 volumio volumio[567]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Jan 26 12:45:16 volumio volumio[567]: info: Initializing connection to go-librespot Websocket Jan 26 12:45:16 volumio go-librespot[934]: time="2026-01-26T12:45:16+07:00" level=debug msg="new websocket client" Jan 26 12:45:16 volumio volumio[567]: info: Connection to go-librespot Websocket established Jan 26 12:45:16 volumio go-librespot[934]: time="2026-01-26T12:45:16+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 26 12:45:17 volumio go-librespot[934]: time="2026-01-26T12:45:17+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: read tcp 192.168.1.107:37414->104.199.241.202:4070: read: connection reset by peer" Jan 26 12:45:17 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 26 12:45:17 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 26 12:45:17 volumio volumio[567]: info: Connection to go-librespot Websocket closed Jan 26 12:45:17 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 12:45:17 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 12:45:17 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 12:45:19 volumio volumio[567]: info: Getting Spotify volume Jan 26 12:45:19 volumio volumio[567]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 26 12:45:19 volumio volumio[567]: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 26 12:45:19 volumio volumio[567]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Jan 26 12:45:19 volumio volumio[567]: errno: -111, Jan 26 12:45:19 volumio volumio[567]: code: 'ECONNREFUSED', Jan 26 12:45:19 volumio volumio[567]: syscall: 'connect', Jan 26 12:45:19 volumio volumio[567]: address: '127.0.0.1', Jan 26 12:45:19 volumio volumio[567]: port: 9879, Jan 26 12:45:19 volumio volumio[567]: response: undefined Jan 26 12:45:19 volumio volumio[567]: } Jan 26 12:45:19 volumio volumio[567]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 26 12:45:19 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 12:45:19 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 12:45:19 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 12:45:20 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Jan 26 12:45:20 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 26 12:45:20 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 26 12:45:20 volumio go-librespot[969]: go-librespot daemon starting... Jan 26 12:45:20 volumio go-librespot[970]: time="2026-01-26T12:45:20+07:00" level=info msg="running go-librespot 0.4.0" Jan 26 12:45:20 volumio go-librespot[970]: time="2026-01-26T12:45:20+07:00" level=debug msg="app state loaded" Jan 26 12:45:20 volumio go-librespot[970]: time="2026-01-26T12:45:20+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 26 12:45:20 volumio sudo[980]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-01-26 12:44' Jan 26 12:45:20 volumio sudo[980]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 12:45:21 volumio sudo[980]: pam_unix(sudo:session): session closed for user root Jan 26 12:45:21 volumio go-librespot[970]: time="2026-01-26T12:45:21+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 26 12:45:21 volumio go-librespot[970]: time="2026-01-26T12:45:21+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 26 12:45:21 volumio go-librespot[970]: time="2026-01-26T12:45:21+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 26 12:45:21 volumio go-librespot[970]: time="2026-01-26T12:45:21+07:00" level=info msg="zeroconf server listening on port 42385" Jan 26 12:45:21 volumio volumio-remote-updater[628]: [2026-01-26 12:45:21] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Jan 26 12:45:21 volumio volumio-remote-updater[628]: [2026-01-26 12:45:21] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Jan 26 12:45:21 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Jan 26 12:45:21 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Jan 26 12:45:21 volumio systemd[1]: volumio.service: Consumed 1min 2.275s CPU time. Jan 26 12:45:21 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 26 12:45:21 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Jan 26 12:45:21 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 6973. Jan 26 12:45:21 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 26 12:45:21 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Jan 26 12:45:21 volumio systemd[1]: volumio.service: Consumed 1min 2.275s CPU time. Jan 26 12:45:21 volumio go-librespot[970]: time="2026-01-26T12:45:21+07:00" level=debug msg="obtained new client token: AAB132FYkqAIraIdtMHeIq0AAYzTvLv8gNLoQPDZUTUW6f+CtQl8hoiq+KfQy9SOYLd/MSUqlDCpHy9eNQ23ROub7RdkHJdQ1CPj90keSDZNxuD9bagtAURh1ttHgnv4WsUAH3FPh+qr6wYZWE75X/Upz8JVXJuU9sAZIJkcFrM05x7Ey+B4mh84yBn4FJf+yhwQA7FYq98TBzjV4Lml2XlKakcw7OG1WkCbBhI5OvREBzT/Ni9ItsqBPk4=" Jan 26 12:45:21 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Jan 26 12:45:21 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Jan 26 12:45:21 volumio go-librespot[970]: time="2026-01-26T12:45:21+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 26 12:45:21 volumio go-librespot[970]: time="2026-01-26T12:45:21+07:00" level=debug msg="completed keyexchange" Jan 26 12:45:21 volumio go-librespot[970]: time="2026-01-26T12:45:21+07:00" level=debug msg="completed challenge" Jan 26 12:45:21 volumio go-librespot[970]: time="2026-01-26T12: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 26 12:45:21 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 26 12:45:21 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 26 12:45:21 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 12:45:21 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 12:45:21 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 12:45:23 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 12:45:23 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 12:45:23 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 12:45:24 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Jan 26 12:45:24 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 26 12:45:25 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 26 12:45:25 volumio go-librespot[1015]: go-librespot daemon starting... Jan 26 12:45:25 volumio go-librespot[1016]: time="2026-01-26T12:45:25+07:00" level=info msg="running go-librespot 0.4.0" Jan 26 12:45:25 volumio go-librespot[1016]: time="2026-01-26T12:45:25+07:00" level=debug msg="app state loaded" Jan 26 12:45:25 volumio go-librespot[1016]: time="2026-01-26T12:45:25+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 26 12:45:25 volumio volumio[994]: info: ------------------------------------------- Jan 26 12:45:25 volumio volumio[994]: info: ----- Volumio3 ---- Jan 26 12:45:25 volumio volumio[994]: info: ------------------------------------------- Jan 26 12:45:25 volumio volumio[994]: info: ----- System startup ---- Jan 26 12:45:25 volumio volumio[994]: info: ------------------------------------------- Jan 26 12:45:25 volumio go-librespot[1016]: time="2026-01-26T12:45:25+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 26 12:45:25 volumio go-librespot[1016]: time="2026-01-26T12:45:25+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 26 12:45:25 volumio go-librespot[1016]: time="2026-01-26T12:45:25+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 26 12:45:25 volumio go-librespot[1016]: time="2026-01-26T12:45:25+07:00" level=info msg="zeroconf server listening on port 46189" Jan 26 12:45:25 volumio go-librespot[1016]: time="2026-01-26T12:45:25+07:00" level=debug msg="obtained new client token: AAAXKh3WBjbBJNxIQmvwL9lcpAFKc6aVYUbJB9F9MEjqFeAHe2CPhRLrV3JWFavJ2yWkEIMs27pcWtj9ekiDdj+O2cbEUOiwmL0+GTkjF3hfbPxQb4mA0Ul+rJ0e5493pg2Yrsnno2DPV7t37+GadYhojbYF9ub7rIc2Rj36H+l6yPcSz3sKZ07Pq1sVxdt+JUh7kHTCt8wg37SJW4U98Ne8w+cDoWEs9rw4Gc1Jok1bByDbgDa50CUB9wo=" Jan 26 12:45:25 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 12:45:25 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 12:45:25 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 12:45:26 volumio go-librespot[1016]: time="2026-01-26T12:45:26+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 26 12:45:26 volumio go-librespot[1016]: time="2026-01-26T12:45:26+07:00" level=debug msg="completed keyexchange" Jan 26 12:45:26 volumio go-librespot[1016]: time="2026-01-26T12:45:26+07:00" level=debug msg="completed challenge" Jan 26 12:45:26 volumio go-librespot[1016]: time="2026-01-26T12:45:26+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 26 12:45:26 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 26 12:45:26 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 26 12:45:26 volumio volumio-remote-updater[628]: [2026-01-26 12:45:26] [connect] Successful connection Jan 26 12:45:26 volumio volumio[994]: info: MYVOLUMIO Environment detected Jan 26 12:45:26 volumio volumio[994]: info: Plugin folders cleanup Jan 26 12:45:26 volumio volumio[994]: info: Scanning into folder /volumio/app/plugins/ Jan 26 12:45:26 volumio volumio[994]: info: Scanning category audio_interface Jan 26 12:45:26 volumio volumio[994]: info: Scanning category miscellanea Jan 26 12:45:26 volumio volumio[994]: info: Scanning category music_service Jan 26 12:45:26 volumio volumio[994]: info: Scanning category plugins.json Jan 26 12:45:26 volumio volumio[994]: info: Scanning category system_controller Jan 26 12:45:26 volumio volumio[994]: info: Scanning category user_interface Jan 26 12:45:26 volumio volumio[994]: info: Scanning into folder /data/plugins/ Jan 26 12:45:26 volumio volumio[994]: info: Scanning category music_service Jan 26 12:45:26 volumio volumio[994]: info: Plugin folders cleanup completed Jan 26 12:45:26 volumio volumio[994]: info: ------------------------------------------- Jan 26 12:45:26 volumio volumio[994]: info: ----- Core plugins startup ---- Jan 26 12:45:26 volumio volumio[994]: info: ------------------------------------------- Jan 26 12:45:26 volumio volumio[994]: info: Loading plugins from folder /volumio/app/plugins/ Jan 26 12:45:26 volumio volumio[994]: info: Adding plugin upnp to MyMusic Plugins Jan 26 12:45:26 volumio volumio[994]: info: Adding plugin airplay_emulation to MyMusic Plugins Jan 26 12:45:26 volumio volumio[994]: info: Adding plugin upnp_browser to MyMusic Plugins Jan 26 12:45:26 volumio volumio[994]: info: Loading plugins from folder /data/plugins/ Jan 26 12:45:26 volumio volumio[994]: info: Loading plugin "system"... Jan 26 12:45:26 volumio volumio[994]: info: Loading plugin "appearance"... Jan 26 12:45:27 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 12:45:27 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 12:45:27 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 12:45:28 volumio volumio[994]: info: Loading plugin "network"... Jan 26 12:45:28 volumio volumio[994]: info: Refreshing Cached IP Addresses Jan 26 12:45:28 volumio sudo[1033]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 26 12:45:28 volumio sudo[1033]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 12:45:28 volumio volumio[994]: info: Loading plugin "services"... Jan 26 12:45:28 volumio sudo[1035]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 26 12:45:28 volumio sudo[1035]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 12:45:28 volumio volumio[994]: info: Loading plugin "alsa_controller"... Jan 26 12:45:28 volumio sudo[1033]: pam_unix(sudo:session): session closed for user root Jan 26 12:45:28 volumio sudo[1035]: pam_unix(sudo:session): session closed for user root Jan 26 12:45:28 volumio sudo[1046]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Jan 26 12:45:28 volumio sudo[1046]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 12:45:29 volumio volumio[994]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 26 12:45:29 volumio volumio[994]: info: Loading plugin "wizard"... Jan 26 12:45:29 volumio volumio[994]: info: Loading plugin "networkfs"... Jan 26 12:45:29 volumio volumio[994]: info: Starting Udev Watcher for removable devices Jan 26 12:45:29 volumio volumio[994]: info: Ignoring mount for partition: boot Jan 26 12:45:29 volumio volumio[994]: info: Ignoring mount for partition: volumio Jan 26 12:45:29 volumio volumio[994]: info: Ignoring mount for partition: volumio_data Jan 26 12:45:29 volumio volumio[994]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 26 12:45:29 volumio volumio[994]: info: Loading plugin "volumio_command_line_client"... Jan 26 12:45:29 volumio volumio[994]: info: Loading plugin "upnp"... Jan 26 12:45:29 volumio volumio[994]: info: [1769406329209] Starting Upmpd Daemon Jan 26 12:45:29 volumio volumio[994]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 26 12:45:29 volumio volumio[994]: info: Loading plugin "my_music"... Jan 26 12:45:29 volumio volumio[994]: info: Loading plugin "mpd"... Jan 26 12:45:29 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Jan 26 12:45:29 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 26 12:45:29 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 26 12:45:29 volumio go-librespot[1072]: go-librespot daemon starting... Jan 26 12:45:29 volumio go-librespot[1073]: time="2026-01-26T12:45:29+07:00" level=info msg="running go-librespot 0.4.0" Jan 26 12:45:29 volumio go-librespot[1073]: time="2026-01-26T12:45:29+07:00" level=debug msg="app state loaded" Jan 26 12:45:29 volumio go-librespot[1073]: time="2026-01-26T12:45:29+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 26 12:45:29 volumio volumio[994]: info: Loading plugin "upnp_browser"... Jan 26 12:45:29 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 12:45:29 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 12:45:29 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 12:45:30 volumio go-librespot[1073]: time="2026-01-26T12:45:30+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 26 12:45:30 volumio go-librespot[1073]: time="2026-01-26T12:45:30+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 26 12:45:30 volumio go-librespot[1073]: time="2026-01-26T12:45:30+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 26 12:45:30 volumio go-librespot[1073]: time="2026-01-26T12:45:30+07:00" level=info msg="zeroconf server listening on port 33533" Jan 26 12:45:30 volumio go-librespot[1073]: time="2026-01-26T12:45:30+07:00" level=debug msg="obtained new client token: AAB+CsRf5w4nmPewgCpNGOuP16evaU8JtoTDXMXhqRB4t5LYoCc940Ld3Ap3gd3k3CRw+//YOACUA4MFaEcC6zNAM4RjvRnyAEdjCWzAAOYsrR1RzVRuSqdhZcOd4aqeJ/N2lcLq1+DJiUWP8kObtysOEKFtI/Tcg+Gk/AKUBaffZutILXVv++Oz9efAq/dDK89PO56LaecrSEfNhq9jKU7fT/8YJ3rF2bmYb9ownm4LoRbOJjVjjPiijp8=" Jan 26 12:45:30 volumio go-librespot[1073]: time="2026-01-26T12:45:30+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 26 12:45:30 volumio go-librespot[1073]: time="2026-01-26T12:45:30+07:00" level=debug msg="completed keyexchange" Jan 26 12:45:30 volumio go-librespot[1073]: time="2026-01-26T12:45:30+07:00" level=debug msg="completed challenge" Jan 26 12:45:30 volumio go-librespot[1073]: time="2026-01-26T12:45:30+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 26 12:45:30 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 26 12:45:30 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 26 12:45:31 volumio sudo[1046]: pam_unix(sudo:session): session closed for user root Jan 26 12:45:31 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 12:45:31 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 12:45:31 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 12:45:32 volumio volumio[994]: info: Starting UPNP Browser Jan 26 12:45:32 volumio volumio[994]: info: Loading plugin "alarm-clock"... Jan 26 12:45:33 volumio volumio[994]: info: Loading plugin "airplay_emulation"... Jan 26 12:45:33 volumio volumio[994]: info: Starting Shairport Sync Jan 26 12:45:33 volumio volumio[994]: info: Loading plugin "last_100"... Jan 26 12:45:33 volumio volumio[994]: info: Loading plugin "webradio"... Jan 26 12:45:33 volumio volumio[994]: info: Loading plugin "i2s_dacs"... Jan 26 12:45:33 volumio volumio[994]: info: Loading plugin "volumiodiscovery"... Jan 26 12:45:33 volumio volumio[994]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 26 12:45:33 volumio volumio[994]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 26 12:45:33 volumio volumio[994]: *** WARNING *** For more information see Jan 26 12:45:33 volumio volumio[994]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 26 12:45:33 volumio volumio[994]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 26 12:45:33 volumio volumio[994]: *** WARNING *** For more information see Jan 26 12:45:33 volumio node[994]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 26 12:45:33 volumio node[994]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 26 12:45:33 volumio node[994]: *** WARNING *** For more information see Jan 26 12:45:33 volumio node[994]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 26 12:45:33 volumio node[994]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 26 12:45:33 volumio node[994]: *** WARNING *** For more information see Jan 26 12:45:33 volumio volumio[994]: info: Applying required configuration parameters for plugin volumiodiscovery Jan 26 12:45:33 volumio volumio[994]: info: Discovery: Started advertising with name: Volumio Jan 26 12:45:33 volumio volumio[994]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 26 12:45:33 volumio volumio[994]: info: Loading plugin "spop"... Jan 26 12:45:33 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Jan 26 12:45:33 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 26 12:45:33 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 26 12:45:33 volumio go-librespot[1084]: go-librespot daemon starting... Jan 26 12:45:33 volumio go-librespot[1085]: time="2026-01-26T12:45:33+07:00" level=info msg="running go-librespot 0.4.0" Jan 26 12:45:33 volumio go-librespot[1085]: time="2026-01-26T12:45:33+07:00" level=debug msg="app state loaded" Jan 26 12:45:33 volumio go-librespot[1085]: time="2026-01-26T12:45:33+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 26 12:45:33 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 12:45:33 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 12:45:33 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 12:45:34 volumio go-librespot[1085]: time="2026-01-26T12:45:34+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 26 12:45:34 volumio go-librespot[1085]: time="2026-01-26T12:45:34+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 26 12:45:34 volumio go-librespot[1085]: time="2026-01-26T12:45:34+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 26 12:45:34 volumio go-librespot[1085]: time="2026-01-26T12:45:34+07:00" level=info msg="zeroconf server listening on port 44231" Jan 26 12:45:34 volumio go-librespot[1085]: time="2026-01-26T12:45:34+07:00" level=debug msg="obtained new client token: AAA5i0K5OhyCAMokr9VuSUiKVyUzmZ65GvrnA5oR5AjQD3GpSZngTGuGta0Gpd0MztluRFx1sNNCARSzeRMud509mj3T8/4m58SWG4FisDIHUe1DF8Li2eZUtiX9KgHs+dUFarEOTJ9NdVJFf2xF9he5UiZ7n1p63e2tbpVqhbJJcEEqE5w93mZt+LpWbRY7N2Rzo4eKwBJYZjYX5X1rtui+JS89oo+i1zzFXZ7Ws6g/SN+GHnmOOU0thV0=" Jan 26 12:45:34 volumio go-librespot[1085]: time="2026-01-26T12:45:34+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 26 12:45:34 volumio go-librespot[1085]: time="2026-01-26T12:45:34+07:00" level=debug msg="completed keyexchange" Jan 26 12:45:34 volumio go-librespot[1085]: time="2026-01-26T12:45:34+07:00" level=debug msg="completed challenge" Jan 26 12:45:34 volumio go-librespot[1085]: time="2026-01-26T12: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 26 12:45:34 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 26 12:45:34 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 26 12:45:35 volumio volumio[994]: info: Loading plugin "ytcr"... Jan 26 12:45:35 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 12:45:35 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 12:45:35 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 12:45:37 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Jan 26 12:45:37 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 26 12:45:38 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 12:45:38 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 12:45:38 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 12:45:38 volumio volumio[994]: info: Loading plugin "ytmusic"... Jan 26 12:45:38 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 26 12:45:38 volumio go-librespot[1092]: go-librespot daemon starting... Jan 26 12:45:38 volumio go-librespot[1093]: time="2026-01-26T12:45:38+07:00" level=info msg="running go-librespot 0.4.0" Jan 26 12:45:38 volumio go-librespot[1093]: time="2026-01-26T12:45:38+07:00" level=debug msg="app state loaded" Jan 26 12:45:38 volumio go-librespot[1093]: time="2026-01-26T12:45:38+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 26 12:45:38 volumio go-librespot[1093]: time="2026-01-26T12:45:38+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 26 12:45:38 volumio go-librespot[1093]: time="2026-01-26T12:45:38+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 26 12:45:38 volumio go-librespot[1093]: time="2026-01-26T12:45:38+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 26 12:45:38 volumio go-librespot[1093]: time="2026-01-26T12:45:38+07:00" level=info msg="zeroconf server listening on port 39937" Jan 26 12:45:38 volumio volumio-remote-updater[628]: [2026-01-26 12:45:38] [connect] Successful connection Jan 26 12:45:38 volumio go-librespot[1093]: time="2026-01-26T12:45:38+07:00" level=debug msg="obtained new client token: AAArdUV/pGfwMApTt22T7ohDJa9qjbFLYoGaKT1eYbQc6AU2lj4TQqMtYjeNRN951RFskeNSX/HQc8LUlbJalBY+l6xXef/2MoYW75s2A4lc4DEnp8h18O9zlJqozttvb3AXNXM+QinmCpDLExOGbCzNYtMCJXQnvlCDly/FrsEC5o7kZZgQMxWVohp4EaOrusFBTJzpnTKHz2A9R7BQ781+Da0dV1u1HqL5BSNVTrgh2ukwTptPxWvA8Mo=" Jan 26 12:45:39 volumio go-librespot[1093]: time="2026-01-26T12:45:39+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 26 12:45:39 volumio volumio[994]: info: Loading plugin "outputs"... Jan 26 12:45:39 volumio go-librespot[1093]: time="2026-01-26T12:45:39+07:00" level=debug msg="completed keyexchange" Jan 26 12:45:39 volumio go-librespot[1093]: time="2026-01-26T12:45:39+07:00" level=debug msg="completed challenge" Jan 26 12:45:39 volumio volumio[994]: info: Loading plugin "albumart"... Jan 26 12:45:39 volumio volumio[994]: info: Plugin example_plugin is not enabled Jan 26 12:45:39 volumio volumio[994]: info: Loading plugin "inputs"... Jan 26 12:45:39 volumio volumio[994]: info: Loading plugin "updater_comm"... Jan 26 12:45:39 volumio go-librespot[1093]: time="2026-01-26T12:45:39+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 26 12:45:39 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 26 12:45:39 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 26 12:45:39 volumio volumio[994]: info: Plugin mpdemulation is not enabled Jan 26 12:45:39 volumio volumio[994]: info: Loading plugin "rest_api"... Jan 26 12:45:39 volumio volumio[994]: info: Loading plugin "websocket"... Jan 26 12:45:39 volumio volumio[994]: info: Starting Socket.io Server version 1.7.4 Jan 26 12:45:39 volumio volumio[994]: info: Loading plugin "RoonBridge"... Jan 26 12:45:40 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 12:45:40 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 12:45:40 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 12:45:40 volumio volumio[994]: info: Applying required configuration parameters for plugin RoonBridge Jan 26 12:45:40 volumio volumio[994]: info: Loading i18n strings for locale en Jan 26 12:45:40 volumio volumio[994]: Updating browse sources language Jan 26 12:45:40 volumio volumio[994]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 26 12:45:40 volumio volumio[1114]: Forking 3 albumart workers Jan 26 12:45:40 volumio volumio[994]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 26 12:45:40 volumio volumio[994]: info: CoreCommandRouter::initPlayerControls Jan 26 12:45:40 volumio volumio[994]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 12:45:40 volumio volumio[994]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 12:45:40 volumio volumio[994]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 12:45:40 volumio volumio[994]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 12:45:40 volumio volumio[994]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 12:45:40 volumio volumio[994]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 12:45:40 volumio volumio[994]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 12:45:40 volumio volumio[994]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 12:45:40 volumio volumio[994]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 26 12:45:40 volumio volumio[994]: Express server listening on port 3000 Jan 26 12:45:40 volumio volumio[994]: [Metrics] WebUI: 16s 113.05ms Jan 26 12:45:40 volumio volumio[994]: info: CoreStateMachine::resetVolumioState Jan 26 12:45:40 volumio volumio[994]: info: CoreStateMachine::getcurrentVolume Jan 26 12:45:40 volumio volumio[994]: info: CoreCommandRouter::volumioRetrievevolume Jan 26 12:45:40 volumio sudo[1161]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 26 12:45:40 volumio sudo[1161]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 12:45:40 volumio sudo[1163]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 26 12:45:40 volumio sudo[1163]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 12:45:40 volumio sudo[1161]: pam_unix(sudo:session): session closed for user root Jan 26 12:45:40 volumio sudo[1163]: pam_unix(sudo:session): session closed for user root Jan 26 12:45:40 volumio volumio[994]: info: Volumio Network Manager: Network status updated: 1 Jan 26 12:45:40 volumio volumio[994]: info: VolumeController:: Volume=100 Mute =false Jan 26 12:45:40 volumio volumio[994]: info: CoreStateMachine::pushState Jan 26 12:45:40 volumio volumio[994]: info: CorePlayQueue::getTrack 0 Jan 26 12:45:40 volumio volumio[994]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 26 12:45:40 volumio volumio[994]: info: CoreCommandRouter::volumioPushState Jan 26 12:45:40 volumio volumio[994]: info: CoreStateMachine::updateTrackBlock Jan 26 12:45:40 volumio volumio[994]: info: CorePlayQueue::getTrackBlock Jan 26 12:45:40 volumio volumio[994]: info: CoreCommandRouter::volumioRetrievevolume Jan 26 12:45:41 volumio volumio-remote-updater[628]: [2026-01-26 12:45:41] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1769406338 101 Jan 26 12:45:41 volumio volumio[994]: 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 26 12:45:41 volumio volumio[994]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 12:45:41 volumio volumio[994]: info: Reloading queue from file Jan 26 12:45:41 volumio volumio[994]: info: CoreStateMachine::setRepeat null single undefined Jan 26 12:45:41 volumio volumio[994]: info: CoreStateMachine::pushState Jan 26 12:45:41 volumio volumio[994]: info: CorePlayQueue::getTrack 0 Jan 26 12:45:41 volumio volumio[994]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 26 12:45:41 volumio volumio[994]: info: CoreCommandRouter::volumioPushState Jan 26 12:45:41 volumio volumio[994]: info: CoreStateMachine::setRandom null Jan 26 12:45:41 volumio volumio[994]: info: CoreStateMachine::pushState Jan 26 12:45:41 volumio volumio[994]: info: CorePlayQueue::getTrack 0 Jan 26 12:45:41 volumio volumio[994]: info: CoreCommandRouter::volumioPushState Jan 26 12:45:41 volumio volumio[994]: info: Setting Device type: Raspberry PI Jan 26 12:45:41 volumio volumio[994]: info: Completed loading Core Plugins Jan 26 12:45:41 volumio volumio[994]: info: Preparing to generate the ALSA configuration file Jan 26 12:45:41 volumio volumio[994]: info: VolumeController:: Volume=100 Mute =false Jan 26 12:45:41 volumio volumio[994]: info: CoreStateMachine::pushState Jan 26 12:45:41 volumio volumio[994]: info: CorePlayQueue::getTrack 0 Jan 26 12:45:41 volumio volumio[994]: info: CoreCommandRouter::volumioPushState Jan 26 12:45:41 volumio volumio[994]: info: Asound.conf file unchanged, so no further update is needed Jan 26 12:45:41 volumio volumio[994]: info: Output device has changed, restarting MPD Jan 26 12:45:41 volumio sudo[1180]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Jan 26 12:45:41 volumio sudo[1180]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 12:45:41 volumio sudo[1183]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 26 12:45:41 volumio sudo[1183]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 12:45:41 volumio sudo[1183]: pam_unix(sudo:session): session closed for user root Jan 26 12:45:41 volumio volumio[994]: info: Output device has changed, restarting Shairport Sync Jan 26 12:45:41 volumio volumio[994]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 12:45:41 volumio volumio[994]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 12:45:41 volumio sudo[1187]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 26 12:45:41 volumio sudo[1187]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 12:45:41 volumio volumio[994]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 26 12:45:41 volumio volumio[994]: info: ___________ START PLUGINS ___________ Jan 26 12:45:41 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Jan 26 12:45:41 volumio volumio[994]: info: ControllerMpd::onStart: Initializing MPD Jan 26 12:45:41 volumio volumio[994]: info: Creating MPD Configuration file Jan 26 12:45:41 volumio sudo[1180]: pam_unix(sudo:session): session closed for user root Jan 26 12:45:41 volumio volumio[994]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 26 12:45:41 volumio volumio[994]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 26 12:45:41 volumio volumio[994]: info: [1769406341865] CoreMusicLibrary::Adding element Media Servers Jan 26 12:45:41 volumio volumio[994]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 26 12:45:41 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 26 12:45:41 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 26 12:45:41 volumio systemd[1]: mpd.service: Consumed 7.351s CPU time. Jan 26 12:45:41 volumio sudo[1196]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 26 12:45:41 volumio sudo[1196]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 12:45:41 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 26 12:45:41 volumio sudo[1194]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 26 12:45:41 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 26 12:45:41 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 26 12:45:41 volumio sudo[1194]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 12:45:41 volumio volumio[994]: info: UPNP Browser: Client initialized successfully Jan 26 12:45:41 volumio sudo[1194]: pam_unix(sudo:session): session closed for user root Jan 26 12:45:41 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 26 12:45:41 volumio volumio[994]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 12:45:42 volumio volumio[994]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 12:45:42 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 12:45:42 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 12:45:42 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 12:45:42 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 26 12:45:42 volumio volumio[994]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 26 12:45:42 volumio volumio[994]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 12:45:42 volumio volumio[994]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 12:45:42 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 26 12:45:42 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 26 12:45:42 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 26 12:45:42 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 26 12:45:42 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 26 12:45:42 volumio volumio[994]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 26 12:45:42 volumio volumio[994]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 26 12:45:42 volumio volumio[994]: info: [1769406342159] CoreMusicLibrary::Adding element Last_100 Jan 26 12:45:42 volumio volumio[994]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 26 12:45:42 volumio volumio[994]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 26 12:45:42 volumio volumio[994]: info: [1769406342172] CoreMusicLibrary::Adding element Webradio Jan 26 12:45:42 volumio volumio[994]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 26 12:45:42 volumio volumio[994]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 26 12:45:42 volumio volumio[994]: info: Initializing BBC Radios Jan 26 12:45:42 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 26 12:45:42 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 26 12:45:42 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Jan 26 12:45:42 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 26 12:45:42 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 26 12:45:42 volumio go-librespot[1220]: go-librespot daemon starting... Jan 26 12:45:42 volumio volumio[994]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 26 12:45:42 volumio volumio[994]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 12:45:42 volumio go-librespot[1223]: time="2026-01-26T12:45:42+07:00" level=info msg="running go-librespot 0.4.0" Jan 26 12:45:42 volumio go-librespot[1223]: time="2026-01-26T12:45:42+07:00" level=debug msg="app state loaded" Jan 26 12:45:42 volumio go-librespot[1223]: time="2026-01-26T12:45:42+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 26 12:45:42 volumio volumio[994]: info: Creating Spotify config file Jan 26 12:45:42 volumio volumio[994]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 12:45:42 volumio sudo[1218]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 26 12:45:42 volumio sudo[1218]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jan 26 12:45:42 volumio sudo[1218]: pam_unix(sudo:session): session closed for user root Jan 26 12:45:43 volumio go-librespot[1223]: time="2026-01-26T12:45:43+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 26 12:45:43 volumio go-librespot[1223]: time="2026-01-26T12:45:43+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 26 12:45:43 volumio go-librespot[1223]: time="2026-01-26T12:45:43+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 26 12:45:43 volumio go-librespot[1223]: time="2026-01-26T12:45:43+07:00" level=info msg="zeroconf server listening on port 34045" Jan 26 12:45:43 volumio go-librespot[1223]: time="2026-01-26T12:45:43+07:00" level=debug msg="obtained new client token: AAA6pdLGzUFpnRCnznc2CcHMTmBhqDXldYMgsTz3YTSXf+MVs2/LwPH5uE8QwRHRcTRyj5WJf+/u2l+ezHEgrM9cPiJ38XgwLRfGVguBp5fosvPd/1diLzWMizyRakUF9ZewexcETCIm/oprR4XeHSx40b1KMI9S3/fK3uFBEedZAC/t8HwA0lU+0+pswa56J8+gx3IEXZV/j9svOrdXyGea6F97O7ehsczVUTmxwkSXOgL2Vz5fZf04olw=" Jan 26 12:45:43 volumio go-librespot[1223]: time="2026-01-26T12:45:43+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 26 12:45:43 volumio go-librespot[1223]: time="2026-01-26T12:45:43+07:00" level=debug msg="completed keyexchange" Jan 26 12:45:43 volumio go-librespot[1223]: time="2026-01-26T12:45:43+07:00" level=debug msg="completed challenge" Jan 26 12:45:43 volumio go-librespot[1223]: time="2026-01-26T12:45:43+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 26 12:45:43 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 26 12:45:43 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 26 12:45:43 volumio volumio[1129]: Starting albumart workers Jan 26 12:45:43 volumio volumio[1130]: Starting albumart workers Jan 26 12:45:44 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 12:45:44 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 12:45:44 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 12:45:44 volumio volumio[1128]: Starting albumart workers Jan 26 12:45:44 volumio volumio[994]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 26 12:45:44 volumio volumio[994]: info: [1769406344043] CoreMusicLibrary::Adding element YouTube Music Jan 26 12:45:44 volumio volumio[994]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 26 12:45:44 volumio volumio[994]: Cannot find translation for source YouTube Music Jan 26 12:45:44 volumio volumio[994]: info: Volumio Calling Home Jan 26 12:45:44 volumio sudo[1236]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Jan 26 12:45:44 volumio sudo[1236]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 12:45:44 volumio sudo[1236]: pam_unix(sudo:session): session closed for user root Jan 26 12:45:44 volumio volumio[994]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Jan 26 12:45:44 volumio volumio[994]: info: Discovery: Found device Volumio Jan 26 12:45:44 volumio volumio[994]: info: CoreCommandRouter::volumioGetState Jan 26 12:45:44 volumio volumio[994]: info: CorePlayQueue::getTrack 0 Jan 26 12:45:44 volumio volumio[994]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Jan 26 12:45:44 volumio volumio[994]: info: Discovery: Found device Volumio Jan 26 12:45:44 volumio volumio[994]: info: CoreCommandRouter::volumioGetState Jan 26 12:45:44 volumio volumio[994]: info: CorePlayQueue::getTrack 0 Jan 26 12:45:44 volumio volumio[994]: info: MPD Permissions set Jan 26 12:45:44 volumio volumio[994]: info: MPD Permissions set Jan 26 12:45:44 volumio volumio[994]: info: Upmpdcli Daemon Started Jan 26 12:45:44 volumio volumio[994]: info: Spotify config file written Jan 26 12:45:45 volumio sudo[1242]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jan 26 12:45:45 volumio sudo[1242]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 12:45:45 volumio volumio[994]: 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 26 12:45:45 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 26 12:45:45 volumio volumio[994]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 12:45:45 volumio volumio[994]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 12:45:45 volumio volumio[994]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 12:45:45 volumio volumio[994]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 12:45:45 volumio volumio[994]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 12:45:45 volumio volumio[994]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 12:45:45 volumio volumio[994]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 12:45:45 volumio volumio[994]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 12:45:45 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 26 12:45:45 volumio go-librespot[1244]: go-librespot daemon starting... Jan 26 12:45:45 volumio sudo[1242]: pam_unix(sudo:session): session closed for user root Jan 26 12:45:45 volumio volumio[994]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 12:45:45 volumio volumio[994]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 12:45:45 volumio go-librespot[1249]: time="2026-01-26T12:45:45+07:00" level=info msg="running go-librespot 0.4.0" Jan 26 12:45:45 volumio go-librespot[1249]: time="2026-01-26T12:45:45+07:00" level=debug msg="app state loaded" Jan 26 12:45:45 volumio go-librespot[1249]: time="2026-01-26T12:45:45+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 26 12:45:45 volumio volumio[994]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 12:45:45 volumio volumio[994]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 12:45:45 volumio volumio[994]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 12:45:45 volumio volumio[994]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 12:45:45 volumio volumio[994]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 12:45:45 volumio volumio[994]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 12:45:45 volumio volumio[994]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 12:45:45 volumio volumio[994]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 12:45:45 volumio volumio[994]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 12:45:45 volumio volumio[994]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 12:45:45 volumio volumio[994]: info: No need to fix Spotify hosts Jan 26 12:45:46 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 12:45:46 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 12:45:46 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 12:45:46 volumio go-librespot[1249]: time="2026-01-26T12: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 26 12:45:46 volumio go-librespot[1249]: time="2026-01-26T12: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 26 12:45:46 volumio go-librespot[1249]: time="2026-01-26T12: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 26 12:45:46 volumio go-librespot[1249]: time="2026-01-26T12:45:46+07:00" level=info msg="zeroconf server listening on port 46255" Jan 26 12:45:46 volumio go-librespot[1249]: time="2026-01-26T12:45:46+07:00" level=debug msg="obtained new client token: AAAGbUzNxwbqX+9WmjyJSxp4vBVK6cJbQ1pBlOZSgKffV5pLP0puBqTZk0jUXXJ4ZXtwwB6EXIOKQmdcIMq2Jxs79fkfK05ZhRFixIl5zfOPz1K6tu9auBWIvcRNqJXHhjrXsAxwIyyZMP/YKj9c9BZQtxsIqyeOslP4gtQHtFLZMd6KyW9sXb3uiP44+2wpRbzDW8/fnLdn2Q73MCDhVHNuMGd5BkdhVbzi2KgyFrVfiZ6vIW8i8G9tvjQ=" Jan 26 12:45:46 volumio volumio[994]: info: Volumio called home Jan 26 12:45:46 volumio go-librespot[1249]: time="2026-01-26T12:45:46+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 26 12:45:46 volumio go-librespot[1249]: time="2026-01-26T12:45:46+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Jan 26 12:45:46 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 26 12:45:46 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 26 12:45:46 volumio volumio[994]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 26 12:45:46 volumio volumio[994]: SPOTIFY: BQDm29ErEvYpg8tZ6VD-fbKzzI0TlWC_cFys5pvmB27ylrsWxagIgp_xX_1QUYqyrtxMcCXPi7AthYkmc_LDKuK0y0Heil1EpUcCOMaqdAJlcq0auez8rCPQ5ZSToFYJRaAVJ2YWiYqj0FP9aC4EAM1SnW3VsN_uzigbItPwKRtDtkiwVK-8mLMoWKmJRlFEHiYzYv2GCx5LglT-U1XV6kETMzVVJ9FukYoE9bRZJPe8_el_vyzDzNFnxpn-9T84b6LsWSiCuiieUp0BJmg4Pw8nLTtuLLBEv3y1MX370rqmQX5uG2dYY3uo Jan 26 12:45:46 volumio volumio[994]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 26 12:45:46 volumio volumio[994]: info: New Spotify access token = BQDm29ErEvYpg8tZ6VD-fbKzzI0TlWC_cFys5pvmB27ylrsWxagIgp_xX_1QUYqyrtxMcCXPi7AthYkmc_LDKuK0y0Heil1EpUcCOMaqdAJlcq0auez8rCPQ5ZSToFYJRaAVJ2YWiYqj0FP9aC4EAM1SnW3VsN_uzigbItPwKRtDtkiwVK-8mLMoWKmJRlFEHiYzYv2GCx5LglT-U1XV6kETMzVVJ9FukYoE9bRZJPe8_el_vyzDzNFnxpn-9T84b6LsWSiCuiieUp0BJmg4Pw8nLTtuLLBEv3y1MX370rqmQX5uG2dYY3uo Jan 26 12:45:46 volumio volumio[994]: info: Spotify credentials grant success - running version from March 24, 2019 Jan 26 12:45:46 volumio volumio[994]: info: Starting Shairport Sync Jan 26 12:45:46 volumio volumio[994]: info: Starting Shairport Sync Jan 26 12:45:46 volumio volumio[994]: info: Starting Shairport Sync Jan 26 12:45:47 volumio sudo[1282]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 26 12:45:47 volumio sudo[1282]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 12:45:47 volumio sudo[1284]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 26 12:45:47 volumio sudo[1284]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 12:45:47 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 26 12:45:47 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Jan 26 12:45:47 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 26 12:45:47 volumio systemd[1]: shairport-sync.service: Consumed 2.366s CPU time. Jan 26 12:45:47 volumio sudo[1286]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 26 12:45:47 volumio sudo[1286]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 12:45:47 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 26 12:45:47 volumio sudo[1282]: pam_unix(sudo:session): session closed for user root Jan 26 12:45:47 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 26 12:45:47 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Jan 26 12:45:47 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 26 12:45:47 volumio volumio[994]: info: Shairport-Sync Started Jan 26 12:45:47 volumio volumio[994]: Error adding Membership: Error: addMembership EINVAL Jan 26 12:45:47 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 26 12:45:47 volumio sudo[1284]: pam_unix(sudo:session): session closed for user root Jan 26 12:45:47 volumio sudo[1286]: pam_unix(sudo:session): session closed for user root Jan 26 12:45:47 volumio volumio[994]: info: CoreCommandRouter::volumioGetState Jan 26 12:45:47 volumio volumio[994]: info: CorePlayQueue::getTrack 0 Jan 26 12:45:47 volumio volumio[994]: info: Shairport-Sync Started Jan 26 12:45:47 volumio volumio[994]: info: Shairport-Sync Started Jan 26 12:45:47 volumio volumio[994]: 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 26 12:45:47 volumio volumio[994]: info: Spotify Successfully logged in Jan 26 12:45:47 volumio volumio[994]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 26 12:45:47 volumio volumio[994]: info: [1769406347808] CoreMusicLibrary::Adding element Spotify Jan 26 12:45:47 volumio volumio[994]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 26 12:45:47 volumio volumio[994]: Cannot find translation for source YouTube Music Jan 26 12:45:47 volumio volumio[994]: Cannot find translation for source Spotify Jan 26 12:45:48 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 12:45:48 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 12:45:48 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 12:45:48 volumio volumio[994]: info: [yt-cast-receiver] DIAL server listening on port 8098 Jan 26 12:45:48 volumio volumio[994]: info: CoreCommandRouter::volumioRetrievevolume Jan 26 12:45:48 volumio volumio[994]: info: VolumeController:: Volume=100 Mute =false Jan 26 12:45:48 volumio volumio[994]: info: CoreCommandRouter::volumioGetState Jan 26 12:45:48 volumio volumio[994]: info: CorePlayQueue::getTrack 0 Jan 26 12:45:48 volumio volumio[994]: info: CoreStateMachine::pushState Jan 26 12:45:48 volumio volumio[994]: info: CorePlayQueue::getTrack 0 Jan 26 12:45:48 volumio volumio[994]: info: CoreCommandRouter::volumioPushState Jan 26 12:45:49 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Jan 26 12:45:49 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 26 12:45:49 volumio volumio[994]: info: go-librespot daemon successfully initialized Jan 26 12:45:49 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 26 12:45:49 volumio go-librespot[1335]: go-librespot daemon starting... Jan 26 12:45:49 volumio go-librespot[1336]: time="2026-01-26T12:45:49+07:00" level=info msg="running go-librespot 0.4.0" Jan 26 12:45:49 volumio go-librespot[1336]: time="2026-01-26T12:45:49+07:00" level=debug msg="app state loaded" Jan 26 12:45:49 volumio go-librespot[1336]: time="2026-01-26T12:45:49+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 26 12:45:49 volumio mpd[1234]: 2026-01-26T12:45:49 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 26 12:45:49 volumio systemd[1]: Started mpd.service - Music Player Daemon. Jan 26 12:45:49 volumio sudo[1187]: pam_unix(sudo:session): session closed for user root Jan 26 12:45:49 volumio sudo[1196]: pam_unix(sudo:session): session closed for user root Jan 26 12:45:50 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 12:45:50 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 12:45:50 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 12:45:50 volumio volumio[994]: error: MPD error: The expression evaluated to a falsy value: Jan 26 12:45:50 volumio volumio[994]: assert.ok(self.idling) Jan 26 12:45:50 volumio volumio[994]: error: The expression evaluated to a falsy value: Jan 26 12:45:50 volumio volumio[994]: assert.ok(self.idling) Jan 26 12:45:50 volumio volumio[994]: error: updateQueue error: null Jan 26 12:45:50 volumio volumio[994]: info: Completed starting Core Plugins Jan 26 12:45:50 volumio volumio[994]: info: ------------------------------------------- Jan 26 12:45:50 volumio volumio[994]: info: ----- MyVolumio plugins startup ---- Jan 26 12:45:50 volumio volumio[994]: info: ------------------------------------------- Jan 26 12:45:50 volumio volumio[994]: info: [MyVolumio PluginManager] Fetching plans data.... Jan 26 12:45:50 volumio volumio[994]: info: MPD running with PID1234 Jan 26 12:45:50 volumio volumio[994]: ,establishing connection Jan 26 12:45:50 volumio volumio[994]: error: updateQueue error: null Jan 26 12:45:50 volumio go-librespot[1336]: time="2026-01-26T12: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 26 12:45:50 volumio go-librespot[1336]: time="2026-01-26T12: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 26 12:45:50 volumio go-librespot[1336]: time="2026-01-26T12: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 26 12:45:50 volumio go-librespot[1336]: time="2026-01-26T12:45:50+07:00" level=info msg="zeroconf server listening on port 40951" Jan 26 12:45:50 volumio go-librespot[1336]: time="2026-01-26T12:45:50+07:00" level=debug msg="obtained new client token: AAAyQUbMlmXsLXcSELBqgE1Hp5KsJN3+BSi8BN7Y7w37Wibww3OkmDuX68Bxm1oqbx2WsQSKNkZRRgVZNNwjp3QAQVTG2T7vA2Nh00z+a0XPFK5j3FJ4wdTvLKWVyTKtvgaNyqMQTVitMO4ld8Ny2P093DzS0NHQt3ctWVaaRLhoUy0Wv9+kHouIwEWhIpvx09zDkMEKwXmApmfvGKbqG8HIqaRW4R5iisQUeBteNVo8fovS3eTA/pOYu2k=" Jan 26 12:45:50 volumio go-librespot[1336]: time="2026-01-26T12:45:50+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 26 12:45:51 volumio go-librespot[1336]: time="2026-01-26T12:45:51+07:00" level=debug msg="completed keyexchange" Jan 26 12:45:51 volumio go-librespot[1336]: time="2026-01-26T12:45:51+07:00" level=debug msg="completed challenge" Jan 26 12:45:51 volumio go-librespot[1336]: time="2026-01-26T12: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 26 12:45:51 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 26 12:45:51 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 26 12:45:52 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 12:45:52 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 12:45:52 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 12:45:52 volumio volumio[994]: info: Initializing connection to go-librespot Websocket Jan 26 12:45:52 volumio volumio[994]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 26 12:45:54 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 12:45:54 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 12:45:54 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 12:45:54 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Jan 26 12:45:54 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 26 12:45:54 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 26 12:45:54 volumio go-librespot[1349]: go-librespot daemon starting... Jan 26 12:45:54 volumio go-librespot[1350]: time="2026-01-26T12:45:54+07:00" level=info msg="running go-librespot 0.4.0" Jan 26 12:45:54 volumio go-librespot[1350]: time="2026-01-26T12:45:54+07:00" level=debug msg="app state loaded" Jan 26 12:45:54 volumio go-librespot[1350]: time="2026-01-26T12:45:54+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 26 12:45:54 volumio go-librespot[1350]: time="2026-01-26T12:45:54+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 26 12:45:54 volumio go-librespot[1350]: time="2026-01-26T12:45:54+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 26 12:45:54 volumio go-librespot[1350]: time="2026-01-26T12:45:54+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 26 12:45:54 volumio go-librespot[1350]: time="2026-01-26T12:45:54+07:00" level=info msg="zeroconf server listening on port 46393" Jan 26 12:45:55 volumio volumio[994]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Jan 26 12:45:55 volumio go-librespot[1350]: time="2026-01-26T12:45:55+07:00" level=debug msg="obtained new client token: AABYkUw2GeW3pWDWUQEQ6pSjYTPZTK7WVNiqRFlLKiFDBvKrraTNyfEwq5Km131Eo0M+o6mITw7UVzatp7HtmEqZN2yDwfUYWraWleMjxh68ETXnEyje2Ts2CIHmCfK/icfg5AoiTvEgbQSqP4+EBxVDZyTFRGwQscvNDzRqfb/0OypslrL/wAceJOmScmuHKZWwPT1PathuI5EF5KHCkdLedwFGpArwmhDGVmi3EwwAwDAoWU4aczgF" Jan 26 12:45:55 volumio go-librespot[1350]: time="2026-01-26T12:45:55+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 26 12:45:55 volumio go-librespot[1350]: time="2026-01-26T12:45:55+07:00" level=debug msg="completed keyexchange" Jan 26 12:45:55 volumio go-librespot[1350]: time="2026-01-26T12:45:55+07:00" level=debug msg="completed challenge" Jan 26 12:45:55 volumio go-librespot[1350]: time="2026-01-26T12:45: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 26 12:45:55 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 26 12:45:55 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 26 12:45:55 volumio volumio[994]: info: Initializing connection to go-librespot Websocket Jan 26 12:45:55 volumio volumio[994]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 26 12:45:56 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 12:45:56 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 12:45:56 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 12:45:58 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 12:45:58 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 12:45:58 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 12:45:58 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 11. Jan 26 12:45:58 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 26 12:45:58 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 26 12:45:58 volumio go-librespot[1358]: go-librespot daemon starting... Jan 26 12:45:58 volumio go-librespot[1359]: time="2026-01-26T12:45:58+07:00" level=info msg="running go-librespot 0.4.0" Jan 26 12:45:58 volumio go-librespot[1359]: time="2026-01-26T12:45:58+07:00" level=debug msg="app state loaded" Jan 26 12:45:58 volumio go-librespot[1359]: time="2026-01-26T12:45:58+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 26 12:45:58 volumio volumio[994]: info: Initializing connection to go-librespot Websocket Jan 26 12:45:58 volumio go-librespot[1359]: time="2026-01-26T12:45:58+07:00" level=debug msg="new websocket client" Jan 26 12:45:58 volumio volumio[994]: info: Connection to go-librespot Websocket established Jan 26 12:45:59 volumio volumio[994]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Jan 26 12:45:59 volumio volumio[994]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Jan 26 12:45:59 volumio volumio[994]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Jan 26 12:45:59 volumio volumio[994]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Jan 26 12:45:59 volumio volumio[994]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Jan 26 12:45:59 volumio volumio[994]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Jan 26 12:45:59 volumio volumio[994]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Jan 26 12:45:59 volumio volumio[994]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Jan 26 12:45:59 volumio volumio[994]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Jan 26 12:45:59 volumio volumio[994]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Jan 26 12:45:59 volumio volumio[994]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Jan 26 12:45:59 volumio volumio[994]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Jan 26 12:45:59 volumio volumio[994]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Jan 26 12:45:59 volumio volumio[994]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Jan 26 12:45:59 volumio volumio[994]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Jan 26 12:45:59 volumio volumio[994]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Jan 26 12:45:59 volumio volumio[994]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Jan 26 12:45:59 volumio volumio[994]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Jan 26 12:45:59 volumio volumio[994]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Jan 26 12:45:59 volumio volumio[994]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Jan 26 12:45:59 volumio volumio[994]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Jan 26 12:45:59 volumio volumio[994]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Jan 26 12:45:59 volumio volumio[994]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Jan 26 12:45:59 volumio volumio[994]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Jan 26 12:45:59 volumio volumio[994]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Jan 26 12:45:59 volumio volumio[994]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Jan 26 12:45:59 volumio volumio[994]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Jan 26 12:45:59 volumio volumio[994]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Jan 26 12:45:59 volumio volumio[994]: info: Adding plugin bluetooth to MyMusic Plugins Jan 26 12:45:59 volumio volumio[994]: info: Adding plugin multiroom to MyMusic Plugins Jan 26 12:45:59 volumio volumio[994]: info: Adding plugin metavolumio to MyMusic Plugins Jan 26 12:45:59 volumio volumio[994]: info: Adding plugin cd_controller to MyMusic Plugins Jan 26 12:45:59 volumio volumio[994]: info: Adding plugin qobuzconnect to MyMusic Plugins Jan 26 12:45:59 volumio volumio[994]: info: Adding plugin smart_inputs to MyMusic Plugins Jan 26 12:45:59 volumio volumio[994]: info: Adding plugin tidalconnect to MyMusic Plugins Jan 26 12:45:59 volumio volumio[994]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Jan 26 12:45:59 volumio go-librespot[1359]: time="2026-01-26T12:45:59+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 26 12:45:59 volumio go-librespot[1359]: time="2026-01-26T12:45:59+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 26 12:45:59 volumio go-librespot[1359]: time="2026-01-26T12:45:59+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 26 12:45:59 volumio go-librespot[1359]: time="2026-01-26T12:45:59+07:00" level=info msg="zeroconf server listening on port 42191" Jan 26 12:45:59 volumio go-librespot[1359]: time="2026-01-26T12:45:59+07:00" level=debug msg="obtained new client token: AAAxMA6iwIlWSJXflLq+IbCh9GifUgdMlKDWYrdkypncHsDJozpjyYf6+mtRpl9+273FuG8sfct18DLzwie6oVzECLK3myfMw31bE97r+khd1GqJNz6nf6VKLGCvxmI9Uqj4f7BgeBHTZNFLVtFCiFITtEK6Yu7VuSP5g1UbqmUcsi3sWMZTsTG5GV2NWAtntgkDYUK0afJHBRQXiHGGwr9UDZ5Sap5qrhsEN7CJg01zZjsEytYrO5FBH6k=" Jan 26 12:45:59 volumio go-librespot[1359]: time="2026-01-26T12:45:59+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 26 12:45:59 volumio go-librespot[1359]: time="2026-01-26T12:45:59+07:00" level=debug msg="completed keyexchange" Jan 26 12:45:59 volumio go-librespot[1359]: time="2026-01-26T12:45:59+07:00" level=debug msg="completed challenge" Jan 26 12:45:59 volumio go-librespot[1359]: time="2026-01-26T12:45:59+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 26 12:45:59 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 26 12:45:59 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 26 12:46:00 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 12:46:00 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 12:46:00 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 12:46:00 volumio volumio[994]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Jan 26 12:46:00 volumio volumio[994]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Jan 26 12:46:00 volumio volumio[994]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 12:46:00 volumio volumio[994]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 12:46:00 volumio volumio[994]: info: Starting MyVolumio Remote Streaming Endpoints Jan 26 12:46:00 volumio volumio[994]: info: MyVolumio login type: Token Jan 26 12:46:01 volumio volumio[994]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Jan 26 12:46:01 volumio volumio[994]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Jan 26 12:46:02 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 12:46:02 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 12:46:02 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 12:46:02 volumio volumio[994]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Jan 26 12:46:02 volumio volumio[994]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Jan 26 12:46:02 volumio volumio[994]: info: Streaming services startup Jan 26 12:46:02 volumio volumio[994]: info: Starting Streaming Daemon Jan 26 12:46:02 volumio sudo[1381]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jan 26 12:46:02 volumio sudo[1381]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 12:46:02 volumio volumio[994]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Jan 26 12:46:02 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 12. Jan 26 12:46:02 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 26 12:46:02 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 26 12:46:02 volumio go-librespot[1390]: go-librespot daemon starting... Jan 26 12:46:02 volumio sudo[1381]: pam_unix(sudo:session): session closed for user root Jan 26 12:46:03 volumio volumio[994]: info: Getting Spotify volume Jan 26 12:46:03 volumio go-librespot[1394]: time="2026-01-26T12:46:03+07:00" level=info msg="running go-librespot 0.4.0" Jan 26 12:46:03 volumio go-librespot[1394]: time="2026-01-26T12:46:03+07:00" level=debug msg="app state loaded" Jan 26 12:46:03 volumio go-librespot[1394]: time="2026-01-26T12:46:03+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 26 12:46:03 volumio volumio[994]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 26 12:46:03 volumio volumio[994]: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 26 12:46:03 volumio volumio[994]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Jan 26 12:46:03 volumio volumio[994]: errno: -111, Jan 26 12:46:03 volumio volumio[994]: code: 'ECONNREFUSED', Jan 26 12:46:03 volumio volumio[994]: syscall: 'connect', Jan 26 12:46:03 volumio volumio[994]: address: '127.0.0.1', Jan 26 12:46:03 volumio volumio[994]: port: 9879, Jan 26 12:46:03 volumio volumio[994]: response: undefined Jan 26 12:46:03 volumio volumio[994]: } Jan 26 12:46:03 volumio volumio[994]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 26 12:46:03 volumio go-librespot[1394]: time="2026-01-26T12:46:03+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 26 12:46:03 volumio go-librespot[1394]: time="2026-01-26T12:46:03+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 26 12:46:03 volumio go-librespot[1394]: time="2026-01-26T12:46:03+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 26 12:46:03 volumio go-librespot[1394]: time="2026-01-26T12:46:03+07:00" level=info msg="zeroconf server listening on port 42829" Jan 26 12:46:03 volumio go-librespot[1394]: time="2026-01-26T12:46:03+07:00" level=debug msg="obtained new client token: AACylmqTpNJUNZmfj3qnHI4ad2KfsDNvzsPvCcufV4dxb0DJoO+8GLxyNmtaY29mGnGFEFdS7KTMHjguuzFsvAn5wbptVgl5mTTpHsFTUtF8bJCgLiOvfYKIn5M1g3B7YRDM2Q/PrR+LR6Ch0iIrSjeq3I9LNA5L731xqqaC0+1u1/YlWnd1mHN9KxV+L2TArskHM2NsIkVTx4eCSzwYJ83TFoCLBKgcauo8YBfsb4haHLx0rpRRyixYNJM=" Jan 26 12:46:03 volumio go-librespot[1394]: time="2026-01-26T12:46:03+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 26 12:46:03 volumio go-librespot[1394]: time="2026-01-26T12:46:03+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Jan 26 12:46:03 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 26 12:46:03 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 26 12:46:04 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 12:46:04 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 12:46:04 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 12:46:04 volumio sudo[1416]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-01-26 12:45' Jan 26 12:46:04 volumio sudo[1416]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 12:46:04 volumio sudo[1416]: pam_unix(sudo:session): session closed for user root Jan 26 12:46:04 volumio volumio-remote-updater[628]: [2026-01-26 12:46:04] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Jan 26 12:46:04 volumio volumio-remote-updater[628]: [2026-01-26 12:46:04] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Jan 26 12:46:04 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Jan 26 12:46:05 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Jan 26 12:46:05 volumio systemd[1]: volumio.service: Consumed 1min 8.819s CPU time. Jan 26 12:46:05 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 26 12:46:05 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Jan 26 12:46:05 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 6974. Jan 26 12:46:05 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 26 12:46:05 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Jan 26 12:46:05 volumio systemd[1]: volumio.service: Consumed 1min 8.819s CPU time. Jan 26 12:46:05 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Jan 26 12:46:05 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Jan 26 12:46:06 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 12:46:06 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 12:46:06 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 12:46:06 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 13. Jan 26 12:46:06 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 26 12:46:07 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 26 12:46:07 volumio go-librespot[1444]: go-librespot daemon starting... Jan 26 12:46:07 volumio go-librespot[1445]: time="2026-01-26T12:46:07+07:00" level=info msg="running go-librespot 0.4.0" Jan 26 12:46:07 volumio go-librespot[1445]: time="2026-01-26T12:46:07+07:00" level=debug msg="app state loaded" Jan 26 12:46:07 volumio go-librespot[1445]: time="2026-01-26T12:46:07+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 26 12:46:07 volumio go-librespot[1445]: time="2026-01-26T12:46:07+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 26 12:46:07 volumio go-librespot[1445]: time="2026-01-26T12:46:07+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 26 12:46:07 volumio go-librespot[1445]: time="2026-01-26T12:46:07+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 26 12:46:07 volumio go-librespot[1445]: time="2026-01-26T12:46:07+07:00" level=info msg="zeroconf server listening on port 46087" Jan 26 12:46:07 volumio go-librespot[1445]: time="2026-01-26T12:46:07+07:00" level=debug msg="obtained new client token: AADmfQC+DNs8s34YeBGh51RqlJDaiTFfBWzBFFGl4CJyV3mT5VNCcAaRH36Fo56b85m9XgeYErE0nusPPuHL0xYJS9TYagBDl4w+w0QGkb2S1RKDOo7U7nyDOLrnNvjJcVgR8LHgTvF1mz6Kq8LJJ/CNVUGSMsQ3yvVsxMHrpfBEoUt+KHrMFTYRiA9rF7cSsbh1Nr9ZuxXloTmmn/vUrsryflUS7AihaAdaCanXozejbjCj2k4RwcMuOH8=" Jan 26 12:46:08 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 12:46:08 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 12:46:08 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 12:46:08 volumio go-librespot[1445]: time="2026-01-26T12:46:08+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 26 12:46:08 volumio go-librespot[1445]: time="2026-01-26T12:46:08+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Jan 26 12:46:08 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 26 12:46:08 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 26 12:46:08 volumio volumio[1429]: info: ------------------------------------------- Jan 26 12:46:08 volumio volumio[1429]: info: ----- Volumio3 ---- Jan 26 12:46:08 volumio volumio[1429]: info: ------------------------------------------- Jan 26 12:46:08 volumio volumio[1429]: info: ----- System startup ---- Jan 26 12:46:08 volumio volumio[1429]: info: ------------------------------------------- Jan 26 12:46:09 volumio volumio-remote-updater[628]: [2026-01-26 12:46:09] [connect] Successful connection Jan 26 12:46:10 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 12:46:10 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 12:46:10 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 12:46:10 volumio volumio[1429]: info: MYVOLUMIO Environment detected Jan 26 12:46:10 volumio volumio[1429]: info: Plugin folders cleanup Jan 26 12:46:10 volumio volumio[1429]: info: Scanning into folder /volumio/app/plugins/ Jan 26 12:46:10 volumio volumio[1429]: info: Scanning category audio_interface Jan 26 12:46:10 volumio volumio[1429]: info: Scanning category miscellanea Jan 26 12:46:10 volumio volumio[1429]: info: Scanning category music_service Jan 26 12:46:10 volumio volumio[1429]: info: Scanning category plugins.json Jan 26 12:46:10 volumio volumio[1429]: info: Scanning category system_controller Jan 26 12:46:10 volumio volumio[1429]: info: Scanning category user_interface Jan 26 12:46:10 volumio volumio[1429]: info: Scanning into folder /data/plugins/ Jan 26 12:46:10 volumio volumio[1429]: info: Scanning category music_service Jan 26 12:46:10 volumio volumio[1429]: info: Plugin folders cleanup completed Jan 26 12:46:10 volumio volumio[1429]: info: ------------------------------------------- Jan 26 12:46:10 volumio volumio[1429]: info: ----- Core plugins startup ---- Jan 26 12:46:10 volumio volumio[1429]: info: ------------------------------------------- Jan 26 12:46:10 volumio volumio[1429]: info: Loading plugins from folder /volumio/app/plugins/ Jan 26 12:46:10 volumio volumio[1429]: info: Adding plugin upnp to MyMusic Plugins Jan 26 12:46:10 volumio volumio[1429]: info: Adding plugin airplay_emulation to MyMusic Plugins Jan 26 12:46:10 volumio volumio[1429]: info: Adding plugin upnp_browser to MyMusic Plugins Jan 26 12:46:10 volumio volumio[1429]: info: Loading plugins from folder /data/plugins/ Jan 26 12:46:10 volumio volumio[1429]: info: Loading plugin "system"... Jan 26 12:46:10 volumio volumio[1429]: info: Loading plugin "appearance"... Jan 26 12:46:11 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 14. Jan 26 12:46:11 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 26 12:46:11 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 26 12:46:11 volumio go-librespot[1471]: go-librespot daemon starting... Jan 26 12:46:11 volumio go-librespot[1472]: time="2026-01-26T12:46:11+07:00" level=info msg="running go-librespot 0.4.0" Jan 26 12:46:11 volumio go-librespot[1472]: time="2026-01-26T12:46:11+07:00" level=debug msg="app state loaded" Jan 26 12:46:11 volumio go-librespot[1472]: time="2026-01-26T12:46:11+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 26 12:46:11 volumio go-librespot[1472]: time="2026-01-26T12:46: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 26 12:46:11 volumio go-librespot[1472]: time="2026-01-26T12:46:11+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 26 12:46:11 volumio go-librespot[1472]: time="2026-01-26T12:46:11+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 26 12:46:11 volumio go-librespot[1472]: time="2026-01-26T12:46:11+07:00" level=info msg="zeroconf server listening on port 33585" Jan 26 12:46:12 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 12:46:12 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 12:46:12 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 12:46:12 volumio go-librespot[1472]: time="2026-01-26T12:46:12+07:00" level=debug msg="obtained new client token: AABvC3Aq67x5qkOWevjOEEymO8eLiUXjkQei5NsE26UAJR/kc4gJvFYsLd8VykB9jZRFb3r3dMv0EVsjywPW/eSWWyg/nRtfcQVFWJ2r1usD+b91nLLtF+KxvFZ7jChr/lTyJlEvDhSdyNpAMkkDdqq213+WSog2vgLL6GPRpWwc7Ueht/6TqDw8atm5W1ofF7eWYDhwHTv0yTZQP1huXMIIFsGOSR/IkqiyaWzN9vJ/zTQrBiFAVzQB" Jan 26 12:46:12 volumio go-librespot[1472]: time="2026-01-26T12:46:12+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 26 12:46:12 volumio go-librespot[1472]: time="2026-01-26T12:46:12+07:00" level=debug msg="completed keyexchange" Jan 26 12:46:12 volumio go-librespot[1472]: time="2026-01-26T12:46:12+07:00" level=debug msg="completed challenge" Jan 26 12:46:12 volumio volumio[1429]: info: Loading plugin "network"... Jan 26 12:46:12 volumio go-librespot[1472]: time="2026-01-26T12:46: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 26 12:46:12 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 26 12:46:12 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 26 12:46:12 volumio volumio[1429]: info: Refreshing Cached IP Addresses Jan 26 12:46:12 volumio sudo[1480]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 26 12:46:12 volumio sudo[1480]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 12:46:12 volumio sudo[1482]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 26 12:46:12 volumio sudo[1482]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 12:46:12 volumio sudo[1480]: pam_unix(sudo:session): session closed for user root Jan 26 12:46:12 volumio volumio[1429]: info: Loading plugin "services"... Jan 26 12:46:12 volumio sudo[1482]: pam_unix(sudo:session): session closed for user root Jan 26 12:46:12 volumio volumio[1429]: info: Loading plugin "alsa_controller"... Jan 26 12:46:12 volumio sudo[1491]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Jan 26 12:46:12 volumio sudo[1491]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 12:46:12 volumio volumio[1429]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 26 12:46:12 volumio volumio[1429]: info: Loading plugin "wizard"... Jan 26 12:46:12 volumio volumio[1429]: info: Loading plugin "networkfs"... Jan 26 12:46:12 volumio volumio[1429]: info: Starting Udev Watcher for removable devices Jan 26 12:46:12 volumio volumio[1429]: info: Ignoring mount for partition: boot Jan 26 12:46:12 volumio volumio[1429]: info: Ignoring mount for partition: volumio Jan 26 12:46:12 volumio volumio[1429]: info: Ignoring mount for partition: volumio_data Jan 26 12:46:12 volumio volumio[1429]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 26 12:46:12 volumio volumio[1429]: info: Loading plugin "volumio_command_line_client"... Jan 26 12:46:12 volumio volumio[1429]: info: Loading plugin "upnp"... Jan 26 12:46:12 volumio volumio[1429]: info: [1769406372783] Starting Upmpd Daemon Jan 26 12:46:12 volumio volumio[1429]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 26 12:46:12 volumio volumio[1429]: info: Loading plugin "my_music"... Jan 26 12:46:12 volumio volumio[1429]: info: Loading plugin "mpd"... Jan 26 12:46:13 volumio volumio[1429]: info: Loading plugin "upnp_browser"... Jan 26 12:46:14 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 12:46:14 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 12:46:14 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 12:46:15 volumio sudo[1491]: pam_unix(sudo:session): session closed for user root Jan 26 12:46:15 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 15. Jan 26 12:46:15 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 26 12:46:15 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 26 12:46:15 volumio go-librespot[1517]: go-librespot daemon starting... Jan 26 12:46:15 volumio go-librespot[1520]: time="2026-01-26T12:46:15+07:00" level=info msg="running go-librespot 0.4.0" Jan 26 12:46:15 volumio go-librespot[1520]: time="2026-01-26T12:46:15+07:00" level=debug msg="app state loaded" Jan 26 12:46:15 volumio go-librespot[1520]: time="2026-01-26T12:46:15+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 26 12:46:16 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 12:46:16 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 12:46:16 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 12:46:16 volumio go-librespot[1520]: time="2026-01-26T12:46:16+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 26 12:46:16 volumio go-librespot[1520]: time="2026-01-26T12:46:16+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Jan 26 12:46:16 volumio go-librespot[1520]: time="2026-01-26T12:46:16+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Jan 26 12:46:16 volumio go-librespot[1520]: time="2026-01-26T12:46:16+07:00" level=info msg="zeroconf server listening on port 37245" Jan 26 12:46:16 volumio volumio[1429]: info: Starting UPNP Browser Jan 26 12:46:16 volumio volumio[1429]: info: Loading plugin "alarm-clock"... Jan 26 12:46:16 volumio go-librespot[1520]: time="2026-01-26T12:46:16+07:00" level=debug msg="obtained new client token: AABEgKtoK/8I2retBLV79omtHMMDh52gy7ewtWLUouZZqCXf9IM7BgvhaozMmgUHH4oLnCaIZBsT+ZMYmpMwU5VLoaOqPjds7jGNam5ekYGXgxNG2sO4PXdFxjH44vd2W+fmlPN1A6TQVKIGGgKYDZrZMlZy5rfu8qwCAC0dlZRFgYLYYLaFQwXse06aIPaF+DS7ZIKjFKji/k89Lb2jOmFbHpu7iQlvicwryLmPkoLtL+IrqMBeVX8NQ/o=" Jan 26 12:46:16 volumio go-librespot[1520]: time="2026-01-26T12:46:16+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 26 12:46:16 volumio go-librespot[1520]: time="2026-01-26T12:46:16+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Jan 26 12:46:16 volumio go-librespot[1520]: time="2026-01-26T12:46:16+07:00" level=debug msg="completed keyexchange" Jan 26 12:46:16 volumio go-librespot[1520]: time="2026-01-26T12:46:16+07:00" level=debug msg="completed challenge" Jan 26 12:46:16 volumio volumio[1429]: info: Loading plugin "airplay_emulation"... Jan 26 12:46:16 volumio volumio[1429]: info: Starting Shairport Sync Jan 26 12:46:16 volumio volumio[1429]: info: Loading plugin "last_100"... Jan 26 12:46:16 volumio volumio[1429]: info: Loading plugin "webradio"... Jan 26 12:46:16 volumio go-librespot[1520]: time="2026-01-26T12:46: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 26 12:46:16 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 26 12:46:16 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 26 12:46:16 volumio volumio[1429]: info: Loading plugin "i2s_dacs"... Jan 26 12:46:16 volumio volumio[1429]: info: Loading plugin "volumiodiscovery"... Jan 26 12:46:17 volumio volumio[1429]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 26 12:46:17 volumio volumio[1429]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 26 12:46:17 volumio volumio[1429]: *** WARNING *** For more information see Jan 26 12:46:17 volumio volumio[1429]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 26 12:46:17 volumio volumio[1429]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 26 12:46:17 volumio volumio[1429]: *** WARNING *** For more information see Jan 26 12:46:17 volumio node[1429]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 26 12:46:17 volumio node[1429]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 26 12:46:17 volumio node[1429]: *** WARNING *** For more information see Jan 26 12:46:17 volumio node[1429]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 26 12:46:17 volumio node[1429]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 26 12:46:17 volumio node[1429]: *** WARNING *** For more information see Jan 26 12:46:17 volumio volumio[1429]: info: Applying required configuration parameters for plugin volumiodiscovery Jan 26 12:46:17 volumio volumio[1429]: info: Discovery: Started advertising with name: Volumio Jan 26 12:46:17 volumio volumio[1429]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 26 12:46:17 volumio volumio[1429]: info: Loading plugin "spop"... Jan 26 12:46:18 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 12:46:18 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 12:46:18 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 12:46:18 volumio volumio[1429]: info: Loading plugin "ytcr"... Jan 26 12:46:19 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 16. Jan 26 12:46:19 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 26 12:46:20 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 12:46:20 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 12:46:20 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 12:46:20 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 26 12:46:20 volumio go-librespot[1533]: go-librespot daemon starting... Jan 26 12:46:20 volumio go-librespot[1534]: time="2026-01-26T12:46:20+07:00" level=info msg="running go-librespot 0.4.0" Jan 26 12:46:20 volumio go-librespot[1534]: time="2026-01-26T12:46:20+07:00" level=debug msg="app state loaded" Jan 26 12:46:20 volumio go-librespot[1534]: time="2026-01-26T12:46:20+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 26 12:46:20 volumio go-librespot[1534]: time="2026-01-26T12:46: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-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 26 12:46:20 volumio go-librespot[1534]: time="2026-01-26T12:46:20+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 26 12:46:20 volumio go-librespot[1534]: time="2026-01-26T12:46:20+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 26 12:46:20 volumio go-librespot[1534]: time="2026-01-26T12:46:20+07:00" level=info msg="zeroconf server listening on port 36955" Jan 26 12:46:20 volumio go-librespot[1534]: time="2026-01-26T12:46:20+07:00" level=debug msg="obtained new client token: AADfjW4V4kPG25TDhuyyqY6xVOsnONpvEpMYPFZgpd9nHic7Ueqo8zJBgSmkgrXj29+wPgO1v3Pkaj5sQGrTZb84jHa/mFOVqtBUi5n2Rc/auifNc5XkLKi+yG/6ZJDwfUoP8WC4Pd6fIRrIM+1a/kSiwoeIhHAZp1xMIsTAG6RkjCwKNhcRxuU5SOKfq+dlj+n6dYntNDlXBbouju1sf0jWX5VhhXgrEiFPSh14ajiGm5hWPjqci6wO8dU=" Jan 26 12:46:20 volumio go-librespot[1534]: time="2026-01-26T12:46:20+07:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:4070, retrying with a different AP" error="dial tcp 104.199.241.202:4070: connect: connection refused" Jan 26 12:46:20 volumio go-librespot[1534]: time="2026-01-26T12:46:20+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Jan 26 12:46:21 volumio go-librespot[1534]: time="2026-01-26T12:46:21+07:00" level=debug msg="completed keyexchange" Jan 26 12:46:21 volumio go-librespot[1534]: time="2026-01-26T12:46:21+07:00" level=debug msg="completed challenge" Jan 26 12:46:21 volumio go-librespot[1534]: time="2026-01-26T12:46: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 26 12:46:21 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 26 12:46:21 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 26 12:46:21 volumio volumio[1429]: info: Loading plugin "ytmusic"... Jan 26 12:46:22 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 12:46:22 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 12:46:22 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 12:46:22 volumio volumio-remote-updater[628]: [2026-01-26 12:46:22] [connect] Successful connection Jan 26 12:46:22 volumio volumio[1429]: info: Loading plugin "outputs"... Jan 26 12:46:22 volumio volumio[1429]: info: Loading plugin "albumart"... Jan 26 12:46:22 volumio volumio[1429]: info: Plugin example_plugin is not enabled Jan 26 12:46:22 volumio volumio[1429]: info: Loading plugin "inputs"... Jan 26 12:46:22 volumio volumio[1429]: info: Loading plugin "updater_comm"... Jan 26 12:46:22 volumio volumio[1429]: info: Plugin mpdemulation is not enabled Jan 26 12:46:22 volumio volumio[1429]: info: Loading plugin "rest_api"... Jan 26 12:46:22 volumio volumio[1429]: info: Loading plugin "websocket"... Jan 26 12:46:23 volumio volumio[1429]: info: Starting Socket.io Server version 1.7.4 Jan 26 12:46:23 volumio volumio[1429]: info: Loading plugin "RoonBridge"... Jan 26 12:46:23 volumio volumio[1429]: info: Applying required configuration parameters for plugin RoonBridge Jan 26 12:46:23 volumio volumio[1429]: info: Loading i18n strings for locale en Jan 26 12:46:23 volumio volumio[1429]: Updating browse sources language Jan 26 12:46:23 volumio volumio[1429]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 26 12:46:23 volumio volumio[1429]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 26 12:46:23 volumio volumio[1555]: Forking 3 albumart workers Jan 26 12:46:23 volumio volumio[1429]: info: CoreCommandRouter::initPlayerControls Jan 26 12:46:23 volumio volumio[1429]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 12:46:23 volumio volumio[1429]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 12:46:23 volumio volumio[1429]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 12:46:23 volumio volumio[1429]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 12:46:23 volumio volumio[1429]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 12:46:23 volumio volumio[1429]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 12:46:23 volumio volumio[1429]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 12:46:23 volumio volumio[1429]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 12:46:23 volumio volumio[1429]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 26 12:46:23 volumio volumio[1429]: Express server listening on port 3000 Jan 26 12:46:23 volumio volumio[1429]: [Metrics] WebUI: 15s 956.63ms Jan 26 12:46:23 volumio volumio[1429]: info: CoreStateMachine::resetVolumioState Jan 26 12:46:23 volumio volumio[1429]: info: CoreStateMachine::getcurrentVolume Jan 26 12:46:23 volumio volumio[1429]: info: CoreCommandRouter::volumioRetrievevolume Jan 26 12:46:24 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 12:46:24 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 12:46:24 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 12:46:24 volumio volumio[1429]: info: Volumio Network Manager: Network status updated: 1 Jan 26 12:46:24 volumio sudo[1600]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 26 12:46:24 volumio sudo[1600]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 12:46:24 volumio sudo[1598]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 26 12:46:24 volumio sudo[1598]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 12:46:24 volumio sudo[1600]: pam_unix(sudo:session): session closed for user root Jan 26 12:46:24 volumio sudo[1598]: pam_unix(sudo:session): session closed for user root Jan 26 12:46:24 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 17. Jan 26 12:46:24 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 26 12:46:24 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 26 12:46:24 volumio go-librespot[1609]: go-librespot daemon starting... Jan 26 12:46:24 volumio go-librespot[1610]: time="2026-01-26T12:46:24+07:00" level=info msg="running go-librespot 0.4.0" Jan 26 12:46:24 volumio go-librespot[1610]: time="2026-01-26T12:46:24+07:00" level=debug msg="app state loaded" Jan 26 12:46:24 volumio go-librespot[1610]: time="2026-01-26T12:46:24+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 26 12:46:24 volumio volumio[1429]: info: VolumeController:: Volume=100 Mute =false Jan 26 12:46:24 volumio volumio[1429]: info: CoreStateMachine::pushState Jan 26 12:46:24 volumio volumio[1429]: info: CorePlayQueue::getTrack 0 Jan 26 12:46:24 volumio volumio[1429]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 26 12:46:24 volumio volumio[1429]: info: CoreCommandRouter::volumioPushState Jan 26 12:46:24 volumio volumio[1429]: info: CoreStateMachine::updateTrackBlock Jan 26 12:46:24 volumio volumio[1429]: info: CorePlayQueue::getTrackBlock Jan 26 12:46:24 volumio volumio[1429]: info: CoreCommandRouter::volumioRetrievevolume Jan 26 12:46:24 volumio volumio-remote-updater[628]: [2026-01-26 12:46:24] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1769406382 101 Jan 26 12:46:24 volumio volumio[1429]: 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 26 12:46:24 volumio volumio[1429]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 12:46:24 volumio volumio[1429]: info: Reloading queue from file Jan 26 12:46:24 volumio volumio[1429]: info: CoreStateMachine::setRepeat null single undefined Jan 26 12:46:24 volumio volumio[1429]: info: CoreStateMachine::pushState Jan 26 12:46:24 volumio volumio[1429]: info: CorePlayQueue::getTrack 0 Jan 26 12:46:24 volumio volumio[1429]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 26 12:46:24 volumio volumio[1429]: info: CoreCommandRouter::volumioPushState Jan 26 12:46:24 volumio volumio[1429]: info: CoreStateMachine::setRandom null Jan 26 12:46:24 volumio volumio[1429]: info: CoreStateMachine::pushState Jan 26 12:46:24 volumio volumio[1429]: info: CorePlayQueue::getTrack 0 Jan 26 12:46:24 volumio volumio[1429]: info: CoreCommandRouter::volumioPushState Jan 26 12:46:24 volumio volumio[1429]: info: Setting Device type: Raspberry PI Jan 26 12:46:24 volumio volumio[1429]: info: Completed loading Core Plugins Jan 26 12:46:24 volumio volumio[1429]: info: Preparing to generate the ALSA configuration file Jan 26 12:46:24 volumio go-librespot[1610]: time="2026-01-26T12:46: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 26 12:46:24 volumio go-librespot[1610]: time="2026-01-26T12:46:24+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 26 12:46:24 volumio go-librespot[1610]: time="2026-01-26T12:46:24+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 26 12:46:25 volumio go-librespot[1610]: time="2026-01-26T12:46:25+07:00" level=info msg="zeroconf server listening on port 33059" Jan 26 12:46:25 volumio volumio[1429]: info: VolumeController:: Volume=100 Mute =false Jan 26 12:46:25 volumio volumio[1429]: info: CoreStateMachine::pushState Jan 26 12:46:25 volumio volumio[1429]: info: CorePlayQueue::getTrack 0 Jan 26 12:46:25 volumio volumio[1429]: info: CoreCommandRouter::volumioPushState Jan 26 12:46:25 volumio volumio[1429]: info: Asound.conf file unchanged, so no further update is needed Jan 26 12:46:25 volumio volumio[1429]: info: Output device has changed, restarting MPD Jan 26 12:46:25 volumio sudo[1627]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Jan 26 12:46:25 volumio sudo[1627]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 12:46:25 volumio volumio[1429]: info: Output device has changed, restarting Shairport Sync Jan 26 12:46:25 volumio volumio[1429]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 12:46:25 volumio sudo[1633]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 26 12:46:25 volumio volumio[1429]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 12:46:25 volumio sudo[1633]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 12:46:25 volumio sudo[1629]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 26 12:46:25 volumio sudo[1629]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 12:46:25 volumio sudo[1629]: pam_unix(sudo:session): session closed for user root Jan 26 12:46:25 volumio volumio[1429]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 26 12:46:25 volumio go-librespot[1610]: time="2026-01-26T12:46:25+07:00" level=debug msg="obtained new client token: AABR4QDGyX3auRkTf5nMWKLc0f3WKzMD9bAB19lsToeHh9JuciFFwu7I9bILiX0AG5sanDzHV4+x89OmGt7WC6ACLhvK5iekzGd6PLxFLOGe0h78oJwHxdkxg73znqyPpqw9DvdCiFzpbHUxn2l01fFVL3YZ2UrWR2Up9tagpeCrCmy12RBYwBy6Cwo4iuGUGcOOBygc9R1RJNP1BmXa2SLjjvSst90TTYNfUnCODx5UDpLQlxJakupE" Jan 26 12:46:25 volumio volumio[1429]: info: ___________ START PLUGINS ___________ Jan 26 12:46:25 volumio sudo[1627]: pam_unix(sudo:session): session closed for user root Jan 26 12:46:25 volumio volumio[1429]: info: ControllerMpd::onStart: Initializing MPD Jan 26 12:46:25 volumio volumio[1429]: info: Creating MPD Configuration file Jan 26 12:46:25 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Jan 26 12:46:25 volumio volumio[1429]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 26 12:46:25 volumio volumio[1429]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 26 12:46:25 volumio volumio[1429]: info: [1769406385385] CoreMusicLibrary::Adding element Media Servers Jan 26 12:46:25 volumio volumio[1429]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 26 12:46:25 volumio sudo[1642]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 26 12:46:25 volumio sudo[1642]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 12:46:25 volumio go-librespot[1610]: time="2026-01-26T12:46:25+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 26 12:46:25 volumio sudo[1642]: pam_unix(sudo:session): session closed for user root Jan 26 12:46:25 volumio volumio[1429]: info: UPNP Browser: Client initialized successfully Jan 26 12:46:25 volumio go-librespot[1610]: time="2026-01-26T12:46:25+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Jan 26 12:46:25 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 26 12:46:25 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 26 12:46:25 volumio systemd[1]: mpd.service: Consumed 7.350s CPU time. Jan 26 12:46:25 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 26 12:46:25 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 26 12:46:25 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 26 12:46:25 volumio sudo[1643]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 26 12:46:25 volumio sudo[1643]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 12:46:25 volumio volumio[1429]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 12:46:25 volumio volumio[1429]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 12:46:25 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 26 12:46:25 volumio volumio[1429]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 26 12:46:25 volumio volumio[1429]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 12:46:25 volumio volumio[1429]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 12:46:25 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 26 12:46:25 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 26 12:46:25 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 26 12:46:25 volumio volumio[1429]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 26 12:46:25 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 26 12:46:25 volumio volumio[1429]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 26 12:46:25 volumio volumio[1429]: info: [1769406385770] CoreMusicLibrary::Adding element Last_100 Jan 26 12:46:25 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 26 12:46:25 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 26 12:46:25 volumio volumio[1429]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 26 12:46:25 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 26 12:46:25 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 26 12:46:25 volumio volumio[1429]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 26 12:46:25 volumio volumio[1429]: info: [1769406385802] CoreMusicLibrary::Adding element Webradio Jan 26 12:46:25 volumio volumio[1429]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 26 12:46:25 volumio volumio[1429]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 26 12:46:25 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 26 12:46:25 volumio volumio[1429]: info: Initializing BBC Radios Jan 26 12:46:25 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 26 12:46:26 volumio volumio[1429]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 26 12:46:26 volumio volumio[1429]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 12:46:26 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 12:46:26 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 12:46:26 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 12:46:26 volumio volumio[1429]: info: Creating Spotify config file Jan 26 12:46:26 volumio volumio[1429]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 12:46:26 volumio sudo[1657]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 26 12:46:26 volumio sudo[1657]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jan 26 12:46:26 volumio sudo[1657]: pam_unix(sudo:session): session closed for user root Jan 26 12:46:27 volumio volumio[1566]: Starting albumart workers Jan 26 12:46:27 volumio volumio[1567]: Starting albumart workers Jan 26 12:46:27 volumio volumio[1429]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 26 12:46:27 volumio volumio[1429]: info: [1769406387441] CoreMusicLibrary::Adding element YouTube Music Jan 26 12:46:27 volumio volumio[1429]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 26 12:46:27 volumio volumio[1429]: Cannot find translation for source YouTube Music Jan 26 12:46:27 volumio volumio[1429]: info: Volumio Calling Home Jan 26 12:46:27 volumio volumio[1565]: Starting albumart workers Jan 26 12:46:27 volumio sudo[1674]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Jan 26 12:46:27 volumio sudo[1674]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 12:46:27 volumio sudo[1674]: pam_unix(sudo:session): session closed for user root Jan 26 12:46:28 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 12:46:28 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 12:46:28 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 12:46:28 volumio volumio[1429]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Jan 26 12:46:28 volumio volumio[1429]: info: Discovery: Found device Volumio Jan 26 12:46:28 volumio volumio[1429]: info: CoreCommandRouter::volumioGetState Jan 26 12:46:28 volumio volumio[1429]: info: CorePlayQueue::getTrack 0 Jan 26 12:46:28 volumio volumio[1429]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Jan 26 12:46:28 volumio volumio[1429]: info: Discovery: Found device Volumio Jan 26 12:46:28 volumio volumio[1429]: info: CoreCommandRouter::volumioGetState Jan 26 12:46:28 volumio volumio[1429]: info: CorePlayQueue::getTrack 0 Jan 26 12:46:28 volumio volumio[1429]: info: MPD Permissions set Jan 26 12:46:28 volumio volumio[1429]: info: MPD Permissions set Jan 26 12:46:28 volumio volumio[1429]: info: Upmpdcli Daemon Started Jan 26 12:46:28 volumio volumio[1429]: info: Spotify config file written Jan 26 12:46:28 volumio volumio[1429]: 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 26 12:46:28 volumio sudo[1680]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jan 26 12:46:28 volumio volumio[1429]: info: Volumio called home Jan 26 12:46:28 volumio volumio[1429]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 12:46:28 volumio volumio[1429]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 12:46:28 volumio volumio[1429]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 12:46:28 volumio sudo[1680]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 12:46:28 volumio volumio[1429]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 12:46:28 volumio volumio[1429]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 12:46:28 volumio volumio[1429]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 12:46:28 volumio volumio[1429]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 12:46:28 volumio volumio[1429]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 12:46:28 volumio volumio[1429]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 12:46:28 volumio volumio[1429]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 12:46:28 volumio volumio[1429]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 12:46:28 volumio volumio[1429]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 12:46:28 volumio volumio[1429]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 12:46:28 volumio volumio[1429]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 12:46:28 volumio volumio[1429]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 12:46:28 volumio volumio[1429]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 12:46:28 volumio volumio[1429]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 12:46:28 volumio volumio[1429]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 12:46:28 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 26 12:46:28 volumio volumio[1429]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 12:46:28 volumio volumio[1429]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 12:46:28 volumio volumio[1429]: info: No need to fix Spotify hosts Jan 26 12:46:28 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 26 12:46:28 volumio go-librespot[1692]: go-librespot daemon starting... Jan 26 12:46:28 volumio sudo[1680]: pam_unix(sudo:session): session closed for user root Jan 26 12:46:28 volumio go-librespot[1693]: time="2026-01-26T12:46:28+07:00" level=info msg="running go-librespot 0.4.0" Jan 26 12:46:28 volumio go-librespot[1693]: time="2026-01-26T12:46:28+07:00" level=debug msg="app state loaded" Jan 26 12:46:28 volumio go-librespot[1693]: time="2026-01-26T12:46:28+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 26 12:46:29 volumio go-librespot[1693]: time="2026-01-26T12:46: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 26 12:46:29 volumio go-librespot[1693]: time="2026-01-26T12:46: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 26 12:46:29 volumio go-librespot[1693]: time="2026-01-26T12:46: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 26 12:46:29 volumio go-librespot[1693]: time="2026-01-26T12:46:29+07:00" level=info msg="zeroconf server listening on port 34701" Jan 26 12:46:29 volumio go-librespot[1693]: time="2026-01-26T12:46:29+07:00" level=debug msg="obtained new client token: AABKqlR+844auu6kqmFACx28n004CwilrW79gTJjRAMZGC3N6dm8OrBsmy3uZPdI0QdokBTFDRDBSN2KYFy9pz/6YSuixnp1j+UQBMznldC1iO9kxwbxrpBwsHP310dEHM/80VnbpN+4ch3iWho2nmEoCXsLBDatZAsnbRkKD5Nx9ceu3szGi8gqmv4Zy70lIbxMqU9IwDK8IoMfrmBrC4oEvMMICRdWR9LLczog4QfhH2IpLBbRWjkb0hM=" Jan 26 12:46:30 volumio go-librespot[1693]: time="2026-01-26T12:46:30+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 26 12:46:30 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 12:46:30 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 12:46:30 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 12:46:30 volumio go-librespot[1693]: time="2026-01-26T12:46:30+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Jan 26 12:46:30 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 26 12:46:30 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 26 12:46:30 volumio volumio[1429]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 26 12:46:30 volumio volumio[1429]: SPOTIFY: BQAR_AP_1agzaBSc8BfG-zj6_oJeR-23rEIi1O8tHu2lz4ELGOEBa01T5RvVkwQNuATdl3Y3N4ZVJ9p0vpCXnThHwF7cTz8Y3Ev4fw7S2qWO4-ua35CsGflQBOPALbdUcr7wtQqSdg3YqeeH3j0aKY4-YzFMdGCquahiqX-dKt3ODPGOh3GgzIwInqJ4kn2DZCQic-YhR4wUWSe2kJiwlRuGJ86R4mOQTDN9yiLdratW8--Bd-mSQW5Tj9nwlp9mvSWr2LiFwB7_wyW2e2VNmdfzBjXY3rlIpj48N9pGcXLu694KGm-Ogkzu Jan 26 12:46:30 volumio volumio[1429]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 26 12:46:30 volumio volumio[1429]: info: New Spotify access token = BQAR_AP_1agzaBSc8BfG-zj6_oJeR-23rEIi1O8tHu2lz4ELGOEBa01T5RvVkwQNuATdl3Y3N4ZVJ9p0vpCXnThHwF7cTz8Y3Ev4fw7S2qWO4-ua35CsGflQBOPALbdUcr7wtQqSdg3YqeeH3j0aKY4-YzFMdGCquahiqX-dKt3ODPGOh3GgzIwInqJ4kn2DZCQic-YhR4wUWSe2kJiwlRuGJ86R4mOQTDN9yiLdratW8--Bd-mSQW5Tj9nwlp9mvSWr2LiFwB7_wyW2e2VNmdfzBjXY3rlIpj48N9pGcXLu694KGm-Ogkzu Jan 26 12:46:30 volumio volumio[1429]: info: Spotify credentials grant success - running version from March 24, 2019 Jan 26 12:46:30 volumio volumio[1429]: info: Starting Shairport Sync Jan 26 12:46:30 volumio volumio[1429]: info: Starting Shairport Sync Jan 26 12:46:30 volumio volumio[1429]: info: Starting Shairport Sync Jan 26 12:46:30 volumio sudo[1721]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 26 12:46:30 volumio sudo[1721]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 12:46:30 volumio sudo[1723]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 26 12:46:30 volumio sudo[1723]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 12:46:30 volumio sudo[1725]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 26 12:46:30 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 26 12:46:30 volumio sudo[1725]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 12:46:30 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Jan 26 12:46:30 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 26 12:46:30 volumio systemd[1]: shairport-sync.service: Consumed 2.389s CPU time. Jan 26 12:46:30 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 26 12:46:30 volumio sudo[1721]: pam_unix(sudo:session): session closed for user root Jan 26 12:46:30 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 26 12:46:30 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Jan 26 12:46:30 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 26 12:46:30 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 26 12:46:30 volumio volumio[1429]: info: Shairport-Sync Started Jan 26 12:46:30 volumio volumio[1429]: Error adding Membership: Error: addMembership EINVAL Jan 26 12:46:30 volumio sudo[1725]: pam_unix(sudo:session): session closed for user root Jan 26 12:46:30 volumio sudo[1723]: pam_unix(sudo:session): session closed for user root Jan 26 12:46:30 volumio volumio[1429]: info: CoreCommandRouter::volumioGetState Jan 26 12:46:30 volumio volumio[1429]: info: CorePlayQueue::getTrack 0 Jan 26 12:46:30 volumio volumio[1429]: info: Shairport-Sync Started Jan 26 12:46:30 volumio volumio[1429]: info: Shairport-Sync Started Jan 26 12:46:30 volumio volumio[1429]: 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 26 12:46:31 volumio volumio[1429]: info: Spotify Successfully logged in Jan 26 12:46:31 volumio volumio[1429]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 26 12:46:31 volumio volumio[1429]: info: [1769406391016] CoreMusicLibrary::Adding element Spotify Jan 26 12:46:31 volumio volumio[1429]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 26 12:46:31 volumio volumio[1429]: Cannot find translation for source YouTube Music Jan 26 12:46:31 volumio volumio[1429]: Cannot find translation for source Spotify Jan 26 12:46:31 volumio volumio[1429]: info: [yt-cast-receiver] DIAL server listening on port 8098 Jan 26 12:46:31 volumio volumio[1429]: info: CoreCommandRouter::volumioRetrievevolume Jan 26 12:46:31 volumio volumio[1429]: info: VolumeController:: Volume=100 Mute =false Jan 26 12:46:31 volumio volumio[1429]: info: CoreCommandRouter::volumioGetState Jan 26 12:46:31 volumio volumio[1429]: info: CorePlayQueue::getTrack 0 Jan 26 12:46:31 volumio volumio[1429]: info: CoreStateMachine::pushState Jan 26 12:46:32 volumio volumio[1429]: info: CorePlayQueue::getTrack 0 Jan 26 12:46:32 volumio volumio[1429]: info: CoreCommandRouter::volumioPushState Jan 26 12:46:32 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 12:46:32 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 12:46:32 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 12:46:33 volumio volumio[1429]: info: go-librespot daemon successfully initialized Jan 26 12:46:33 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 18. Jan 26 12:46:33 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 26 12:46:33 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 26 12:46:33 volumio go-librespot[1774]: go-librespot daemon starting... Jan 26 12:46:33 volumio go-librespot[1775]: time="2026-01-26T12:46:33+07:00" level=info msg="running go-librespot 0.4.0" Jan 26 12:46:33 volumio go-librespot[1775]: time="2026-01-26T12:46:33+07:00" level=debug msg="app state loaded" Jan 26 12:46:33 volumio go-librespot[1775]: time="2026-01-26T12:46:33+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 26 12:46:33 volumio mpd[1672]: 2026-01-26T12:46:33 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 26 12:46:33 volumio systemd[1]: Started mpd.service - Music Player Daemon. Jan 26 12:46:33 volumio sudo[1643]: pam_unix(sudo:session): session closed for user root Jan 26 12:46:33 volumio sudo[1633]: pam_unix(sudo:session): session closed for user root Jan 26 12:46:33 volumio volumio[1429]: error: MPD error: The expression evaluated to a falsy value: Jan 26 12:46:33 volumio volumio[1429]: assert.ok(self.idling) Jan 26 12:46:33 volumio volumio[1429]: error: The expression evaluated to a falsy value: Jan 26 12:46:33 volumio volumio[1429]: assert.ok(self.idling) Jan 26 12:46:33 volumio volumio[1429]: info: MPD running with PID1672 Jan 26 12:46:33 volumio volumio[1429]: ,establishing connection Jan 26 12:46:33 volumio volumio[1429]: error: updateQueue error: null Jan 26 12:46:33 volumio volumio[1429]: info: Completed starting Core Plugins Jan 26 12:46:33 volumio volumio[1429]: info: ------------------------------------------- Jan 26 12:46:33 volumio volumio[1429]: info: ----- MyVolumio plugins startup ---- Jan 26 12:46:33 volumio volumio[1429]: info: ------------------------------------------- Jan 26 12:46:33 volumio volumio[1429]: info: [MyVolumio PluginManager] Fetching plans data.... Jan 26 12:46:33 volumio go-librespot[1775]: time="2026-01-26T12:46: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-gew4.spotify.com:80]" Jan 26 12:46:33 volumio go-librespot[1775]: time="2026-01-26T12:46:33+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 26 12:46:33 volumio go-librespot[1775]: time="2026-01-26T12:46:33+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 26 12:46:33 volumio volumio[1429]: error: updateQueue error: null Jan 26 12:46:33 volumio go-librespot[1775]: time="2026-01-26T12:46:33+07:00" level=info msg="zeroconf server listening on port 42983" Jan 26 12:46:34 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 12:46:34 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 12:46:34 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 12:46:34 volumio go-librespot[1775]: time="2026-01-26T12:46:34+07:00" level=debug msg="obtained new client token: AABUU8uUA2BscWDNxHp4AWKyLoXY15Mpe4or3F0HS8srMRt1AkxUYBsTl1jSi08ItjU0OSHVA2XF1pqRPBDiRBY11pgQVFxhc6OjD3yKCRPT3E1YvufrkjNHQCI0jO3weBaQPmf8cP8Bx5JplLCHTDHj8QejvMcDPVAm1gn31wPD32CylcNm5CMI7+onZP65Pf0vfW9drnQ6uF9WblhAipx1HsBvun0my8EHHqn3Hi2A7hb6mblShi7Z" Jan 26 12:46:34 volumio go-librespot[1775]: time="2026-01-26T12:46:34+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 26 12:46:34 volumio go-librespot[1775]: time="2026-01-26T12:46:34+07:00" level=debug msg="completed keyexchange" Jan 26 12:46:34 volumio go-librespot[1775]: time="2026-01-26T12:46:34+07:00" level=debug msg="completed challenge" Jan 26 12:46:34 volumio go-librespot[1775]: time="2026-01-26T12:46: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 26 12:46:34 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 26 12:46:34 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 26 12:46:36 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 12:46:36 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 12:46:36 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 12:46:36 volumio volumio[1429]: info: Initializing connection to go-librespot Websocket Jan 26 12:46:36 volumio volumio[1429]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 26 12:46:37 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 19. Jan 26 12:46:37 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 26 12:46:37 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 26 12:46:37 volumio go-librespot[1788]: go-librespot daemon starting... Jan 26 12:46:37 volumio go-librespot[1789]: time="2026-01-26T12:46:37+07:00" level=info msg="running go-librespot 0.4.0" Jan 26 12:46:37 volumio go-librespot[1789]: time="2026-01-26T12:46:37+07:00" level=debug msg="app state loaded" Jan 26 12:46:37 volumio go-librespot[1789]: time="2026-01-26T12:46:37+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 26 12:46:38 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 12:46:38 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 12:46:38 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 12:46:38 volumio go-librespot[1789]: time="2026-01-26T12:46:38+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 26 12:46:38 volumio go-librespot[1789]: time="2026-01-26T12:46:38+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 26 12:46:38 volumio go-librespot[1789]: time="2026-01-26T12:46:38+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 26 12:46:38 volumio go-librespot[1789]: time="2026-01-26T12:46:38+07:00" level=info msg="zeroconf server listening on port 36067" Jan 26 12:46:38 volumio go-librespot[1789]: time="2026-01-26T12:46:38+07:00" level=debug msg="obtained new client token: AAAPdXxFij2cNBiEm4h5bydfZEhZckJD7ZXhbuVkQVLIf5VleBNro0+3T6VVHtqCdjXCyMDltyXJ3ICXfbGRT2uxWqsfPQJEFvf3wieu7m+lSPZc315HoygpCbN/0qtKJ6X5I5oRIXwJK44eEaYfwmU+CVnf7L8ZbZK+g/h5PfeNj2VeER9bBtlz4Vi3vktQDTZut217RwFyVv+0xAo44fqA/UJIOUFfXdQgj9v6rPtNFMZ3aCjF5DEtsXg=" Jan 26 12:46:38 volumio volumio[1429]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Jan 26 12:46:38 volumio go-librespot[1789]: time="2026-01-26T12:46:38+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 26 12:46:38 volumio go-librespot[1789]: time="2026-01-26T12:46:38+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Jan 26 12:46:38 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 26 12:46:38 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 26 12:46:39 volumio volumio[1429]: info: Initializing connection to go-librespot Websocket Jan 26 12:46:39 volumio volumio[1429]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 26 12:46:40 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 12:46:40 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 12:46:40 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 12:46:41 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 20. Jan 26 12:46:41 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 26 12:46:42 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 12:46:42 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 12:46:42 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 12:46:42 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 26 12:46:42 volumio go-librespot[1796]: go-librespot daemon starting... Jan 26 12:46:42 volumio go-librespot[1797]: time="2026-01-26T12:46:42+07:00" level=info msg="running go-librespot 0.4.0" Jan 26 12:46:42 volumio go-librespot[1797]: time="2026-01-26T12:46:42+07:00" level=debug msg="app state loaded" Jan 26 12:46:42 volumio go-librespot[1797]: time="2026-01-26T12:46:42+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 26 12:46:42 volumio volumio[1429]: info: Initializing connection to go-librespot Websocket Jan 26 12:46:42 volumio go-librespot[1797]: time="2026-01-26T12:46:42+07:00" level=debug msg="new websocket client" Jan 26 12:46:42 volumio volumio[1429]: info: Connection to go-librespot Websocket established Jan 26 12:46:42 volumio go-librespot[1797]: time="2026-01-26T12: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 26 12:46:42 volumio go-librespot[1797]: time="2026-01-26T12: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 26 12:46:42 volumio go-librespot[1797]: time="2026-01-26T12: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 26 12:46:42 volumio go-librespot[1797]: time="2026-01-26T12:46:42+07:00" level=info msg="zeroconf server listening on port 39417" Jan 26 12:46:42 volumio volumio[1429]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Jan 26 12:46:42 volumio volumio[1429]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Jan 26 12:46:42 volumio volumio[1429]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Jan 26 12:46:42 volumio volumio[1429]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Jan 26 12:46:42 volumio volumio[1429]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Jan 26 12:46:42 volumio volumio[1429]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Jan 26 12:46:42 volumio volumio[1429]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Jan 26 12:46:42 volumio volumio[1429]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Jan 26 12:46:42 volumio volumio[1429]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Jan 26 12:46:42 volumio volumio[1429]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Jan 26 12:46:42 volumio volumio[1429]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Jan 26 12:46:42 volumio volumio[1429]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Jan 26 12:46:42 volumio volumio[1429]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Jan 26 12:46:42 volumio volumio[1429]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Jan 26 12:46:42 volumio volumio[1429]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Jan 26 12:46:42 volumio volumio[1429]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Jan 26 12:46:42 volumio volumio[1429]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Jan 26 12:46:42 volumio volumio[1429]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Jan 26 12:46:42 volumio volumio[1429]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Jan 26 12:46:42 volumio volumio[1429]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Jan 26 12:46:42 volumio volumio[1429]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Jan 26 12:46:42 volumio volumio[1429]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Jan 26 12:46:42 volumio volumio[1429]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Jan 26 12:46:42 volumio volumio[1429]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Jan 26 12:46:42 volumio volumio[1429]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Jan 26 12:46:42 volumio volumio[1429]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Jan 26 12:46:42 volumio volumio[1429]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Jan 26 12:46:42 volumio volumio[1429]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Jan 26 12:46:42 volumio volumio[1429]: info: Adding plugin bluetooth to MyMusic Plugins Jan 26 12:46:42 volumio volumio[1429]: info: Adding plugin multiroom to MyMusic Plugins Jan 26 12:46:42 volumio volumio[1429]: info: Adding plugin metavolumio to MyMusic Plugins Jan 26 12:46:42 volumio volumio[1429]: info: Adding plugin cd_controller to MyMusic Plugins Jan 26 12:46:42 volumio volumio[1429]: info: Adding plugin qobuzconnect to MyMusic Plugins Jan 26 12:46:42 volumio volumio[1429]: info: Adding plugin smart_inputs to MyMusic Plugins Jan 26 12:46:42 volumio volumio[1429]: info: Adding plugin tidalconnect to MyMusic Plugins Jan 26 12:46:42 volumio volumio[1429]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Jan 26 12:46:42 volumio go-librespot[1797]: time="2026-01-26T12:46:42+07:00" level=debug msg="obtained new client token: AADvwcK8WK+pwxomggabsqfBGy6lZfn3CcX3ry1aZtaG6XUG8RUPYlX73nU+YVC/T/uGMTqaGfZHPy0Hf1Wi25jJZ2242w4WVznswMr5h3qdD4cZzGZaeesGWxTkaEiqUHvcKLfuIz7fbnfz23UNviMXOP8SwZaE7f/1faa9Epgp9wM0f2Vj7mAmIx2qA0MYURIBDb2c50laC5C2/X/k2iSNMTtwwDcQUEUcUxRjG09jr61/U/HvxULzazo=" Jan 26 12:46:43 volumio go-librespot[1797]: time="2026-01-26T12:46:43+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 26 12:46:43 volumio go-librespot[1797]: time="2026-01-26T12:46:43+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Jan 26 12:46:43 volumio go-librespot[1797]: time="2026-01-26T12:46:43+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Jan 26 12:46:43 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 26 12:46:43 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 26 12:46:44 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 12:46:44 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 12:46:44 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 12:46:44 volumio volumio[1429]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Jan 26 12:46:44 volumio volumio[1429]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Jan 26 12:46:44 volumio volumio[1429]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 12:46:44 volumio volumio[1429]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 12:46:44 volumio volumio[1429]: info: Starting MyVolumio Remote Streaming Endpoints Jan 26 12:46:44 volumio volumio[1429]: info: MyVolumio login type: Token Jan 26 12:46:44 volumio volumio[1429]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Jan 26 12:46:44 volumio volumio[1429]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Jan 26 12:46:46 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 12:46:46 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 12:46:46 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 12:46:46 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 21. Jan 26 12:46:46 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 26 12:46:46 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 26 12:46:46 volumio go-librespot[1818]: go-librespot daemon starting... Jan 26 12:46:46 volumio go-librespot[1819]: time="2026-01-26T12:46:46+07:00" level=info msg="running go-librespot 0.4.0" Jan 26 12:46:46 volumio go-librespot[1819]: time="2026-01-26T12:46:46+07:00" level=debug msg="app state loaded" Jan 26 12:46:46 volumio go-librespot[1819]: time="2026-01-26T12:46:46+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 26 12:46:46 volumio volumio[1429]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Jan 26 12:46:46 volumio volumio[1429]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Jan 26 12:46:46 volumio volumio[1429]: info: Streaming services startup Jan 26 12:46:46 volumio volumio[1429]: info: Starting Streaming Daemon Jan 26 12:46:46 volumio sudo[1827]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jan 26 12:46:46 volumio sudo[1827]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 12:46:46 volumio volumio[1429]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Jan 26 12:46:46 volumio sudo[1827]: pam_unix(sudo:session): session closed for user root Jan 26 12:46:46 volumio volumio[1429]: info: Getting Spotify volume Jan 26 12:46:46 volumio volumio[1429]: info: Connection to go-librespot Websocket closed Jan 26 12:46:46 volumio volumio[1429]: error: Cannot start Volumio Streaming Daemon Jan 26 12:46:46 volumio volumio[1429]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Jan 26 12:46:46 volumio volumio[1429]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Jan 26 12:46:46 volumio volumio[1429]: 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 26 12:46:46 volumio go-librespot[1819]: time="2026-01-26T12: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-gew1.spotify.com:80]" Jan 26 12:46:46 volumio go-librespot[1819]: time="2026-01-26T12: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 gew1-dealer.spotify.com:443]" Jan 26 12:46:46 volumio go-librespot[1819]: time="2026-01-26T12: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 gew1-spclient.spotify.com:443]" Jan 26 12:46:46 volumio go-librespot[1819]: time="2026-01-26T12:46:46+07:00" level=info msg="zeroconf server listening on port 45957" Jan 26 12:46:47 volumio volumio[1429]: info: CoreCommandRouter::volumioGetState Jan 26 12:46:47 volumio volumio[1429]: info: CorePlayQueue::getTrack 0 Jan 26 12:46:47 volumio volumio[1429]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jan 26 12:46:47 volumio volumio[1429]: SPOTIFY: SPOTIFY VOLUME undefined Jan 26 12:46:47 volumio volumio[1429]: SPOTIFY: VOLUMIO VOLUME 100 Jan 26 12:46:47 volumio volumio[1429]: info: Aligning Spotify Volume to Volumio Volume Jan 26 12:46:47 volumio volumio[1429]: info: CoreCommandRouter::volumioGetState Jan 26 12:46:47 volumio volumio[1429]: info: CorePlayQueue::getTrack 0 Jan 26 12:46:47 volumio volumio[1429]: info: Setting Spotify Volume from Volumio: 100 Jan 26 12:46:47 volumio go-librespot[1819]: time="2026-01-26T12:46:47+07:00" level=debug msg="obtained new client token: AAB+x8bjqcrxtEwUnJfBCyGOUvDFBZyMbiG5wcoUU3Blss+kGCyuv6ObAIi+veOnl5y/9Vwd4O1618N6Hj9NFoshk6R2bL8SNQFsMTuOkDGcVgKoN/20ig/qap0K4blMDUugmmAEZeW8hccifhrvK6tzw410qIX2yT6ZMRoVC4ud4+s9nI7gdRRIPS1PvPqdyfvu9kWihymawJpos23vwScDoPpF/w2c8vrsRYfHutR4Cv2CtuW8kzx/" Jan 26 12:46:47 volumio go-librespot[1819]: time="2026-01-26T12:46:47+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 26 12:46:47 volumio go-librespot[1819]: time="2026-01-26T12:46:47+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Jan 26 12:46:47 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 26 12:46:47 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 26 12:46:47 volumio volumio[1429]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 26 12:46:47 volumio volumio[1429]: Error: socket hang up Jan 26 12:46:47 volumio volumio[1429]: at connResetException (node:internal/errors:720:14) Jan 26 12:46:47 volumio volumio[1429]: at Socket.socketOnEnd (node:_http_client:519:23) Jan 26 12:46:47 volumio volumio[1429]: at Socket.emit (node:events:526:35) Jan 26 12:46:47 volumio volumio[1429]: at endReadableNT (node:internal/streams/readable:1376:12) Jan 26 12:46:47 volumio volumio[1429]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Jan 26 12:46:47 volumio volumio[1429]: code: 'ECONNRESET', Jan 26 12:46:47 volumio volumio[1429]: response: undefined Jan 26 12:46:47 volumio volumio[1429]: } Jan 26 12:46:47 volumio volumio[1429]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 26 12:46:48 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 12:46:48 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 12:46:48 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 12:46:48 volumio sudo[1848]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-01-26 12:45' Jan 26 12:46:48 volumio sudo[1848]: 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"