Jan 29 03:38:00 volumio volumio[18520]: info: Applying required configuration parameters for plugin RoonBridge Jan 29 03:38:00 volumio volumio[18520]: info: Loading i18n strings for locale en Jan 29 03:38:00 volumio volumio[18520]: Updating browse sources language Jan 29 03:38:00 volumio volumio[18520]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 29 03:38:00 volumio volumio[18633]: Forking 3 albumart workers Jan 29 03:38:00 volumio volumio[18520]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 29 03:38:00 volumio volumio[18520]: info: CoreCommandRouter::initPlayerControls Jan 29 03:38:00 volumio volumio[18520]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 29 03:38:00 volumio volumio[18520]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 29 03:38:00 volumio volumio[18520]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 29 03:38:00 volumio volumio[18520]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 29 03:38:00 volumio volumio[18520]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 29 03:38:00 volumio volumio[18520]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 29 03:38:00 volumio volumio[18520]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 29 03:38:00 volumio volumio[18520]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 29 03:38:00 volumio volumio[18520]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 29 03:38:00 volumio volumio[18520]: Express server listening on port 3000 Jan 29 03:38:00 volumio volumio[18520]: [Metrics] WebUI: 15s 995.58ms Jan 29 03:38:00 volumio volumio[18520]: info: CoreStateMachine::resetVolumioState Jan 29 03:38:00 volumio volumio[18520]: info: CoreStateMachine::getcurrentVolume Jan 29 03:38:00 volumio volumio[18520]: info: CoreCommandRouter::volumioRetrievevolume Jan 29 03:38:00 volumio sudo[18677]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 29 03:38:00 volumio sudo[18677]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 29 03:38:00 volumio volumio[18520]: info: Volumio Network Manager: Network status updated: 1 Jan 29 03:38:00 volumio sudo[18675]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 29 03:38:00 volumio sudo[18675]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 29 03:38:00 volumio sudo[18677]: pam_unix(sudo:session): session closed for user root Jan 29 03:38:00 volumio sudo[18675]: pam_unix(sudo:session): session closed for user root Jan 29 03:38:00 volumio volumio[18520]: info: VolumeController:: Volume=100 Mute =false Jan 29 03:38:01 volumio volumio[18520]: info: CoreStateMachine::pushState Jan 29 03:38:01 volumio volumio[18520]: info: CorePlayQueue::getTrack 0 Jan 29 03:38:01 volumio volumio[18520]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 29 03:38:01 volumio volumio[18520]: info: CoreCommandRouter::volumioPushState Jan 29 03:38:01 volumio volumio[18520]: info: CoreStateMachine::updateTrackBlock Jan 29 03:38:01 volumio volumio[18520]: info: CorePlayQueue::getTrackBlock Jan 29 03:38:01 volumio volumio[18520]: info: CoreCommandRouter::volumioRetrievevolume Jan 29 03:38:01 volumio volumio-remote-updater[628]: [2026-01-29 03:38:01] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1769632679 101 Jan 29 03:38:01 volumio volumio[18520]: 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 29 03:38:01 volumio volumio[18520]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 29 03:38:01 volumio volumio[18520]: info: Reloading queue from file Jan 29 03:38:01 volumio volumio[18520]: info: CoreStateMachine::setRepeat null single undefined Jan 29 03:38:01 volumio volumio[18520]: info: CoreStateMachine::pushState Jan 29 03:38:01 volumio volumio[18520]: info: CorePlayQueue::getTrack 0 Jan 29 03:38:01 volumio volumio[18520]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 29 03:38:01 volumio volumio[18520]: info: CoreCommandRouter::volumioPushState Jan 29 03:38:01 volumio volumio[18520]: info: CoreStateMachine::setRandom null Jan 29 03:38:01 volumio volumio[18520]: info: CoreStateMachine::pushState Jan 29 03:38:01 volumio volumio[18520]: info: CorePlayQueue::getTrack 0 Jan 29 03:38:01 volumio volumio[18520]: info: CoreCommandRouter::volumioPushState Jan 29 03:38:01 volumio volumio[18520]: info: Setting Device type: Raspberry PI Jan 29 03:38:01 volumio volumio[18520]: info: Completed loading Core Plugins Jan 29 03:38:01 volumio volumio[18520]: info: Preparing to generate the ALSA configuration file Jan 29 03:38:01 volumio volumio[18520]: info: VolumeController:: Volume=100 Mute =false Jan 29 03:38:01 volumio volumio[18520]: info: CoreStateMachine::pushState Jan 29 03:38:01 volumio volumio[18520]: info: CorePlayQueue::getTrack 0 Jan 29 03:38:01 volumio volumio[18520]: info: CoreCommandRouter::volumioPushState Jan 29 03:38:01 volumio volumio[18520]: info: Asound.conf file unchanged, so no further update is needed Jan 29 03:38:01 volumio volumio[18520]: info: Output device has changed, restarting MPD Jan 29 03:38:01 volumio volumio[18520]: info: Output device has changed, restarting Shairport Sync Jan 29 03:38:01 volumio volumio[18520]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 29 03:38:01 volumio volumio[18520]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 29 03:38:01 volumio sudo[18694]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Jan 29 03:38:01 volumio sudo[18694]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 29 03:38:01 volumio sudo[18696]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 29 03:38:01 volumio sudo[18696]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 29 03:38:01 volumio volumio[18520]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 29 03:38:01 volumio sudo[18696]: pam_unix(sudo:session): session closed for user root Jan 29 03:38:01 volumio volumio[18520]: info: ___________ START PLUGINS ___________ Jan 29 03:38:01 volumio sudo[18698]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 29 03:38:01 volumio volumio[18520]: info: ControllerMpd::onStart: Initializing MPD Jan 29 03:38:01 volumio volumio[18520]: info: Creating MPD Configuration file Jan 29 03:38:01 volumio sudo[18698]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 29 03:38:01 volumio sudo[18694]: pam_unix(sudo:session): session closed for user root Jan 29 03:38:01 volumio volumio[18520]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 29 03:38:01 volumio volumio[18520]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 29 03:38:01 volumio volumio[18520]: info: [1769632681741] CoreMusicLibrary::Adding element Media Servers Jan 29 03:38:01 volumio volumio[18520]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 29 03:38:01 volumio sudo[18707]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 29 03:38:01 volumio sudo[18707]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 29 03:38:01 volumio volumio[18520]: info: UPNP Browser: Client initialized successfully Jan 29 03:38:01 volumio sudo[18709]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 29 03:38:01 volumio sudo[18709]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 29 03:38:01 volumio sudo[18707]: pam_unix(sudo:session): session closed for user root Jan 29 03:38:01 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Jan 29 03:38:01 volumio volumio[18520]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 29 03:38:01 volumio volumio[18520]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 29 03:38:01 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 29 03:38:01 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 29 03:38:01 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 29 03:38:01 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 29 03:38:01 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 29 03:38:02 volumio systemd[1]: mpd.service: Consumed 7.478s CPU time. Jan 29 03:38:02 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 29 03:38:02 volumio volumio[18520]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 29 03:38:02 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 29 03:38:02 volumio volumio[18520]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 29 03:38:02 volumio volumio[18520]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 29 03:38:02 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 29 03:38:02 volumio volumio[18520]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 29 03:38:02 volumio volumio[18520]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 29 03:38:02 volumio volumio[18520]: info: [1769632682077] CoreMusicLibrary::Adding element Last_100 Jan 29 03:38:02 volumio volumio[18520]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 29 03:38:02 volumio volumio[18520]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 29 03:38:02 volumio volumio[18520]: info: [1769632682099] CoreMusicLibrary::Adding element Webradio Jan 29 03:38:02 volumio volumio[18520]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 29 03:38:02 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 29 03:38:02 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 29 03:38:02 volumio volumio[18520]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 29 03:38:02 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 29 03:38:02 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 29 03:38:02 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 29 03:38:02 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 29 03:38:02 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 29 03:38:02 volumio volumio[18520]: info: Initializing BBC Radios Jan 29 03:38:02 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 29 03:38:02 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 29 03:38:02 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Jan 29 03:38:02 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 29 03:38:02 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 29 03:38:02 volumio go-librespot[18727]: go-librespot daemon starting... Jan 29 03:38:02 volumio go-librespot[18728]: time="2026-01-29T03:38:02+07:00" level=info msg="running go-librespot 0.4.0" Jan 29 03:38:02 volumio go-librespot[18728]: time="2026-01-29T03:38:02+07:00" level=debug msg="app state loaded" Jan 29 03:38:02 volumio go-librespot[18728]: time="2026-01-29T03:38:02+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 29 03:38:02 volumio volumio[18520]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 29 03:38:02 volumio volumio[18520]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 29 03:38:02 volumio volumio[18520]: info: Creating Spotify config file Jan 29 03:38:02 volumio volumio[18520]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 29 03:38:02 volumio sudo[18725]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 29 03:38:02 volumio sudo[18725]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jan 29 03:38:02 volumio sudo[18725]: pam_unix(sudo:session): session closed for user root Jan 29 03:38:03 volumio go-librespot[18728]: time="2026-01-29T03:38: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 29 03:38:03 volumio go-librespot[18728]: time="2026-01-29T03:38: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 29 03:38:03 volumio go-librespot[18728]: time="2026-01-29T03:38: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 29 03:38:03 volumio go-librespot[18728]: time="2026-01-29T03:38:03+07:00" level=info msg="zeroconf server listening on port 42311" Jan 29 03:38:03 volumio go-librespot[18728]: time="2026-01-29T03:38:03+07:00" level=debug msg="obtained new client token: AACgqYY36ugnaW4q9Q3aXVBY5I3rfNZTpcwE3nOBjuelDRV1azQBQ+vwXd8H5m+YKPRs2K3Z4zWZtvzhEc63/vTlHv/G/YblI/KtmVvXk2tnL3LwATpy1p/t6ce1wrWnbpN5UGvnbg9r8nFIWqHQbshsCooKRRhNP+OwZ0kVNCXv4INnyTjJ/LqI5CbLq7k6qlW/L66CDqkQCQv0RaUbvNbOe4f8PCIJD5t+0fsLNzh+zSi28iebvt/FpI4=" Jan 29 03:38:03 volumio go-librespot[18728]: time="2026-01-29T03:38:03+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 29 03:38:03 volumio go-librespot[18728]: time="2026-01-29T03:38:03+07:00" level=debug msg="completed keyexchange" Jan 29 03:38:03 volumio go-librespot[18728]: time="2026-01-29T03:38:03+07:00" level=debug msg="completed challenge" Jan 29 03:38:03 volumio go-librespot[18728]: time="2026-01-29T03:38:03+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 29 03:38:03 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 29 03:38:03 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 29 03:38:03 volumio volumio[18644]: Starting albumart workers Jan 29 03:38:03 volumio volumio[18645]: Starting albumart workers Jan 29 03:38:03 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 29 03:38:03 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 29 03:38:03 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 29 03:38:03 volumio volumio[18643]: Starting albumart workers Jan 29 03:38:04 volumio volumio[18520]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 29 03:38:04 volumio volumio[18520]: info: [1769632684217] CoreMusicLibrary::Adding element YouTube Music Jan 29 03:38:04 volumio volumio[18520]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 29 03:38:04 volumio volumio[18520]: Cannot find translation for source YouTube Music Jan 29 03:38:04 volumio volumio[18520]: info: Volumio Calling Home Jan 29 03:38:04 volumio sudo[18748]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Jan 29 03:38:04 volumio sudo[18748]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 29 03:38:04 volumio sudo[18748]: pam_unix(sudo:session): session closed for user root Jan 29 03:38:05 volumio volumio[18520]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Jan 29 03:38:05 volumio volumio[18520]: info: Discovery: Found device Volumio Jan 29 03:38:05 volumio volumio[18520]: info: CoreCommandRouter::volumioGetState Jan 29 03:38:05 volumio volumio[18520]: info: CorePlayQueue::getTrack 0 Jan 29 03:38:05 volumio volumio[18520]: info: MPD Permissions set Jan 29 03:38:05 volumio volumio[18520]: info: MPD Permissions set Jan 29 03:38:05 volumio volumio[18520]: info: Upmpdcli Daemon Started Jan 29 03:38:05 volumio volumio[18520]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Jan 29 03:38:05 volumio volumio[18520]: info: Discovery: Found device Volumio Jan 29 03:38:05 volumio volumio[18520]: info: CoreCommandRouter::volumioGetState Jan 29 03:38:05 volumio volumio[18520]: info: CorePlayQueue::getTrack 0 Jan 29 03:38:05 volumio volumio[18520]: info: Spotify config file written Jan 29 03:38:05 volumio sudo[18754]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jan 29 03:38:05 volumio sudo[18754]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 29 03:38:05 volumio volumio[18520]: 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 29 03:38:05 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 29 03:38:05 volumio volumio[18520]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 29 03:38:05 volumio volumio[18520]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 29 03:38:05 volumio volumio[18520]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 29 03:38:05 volumio volumio[18520]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 29 03:38:05 volumio volumio[18520]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 29 03:38:05 volumio volumio[18520]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 29 03:38:05 volumio volumio[18520]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 29 03:38:05 volumio volumio[18520]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 29 03:38:05 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 29 03:38:05 volumio go-librespot[18756]: go-librespot daemon starting... Jan 29 03:38:05 volumio sudo[18754]: pam_unix(sudo:session): session closed for user root Jan 29 03:38:05 volumio volumio[18520]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 29 03:38:05 volumio volumio[18520]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 29 03:38:05 volumio volumio[18520]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 29 03:38:05 volumio volumio[18520]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 29 03:38:05 volumio volumio[18520]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 29 03:38:05 volumio volumio[18520]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 29 03:38:05 volumio volumio[18520]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 29 03:38:05 volumio volumio[18520]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 29 03:38:05 volumio go-librespot[18761]: time="2026-01-29T03:38:05+07:00" level=info msg="running go-librespot 0.4.0" Jan 29 03:38:05 volumio go-librespot[18761]: time="2026-01-29T03:38:05+07:00" level=debug msg="app state loaded" Jan 29 03:38:05 volumio volumio[18520]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 29 03:38:05 volumio go-librespot[18761]: time="2026-01-29T03:38:05+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 29 03:38:05 volumio volumio[18520]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 29 03:38:05 volumio volumio[18520]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 29 03:38:05 volumio volumio[18520]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 29 03:38:05 volumio volumio[18520]: info: No need to fix Spotify hosts Jan 29 03:38:05 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 29 03:38:05 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 29 03:38:05 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 29 03:38:06 volumio go-librespot[18761]: time="2026-01-29T03:38:06+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 29 03:38:06 volumio go-librespot[18761]: time="2026-01-29T03:38:06+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 29 03:38:06 volumio go-librespot[18761]: time="2026-01-29T03:38:06+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 29 03:38:06 volumio go-librespot[18761]: time="2026-01-29T03:38:06+07:00" level=info msg="zeroconf server listening on port 43801" Jan 29 03:38:06 volumio volumio[18520]: info: Volumio called home Jan 29 03:38:06 volumio go-librespot[18761]: time="2026-01-29T03:38:06+07:00" level=debug msg="obtained new client token: AADkAcwzwf67LQLlL4qUWFpVSeWgnNCX58J3avXE8b6Y/gWLeShamJ/9ieRI8aDCk8FvdtKDPMVrvmSHScGFd1PuUh9DC3A06F4+pdacnh8XrfYw3LkYcPZ7xK1yuXhVRWmo+8ze+L5kgqOZjoqI9vqDN9TlfrLUcwIQFqFTU8h9E529dDfmfOfGEElQuAnZCnlN6DWmmAmHtJvZCr6lN6aUkWXGltLs1Ikt8HtrUdBRwOIxJ21/YZe/vCs=" Jan 29 03:38:06 volumio go-librespot[18761]: time="2026-01-29T03:38:06+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 29 03:38:06 volumio go-librespot[18761]: time="2026-01-29T03:38:06+07:00" level=debug msg="completed keyexchange" Jan 29 03:38:06 volumio go-librespot[18761]: time="2026-01-29T03:38:06+07:00" level=debug msg="completed challenge" Jan 29 03:38:06 volumio volumio[18520]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 29 03:38:06 volumio volumio[18520]: SPOTIFY: BQBZK3H87IMr6dkeQSihKJB7T6BkDbW2MMwkNWYYPm27FJnvoQ2w1W8dCLCHTY4jTPcU_IXpwq_TbX43eK9aMMyaLazyRMPcKBZlKyrVTB_dylIbzy17orxTIEb6YFHpA92c18s4UY8A6_UPIZOQmWWsEVmk3Ib8HH8HQG6TL1iLAQzZZrxABpxafqQKm0fBh3BW7rroKRYz98JMfJLTgs54wReeJ0vZJ98iH2bCGYbZFfaS8KeaKDeqNjU4uQhwGHHubLPdixqeYR7RBy7DmXlpnuHUyt4alT_n_GMHjPVjuPyHFiKU6H3d Jan 29 03:38:06 volumio volumio[18520]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 29 03:38:06 volumio volumio[18520]: info: New Spotify access token = BQBZK3H87IMr6dkeQSihKJB7T6BkDbW2MMwkNWYYPm27FJnvoQ2w1W8dCLCHTY4jTPcU_IXpwq_TbX43eK9aMMyaLazyRMPcKBZlKyrVTB_dylIbzy17orxTIEb6YFHpA92c18s4UY8A6_UPIZOQmWWsEVmk3Ib8HH8HQG6TL1iLAQzZZrxABpxafqQKm0fBh3BW7rroKRYz98JMfJLTgs54wReeJ0vZJ98iH2bCGYbZFfaS8KeaKDeqNjU4uQhwGHHubLPdixqeYR7RBy7DmXlpnuHUyt4alT_n_GMHjPVjuPyHFiKU6H3d Jan 29 03:38:06 volumio volumio[18520]: info: Spotify credentials grant success - running version from March 24, 2019 Jan 29 03:38:06 volumio go-librespot[18761]: time="2026-01-29T03:38:06+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 29 03:38:06 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 29 03:38:06 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 29 03:38:06 volumio volumio[18520]: info: Starting Shairport Sync Jan 29 03:38:06 volumio volumio[18520]: info: Starting Shairport Sync Jan 29 03:38:06 volumio volumio[18520]: info: Starting Shairport Sync Jan 29 03:38:07 volumio sudo[18795]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 29 03:38:07 volumio sudo[18795]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 29 03:38:07 volumio sudo[18797]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 29 03:38:07 volumio sudo[18799]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 29 03:38:07 volumio sudo[18797]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 29 03:38:07 volumio sudo[18799]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 29 03:38:07 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 29 03:38:07 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Jan 29 03:38:07 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 29 03:38:07 volumio systemd[1]: shairport-sync.service: Consumed 2.378s CPU time. Jan 29 03:38:07 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 29 03:38:07 volumio sudo[18797]: pam_unix(sudo:session): session closed for user root Jan 29 03:38:07 volumio sudo[18799]: pam_unix(sudo:session): session closed for user root Jan 29 03:38:07 volumio sudo[18795]: pam_unix(sudo:session): session closed for user root Jan 29 03:38:07 volumio volumio[18520]: info: Shairport-Sync Started Jan 29 03:38:07 volumio volumio[18520]: Error adding Membership: Error: addMembership EINVAL Jan 29 03:38:07 volumio volumio[18520]: info: Shairport-Sync Started Jan 29 03:38:07 volumio volumio[18520]: info: Shairport-Sync Started Jan 29 03:38:07 volumio volumio[18520]: info: CoreCommandRouter::volumioGetState Jan 29 03:38:07 volumio volumio[18520]: info: CorePlayQueue::getTrack 0 Jan 29 03:38:07 volumio volumio[18520]: 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 29 03:38:07 volumio volumio[18520]: info: Spotify Successfully logged in Jan 29 03:38:07 volumio volumio[18520]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 29 03:38:07 volumio volumio[18520]: info: [1769632687766] CoreMusicLibrary::Adding element Spotify Jan 29 03:38:07 volumio volumio[18520]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 29 03:38:07 volumio volumio[18520]: Cannot find translation for source YouTube Music Jan 29 03:38:07 volumio volumio[18520]: Cannot find translation for source Spotify Jan 29 03:38:07 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 29 03:38:07 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 29 03:38:07 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 29 03:38:08 volumio volumio[18520]: info: [yt-cast-receiver] DIAL server listening on port 8098 Jan 29 03:38:08 volumio volumio[18520]: info: CoreCommandRouter::volumioRetrievevolume Jan 29 03:38:08 volumio volumio[18520]: info: VolumeController:: Volume=100 Mute =false Jan 29 03:38:08 volumio volumio[18520]: info: CoreCommandRouter::volumioGetState Jan 29 03:38:08 volumio volumio[18520]: info: CorePlayQueue::getTrack 0 Jan 29 03:38:08 volumio volumio[18520]: info: CoreStateMachine::pushState Jan 29 03:38:08 volumio volumio[18520]: info: CorePlayQueue::getTrack 0 Jan 29 03:38:08 volumio volumio[18520]: info: CoreCommandRouter::volumioPushState Jan 29 03:38:09 volumio volumio[18520]: info: go-librespot daemon successfully initialized Jan 29 03:38:09 volumio mpd[18745]: 2026-01-29T03:38:09 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 29 03:38:09 volumio systemd[1]: Started mpd.service - Music Player Daemon. Jan 29 03:38:09 volumio sudo[18709]: pam_unix(sudo:session): session closed for user root Jan 29 03:38:09 volumio sudo[18698]: pam_unix(sudo:session): session closed for user root Jan 29 03:38:09 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 29 03:38:09 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 29 03:38:09 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 29 03:38:09 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 11. Jan 29 03:38:09 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 29 03:38:10 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 29 03:38:10 volumio go-librespot[18838]: go-librespot daemon starting... Jan 29 03:38:10 volumio go-librespot[18839]: time="2026-01-29T03:38:10+07:00" level=info msg="running go-librespot 0.4.0" Jan 29 03:38:10 volumio go-librespot[18839]: time="2026-01-29T03:38:10+07:00" level=debug msg="app state loaded" Jan 29 03:38:10 volumio go-librespot[18839]: time="2026-01-29T03:38:10+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 29 03:38:10 volumio volumio[18520]: error: MPD error: The expression evaluated to a falsy value: Jan 29 03:38:10 volumio volumio[18520]: assert.ok(self.idling) Jan 29 03:38:10 volumio volumio[18520]: error: The expression evaluated to a falsy value: Jan 29 03:38:10 volumio volumio[18520]: assert.ok(self.idling) Jan 29 03:38:10 volumio volumio[18520]: error: updateQueue error: null Jan 29 03:38:10 volumio volumio[18520]: info: MPD running with PID18745 Jan 29 03:38:10 volumio volumio[18520]: ,establishing connection Jan 29 03:38:10 volumio volumio[18520]: info: Completed starting Core Plugins Jan 29 03:38:10 volumio volumio[18520]: info: ------------------------------------------- Jan 29 03:38:10 volumio volumio[18520]: info: ----- MyVolumio plugins startup ---- Jan 29 03:38:10 volumio volumio[18520]: info: ------------------------------------------- Jan 29 03:38:10 volumio volumio[18520]: info: [MyVolumio PluginManager] Fetching plans data.... Jan 29 03:38:10 volumio volumio[18520]: error: updateQueue error: null Jan 29 03:38:10 volumio go-librespot[18839]: time="2026-01-29T03:38:10+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 29 03:38:10 volumio go-librespot[18839]: time="2026-01-29T03:38:10+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 29 03:38:10 volumio go-librespot[18839]: time="2026-01-29T03:38:10+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 29 03:38:10 volumio go-librespot[18839]: time="2026-01-29T03:38:10+07:00" level=info msg="zeroconf server listening on port 38621" Jan 29 03:38:10 volumio go-librespot[18839]: time="2026-01-29T03:38:10+07:00" level=debug msg="obtained new client token: AAANZc+Ef7ErxAFVKTncJkKLAOXjYQidKhaiY16x2eB9qvKSwzkjk2UgeOKqi9MHuFk3ZJeRwzA77tR82851D1lGuuumZ+rgZuVn95EHc58bxfVma7eWK68gqXsfx4yIRtOjNgThV3x+9s3a3vbgR7bScC0NwGiAYxoulzf8qu3Wt8ZIxbfX1XR2VOMOsH0c85ihDWQBW4HeYgtL36RqdWrXymyKmXq9lX13It/EMWZWqJd9ogFxDutvGa4=" Jan 29 03:38:11 volumio go-librespot[18839]: time="2026-01-29T03:38:11+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 29 03:38:11 volumio go-librespot[18839]: time="2026-01-29T03:38:11+07:00" level=debug msg="completed keyexchange" Jan 29 03:38:11 volumio go-librespot[18839]: time="2026-01-29T03:38:11+07:00" level=debug msg="completed challenge" Jan 29 03:38:11 volumio go-librespot[18839]: time="2026-01-29T03:38:11+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 29 03:38:11 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 29 03:38:11 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 29 03:38:11 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 29 03:38:11 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 29 03:38:11 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 29 03:38:12 volumio volumio[18520]: info: Initializing connection to go-librespot Websocket Jan 29 03:38:12 volumio volumio[18520]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 29 03:38:13 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 29 03:38:13 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 29 03:38:13 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 29 03:38:14 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 12. Jan 29 03:38:14 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 29 03:38:14 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 29 03:38:14 volumio go-librespot[18849]: go-librespot daemon starting... Jan 29 03:38:14 volumio go-librespot[18850]: time="2026-01-29T03:38:14+07:00" level=info msg="running go-librespot 0.4.0" Jan 29 03:38:14 volumio go-librespot[18850]: time="2026-01-29T03:38:14+07:00" level=debug msg="app state loaded" Jan 29 03:38:14 volumio go-librespot[18850]: time="2026-01-29T03:38:14+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 29 03:38:15 volumio volumio[18520]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Jan 29 03:38:15 volumio go-librespot[18850]: time="2026-01-29T03:38:15+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 29 03:38:15 volumio go-librespot[18850]: time="2026-01-29T03:38:15+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 29 03:38:15 volumio go-librespot[18850]: time="2026-01-29T03:38:15+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 29 03:38:15 volumio go-librespot[18850]: time="2026-01-29T03:38:15+07:00" level=info msg="zeroconf server listening on port 36509" Jan 29 03:38:15 volumio go-librespot[18850]: time="2026-01-29T03:38:15+07:00" level=debug msg="obtained new client token: AACORZQpSfZvbKdLa4CUsYWglqg9pz7ZAfmbV+Um+qudrBQOtvkSfDdNVFmAd2CWZoVwoJaJWQr9jpFIFsHwad3vnuK114gK81hDCbQBmKjEUmLtTcPqTZde4phTIB31EK77CqCqmuGQ6HbM0t10X+vkRRgiTxdg6ZESQOOVf92qaMLnLYrCrxn2iBAfESR3VqG0v+YqaS7sFCJDQ/5lqC9XOI5RXIUQiDkEueCj8TmF4hpo1aHdBims" Jan 29 03:38:15 volumio go-librespot[18850]: time="2026-01-29T03:38:15+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 29 03:38:15 volumio go-librespot[18850]: time="2026-01-29T03:38:15+07:00" level=debug msg="completed keyexchange" Jan 29 03:38:15 volumio go-librespot[18850]: time="2026-01-29T03:38:15+07:00" level=debug msg="completed challenge" Jan 29 03:38:15 volumio go-librespot[18850]: time="2026-01-29T03:38:15+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 29 03:38:15 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 29 03:38:15 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 29 03:38:15 volumio volumio[18520]: info: Initializing connection to go-librespot Websocket Jan 29 03:38:15 volumio volumio[18520]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 29 03:38:15 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 29 03:38:15 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 29 03:38:15 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 29 03:38:17 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 29 03:38:17 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 29 03:38:17 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 29 03:38:18 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 13. Jan 29 03:38:18 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 29 03:38:18 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 29 03:38:18 volumio go-librespot[18857]: go-librespot daemon starting... Jan 29 03:38:18 volumio go-librespot[18858]: time="2026-01-29T03:38:18+07:00" level=info msg="running go-librespot 0.4.0" Jan 29 03:38:18 volumio go-librespot[18858]: time="2026-01-29T03:38:18+07:00" level=debug msg="app state loaded" Jan 29 03:38:18 volumio volumio[18520]: info: Initializing connection to go-librespot Websocket Jan 29 03:38:18 volumio go-librespot[18858]: time="2026-01-29T03:38:18+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 29 03:38:18 volumio go-librespot[18858]: time="2026-01-29T03:38:18+07:00" level=debug msg="new websocket client" Jan 29 03:38:18 volumio volumio[18520]: info: Connection to go-librespot Websocket established Jan 29 03:38:19 volumio volumio[18520]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Jan 29 03:38:19 volumio volumio[18520]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Jan 29 03:38:19 volumio volumio[18520]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Jan 29 03:38:19 volumio volumio[18520]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Jan 29 03:38:19 volumio volumio[18520]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Jan 29 03:38:19 volumio volumio[18520]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Jan 29 03:38:19 volumio volumio[18520]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Jan 29 03:38:19 volumio volumio[18520]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Jan 29 03:38:19 volumio volumio[18520]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Jan 29 03:38:19 volumio volumio[18520]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Jan 29 03:38:19 volumio volumio[18520]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Jan 29 03:38:19 volumio volumio[18520]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Jan 29 03:38:19 volumio volumio[18520]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Jan 29 03:38:19 volumio volumio[18520]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Jan 29 03:38:19 volumio volumio[18520]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Jan 29 03:38:19 volumio volumio[18520]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Jan 29 03:38:19 volumio volumio[18520]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Jan 29 03:38:19 volumio volumio[18520]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Jan 29 03:38:19 volumio volumio[18520]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Jan 29 03:38:19 volumio volumio[18520]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Jan 29 03:38:19 volumio volumio[18520]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Jan 29 03:38:19 volumio volumio[18520]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Jan 29 03:38:19 volumio volumio[18520]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Jan 29 03:38:19 volumio volumio[18520]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Jan 29 03:38:19 volumio volumio[18520]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Jan 29 03:38:19 volumio volumio[18520]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Jan 29 03:38:19 volumio volumio[18520]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Jan 29 03:38:19 volumio volumio[18520]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Jan 29 03:38:19 volumio volumio[18520]: info: Adding plugin bluetooth to MyMusic Plugins Jan 29 03:38:19 volumio volumio[18520]: info: Adding plugin multiroom to MyMusic Plugins Jan 29 03:38:19 volumio volumio[18520]: info: Adding plugin metavolumio to MyMusic Plugins Jan 29 03:38:19 volumio volumio[18520]: info: Adding plugin cd_controller to MyMusic Plugins Jan 29 03:38:19 volumio volumio[18520]: info: Adding plugin qobuzconnect to MyMusic Plugins Jan 29 03:38:19 volumio volumio[18520]: info: Adding plugin smart_inputs to MyMusic Plugins Jan 29 03:38:19 volumio volumio[18520]: info: Adding plugin tidalconnect to MyMusic Plugins Jan 29 03:38:19 volumio volumio[18520]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Jan 29 03:38:19 volumio go-librespot[18858]: time="2026-01-29T03:38:19+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 29 03:38:19 volumio go-librespot[18858]: time="2026-01-29T03:38:19+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Jan 29 03:38:19 volumio go-librespot[18858]: time="2026-01-29T03:38:19+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Jan 29 03:38:19 volumio go-librespot[18858]: time="2026-01-29T03:38:19+07:00" level=info msg="zeroconf server listening on port 38425" Jan 29 03:38:19 volumio go-librespot[18858]: time="2026-01-29T03:38:19+07:00" level=debug msg="obtained new client token: AACRuCvLCXxPPZL6TGFPOgFGwB4EIZJCVJywOnu2pa5LpeizFt3oqk2zk5ii31fGnD6+AqonJjOkLQiz6JcFvmg30Rg/Fu4cKyVuGnWheCxozuklljX5FvohpnMjZu+pOzUqjQXObYY764VZ0v5HbbKawUbavrjrx/2BktZT6W59TvbSF13Q/Bq6KiG3bbmDUUIeoDWGVXZpoSvod4ToWhtiBDDCxX5urS8WLzEp/B0wWXnOF+hYQKr9IlU=" Jan 29 03:38:19 volumio go-librespot[18858]: time="2026-01-29T03:38:19+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 29 03:38:19 volumio go-librespot[18858]: time="2026-01-29T03:38:19+07:00" level=debug msg="completed keyexchange" Jan 29 03:38:19 volumio go-librespot[18858]: time="2026-01-29T03:38:19+07:00" level=debug msg="completed challenge" Jan 29 03:38:19 volumio go-librespot[18858]: time="2026-01-29T03:38:19+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 29 03:38:19 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 29 03:38:19 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 29 03:38:19 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 29 03:38:19 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 29 03:38:19 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 29 03:38:21 volumio volumio[18520]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Jan 29 03:38:21 volumio volumio[18520]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Jan 29 03:38:21 volumio volumio[18520]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 29 03:38:21 volumio volumio[18520]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 29 03:38:21 volumio volumio[18520]: info: Starting MyVolumio Remote Streaming Endpoints Jan 29 03:38:21 volumio volumio[18520]: info: MyVolumio login type: Token Jan 29 03:38:21 volumio volumio[18520]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Jan 29 03:38:21 volumio volumio[18520]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Jan 29 03:38:21 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 29 03:38:21 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 29 03:38:21 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 29 03:38:22 volumio volumio[18520]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Jan 29 03:38:22 volumio volumio[18520]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Jan 29 03:38:22 volumio volumio[18520]: info: Streaming services startup Jan 29 03:38:22 volumio volumio[18520]: info: Starting Streaming Daemon Jan 29 03:38:22 volumio sudo[18882]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jan 29 03:38:22 volumio volumio[18520]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Jan 29 03:38:22 volumio sudo[18882]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 29 03:38:22 volumio sudo[18882]: pam_unix(sudo:session): session closed for user root Jan 29 03:38:22 volumio volumio[18520]: info: Getting Spotify volume Jan 29 03:38:22 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 14. Jan 29 03:38:22 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 29 03:38:23 volumio volumio[18520]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 29 03:38:23 volumio volumio[18520]: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 29 03:38:23 volumio volumio[18520]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Jan 29 03:38:23 volumio volumio[18520]: errno: -111, Jan 29 03:38:23 volumio volumio[18520]: code: 'ECONNREFUSED', Jan 29 03:38:23 volumio volumio[18520]: syscall: 'connect', Jan 29 03:38:23 volumio volumio[18520]: address: '127.0.0.1', Jan 29 03:38:23 volumio volumio[18520]: port: 9879, Jan 29 03:38:23 volumio volumio[18520]: response: undefined Jan 29 03:38:23 volumio volumio[18520]: } Jan 29 03:38:23 volumio volumio[18520]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 29 03:38:23 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 29 03:38:23 volumio go-librespot[18888]: go-librespot daemon starting... Jan 29 03:38:23 volumio go-librespot[18892]: time="2026-01-29T03:38:23+07:00" level=info msg="running go-librespot 0.4.0" Jan 29 03:38:23 volumio go-librespot[18892]: time="2026-01-29T03:38:23+07:00" level=debug msg="app state loaded" Jan 29 03:38:23 volumio go-librespot[18892]: time="2026-01-29T03:38:23+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 29 03:38:23 volumio go-librespot[18892]: time="2026-01-29T03:38:23+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 29 03:38:23 volumio go-librespot[18892]: time="2026-01-29T03:38:23+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 29 03:38:23 volumio go-librespot[18892]: time="2026-01-29T03:38:23+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 29 03:38:23 volumio go-librespot[18892]: time="2026-01-29T03:38:23+07:00" level=info msg="zeroconf server listening on port 45941" Jan 29 03:38:23 volumio go-librespot[18892]: time="2026-01-29T03:38:23+07:00" level=debug msg="obtained new client token: AACC4rnsqiRn3gm/Z9735nMD57sqDjPn6+HpPMfcZd4BGOtNxFAxObwFn5DLASE3TJF8TWe40P03mKiwfhA97TWPesXlxPdSWxQjvmr2mk+k32/1HMogXNt3VjCxL9uSSGzifSASzDs7RQdA8vBkva23FejZS99olxpPgibC3hMU8GEovObLuUXFsOiHE4mQ+YT4lr/SIzv0xsXWlBTpUQvc2L8lJOmcNUxI5T2KXXjuTjTDrUf3rxs3fYY=" Jan 29 03:38:23 volumio go-librespot[18892]: time="2026-01-29T03:38:23+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 29 03:38:23 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 29 03:38:23 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 29 03:38:23 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 29 03:38:24 volumio go-librespot[18892]: time="2026-01-29T03:38:24+07:00" level=debug msg="completed keyexchange" Jan 29 03:38:24 volumio go-librespot[18892]: time="2026-01-29T03:38:24+07:00" level=debug msg="completed challenge" Jan 29 03:38:24 volumio go-librespot[18892]: time="2026-01-29T03:38:24+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 29 03:38:24 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 29 03:38:24 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 29 03:38:24 volumio sudo[18910]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-01-29 03:37' Jan 29 03:38:24 volumio sudo[18910]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 29 03:38:24 volumio sudo[18910]: pam_unix(sudo:session): session closed for user root Jan 29 03:38:24 volumio volumio-remote-updater[628]: [2026-01-29 03:38:24] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Jan 29 03:38:24 volumio volumio-remote-updater[628]: [2026-01-29 03:38:24] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Jan 29 03:38:24 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Jan 29 03:38:25 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Jan 29 03:38:25 volumio systemd[1]: volumio.service: Consumed 1min 1.299s CPU time. Jan 29 03:38:25 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 29 03:38:25 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Jan 29 03:38:25 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 11089. Jan 29 03:38:25 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 29 03:38:25 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Jan 29 03:38:25 volumio systemd[1]: volumio.service: Consumed 1min 1.299s CPU time. Jan 29 03:38:25 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Jan 29 03:38:25 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Jan 29 03:38:25 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 29 03:38:25 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 29 03:38:25 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 29 03:38:27 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 15. Jan 29 03:38:27 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 29 03:38:27 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 29 03:38:27 volumio go-librespot[18938]: go-librespot daemon starting... Jan 29 03:38:27 volumio go-librespot[18939]: time="2026-01-29T03:38:27+07:00" level=info msg="running go-librespot 0.4.0" Jan 29 03:38:27 volumio go-librespot[18939]: time="2026-01-29T03:38:27+07:00" level=debug msg="app state loaded" Jan 29 03:38:27 volumio go-librespot[18939]: time="2026-01-29T03:38:27+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 29 03:38:27 volumio go-librespot[18939]: time="2026-01-29T03:38:27+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 29 03:38:27 volumio go-librespot[18939]: time="2026-01-29T03:38:27+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 29 03:38:27 volumio go-librespot[18939]: time="2026-01-29T03:38:27+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 29 03:38:27 volumio go-librespot[18939]: time="2026-01-29T03:38:27+07:00" level=info msg="zeroconf server listening on port 45143" Jan 29 03:38:27 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 29 03:38:27 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 29 03:38:27 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 29 03:38:28 volumio go-librespot[18939]: time="2026-01-29T03:38:28+07:00" level=debug msg="obtained new client token: AABEXC7xf12XONQqH5z6JtI1ducaXTdwDoTyxm3JEr9da2lKIoNLk4S+ZHfLHSRZgC5vn/KZpgJjKPpT6kyEQh8t3U79wOsBGTrbaTJ0aAgNjEimgcxKQZtOeELKHUXhT0gsFpHRvPY4n3iST0Jvs8N0W4PRLZ7qdqd2WMr0EMw5BZGbPd3W+UJNq7K6GagGgPiCejJxafLaCBH/hkHxVouPgVAwlciFisZWtADs2rhApRHqB6X8SdAh" Jan 29 03:38:28 volumio go-librespot[18939]: time="2026-01-29T03:38:28+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 29 03:38:28 volumio go-librespot[18939]: time="2026-01-29T03:38:28+07:00" level=debug msg="completed keyexchange" Jan 29 03:38:28 volumio go-librespot[18939]: time="2026-01-29T03:38:28+07:00" level=debug msg="completed challenge" Jan 29 03:38:28 volumio go-librespot[18939]: time="2026-01-29T03:38:28+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 29 03:38:28 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 29 03:38:28 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 29 03:38:28 volumio volumio[18923]: info: ------------------------------------------- Jan 29 03:38:28 volumio volumio[18923]: info: ----- Volumio3 ---- Jan 29 03:38:28 volumio volumio[18923]: info: ------------------------------------------- Jan 29 03:38:28 volumio volumio[18923]: info: ----- System startup ---- Jan 29 03:38:28 volumio volumio[18923]: info: ------------------------------------------- Jan 29 03:38:29 volumio volumio-remote-updater[628]: [2026-01-29 03:38:29] [connect] Successful connection Jan 29 03:38:29 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 29 03:38:29 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 29 03:38:29 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 29 03:38:30 volumio volumio[18923]: info: MYVOLUMIO Environment detected Jan 29 03:38:30 volumio volumio[18923]: info: Plugin folders cleanup Jan 29 03:38:30 volumio volumio[18923]: info: Scanning into folder /volumio/app/plugins/ Jan 29 03:38:30 volumio volumio[18923]: info: Scanning category audio_interface Jan 29 03:38:30 volumio volumio[18923]: info: Scanning category miscellanea Jan 29 03:38:30 volumio volumio[18923]: info: Scanning category music_service Jan 29 03:38:30 volumio volumio[18923]: info: Scanning category plugins.json Jan 29 03:38:30 volumio volumio[18923]: info: Scanning category system_controller Jan 29 03:38:30 volumio volumio[18923]: info: Scanning category user_interface Jan 29 03:38:30 volumio volumio[18923]: info: Scanning into folder /data/plugins/ Jan 29 03:38:30 volumio volumio[18923]: info: Scanning category music_service Jan 29 03:38:30 volumio volumio[18923]: info: Plugin folders cleanup completed Jan 29 03:38:30 volumio volumio[18923]: info: ------------------------------------------- Jan 29 03:38:30 volumio volumio[18923]: info: ----- Core plugins startup ---- Jan 29 03:38:30 volumio volumio[18923]: info: ------------------------------------------- Jan 29 03:38:30 volumio volumio[18923]: info: Loading plugins from folder /volumio/app/plugins/ Jan 29 03:38:30 volumio volumio[18923]: info: Adding plugin upnp to MyMusic Plugins Jan 29 03:38:30 volumio volumio[18923]: info: Adding plugin airplay_emulation to MyMusic Plugins Jan 29 03:38:30 volumio volumio[18923]: info: Adding plugin upnp_browser to MyMusic Plugins Jan 29 03:38:30 volumio volumio[18923]: info: Loading plugins from folder /data/plugins/ Jan 29 03:38:30 volumio volumio[18923]: info: Loading plugin "system"... Jan 29 03:38:30 volumio volumio[18923]: info: Loading plugin "appearance"... Jan 29 03:38:31 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 16. Jan 29 03:38:31 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 29 03:38:31 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 29 03:38:31 volumio go-librespot[18960]: go-librespot daemon starting... Jan 29 03:38:31 volumio go-librespot[18961]: time="2026-01-29T03:38:31+07:00" level=info msg="running go-librespot 0.4.0" Jan 29 03:38:31 volumio go-librespot[18961]: time="2026-01-29T03:38:31+07:00" level=debug msg="app state loaded" Jan 29 03:38:31 volumio go-librespot[18961]: time="2026-01-29T03:38:31+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 29 03:38:31 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 29 03:38:31 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 29 03:38:31 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 29 03:38:32 volumio volumio[18923]: info: Loading plugin "network"... Jan 29 03:38:32 volumio volumio[18923]: info: Refreshing Cached IP Addresses Jan 29 03:38:32 volumio go-librespot[18961]: time="2026-01-29T03:38:32+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 29 03:38:32 volumio go-librespot[18961]: time="2026-01-29T03:38:32+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 29 03:38:32 volumio go-librespot[18961]: time="2026-01-29T03:38:32+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 29 03:38:32 volumio go-librespot[18961]: time="2026-01-29T03:38:32+07:00" level=info msg="zeroconf server listening on port 34059" Jan 29 03:38:32 volumio sudo[18969]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 29 03:38:32 volumio sudo[18969]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 29 03:38:32 volumio sudo[18969]: pam_unix(sudo:session): session closed for user root Jan 29 03:38:32 volumio sudo[18971]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 29 03:38:32 volumio sudo[18971]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 29 03:38:32 volumio volumio[18923]: info: Loading plugin "services"... Jan 29 03:38:32 volumio volumio[18923]: info: Loading plugin "alsa_controller"... Jan 29 03:38:32 volumio sudo[18971]: pam_unix(sudo:session): session closed for user root Jan 29 03:38:32 volumio sudo[18979]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Jan 29 03:38:32 volumio sudo[18979]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 29 03:38:32 volumio volumio[18923]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 29 03:38:32 volumio volumio[18923]: info: Loading plugin "wizard"... Jan 29 03:38:32 volumio volumio[18923]: info: Loading plugin "networkfs"... Jan 29 03:38:32 volumio go-librespot[18961]: time="2026-01-29T03:38:32+07:00" level=debug msg="obtained new client token: AAASEQax0IVfwZ88vn3cinArv19ZrfRQGykO0idgBH9AgGXOOZ2DMPSr2ocS0MNZo3WeS4hBKnr5UEu8Rl8YCS5PTB/ARL7wg4eCSy8WNzt4ds0gsRsxuzy242qX55bjgOx4bB6UUv52xM88k8A6/fyD0EOX5r1LIlq4KUBRUrV6J6z08ejW9YJoilTbFbv12Zv2pijel5guNzUxUhVG0jXJ6T7PTWk1Ac8L9n/aHqlhdQl8mlpy/5nogIw=" Jan 29 03:38:32 volumio volumio[18923]: info: Starting Udev Watcher for removable devices Jan 29 03:38:32 volumio go-librespot[18961]: time="2026-01-29T03:38:32+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 29 03:38:32 volumio volumio[18923]: info: Ignoring mount for partition: boot Jan 29 03:38:32 volumio volumio[18923]: info: Ignoring mount for partition: volumio Jan 29 03:38:32 volumio volumio[18923]: info: Ignoring mount for partition: volumio_data Jan 29 03:38:32 volumio volumio[18923]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 29 03:38:32 volumio volumio[18923]: info: Loading plugin "volumio_command_line_client"... Jan 29 03:38:32 volumio volumio[18923]: info: Loading plugin "upnp"... Jan 29 03:38:32 volumio volumio[18923]: info: [1769632712778] Starting Upmpd Daemon Jan 29 03:38:32 volumio volumio[18923]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 29 03:38:32 volumio volumio[18923]: info: Loading plugin "my_music"... Jan 29 03:38:32 volumio volumio[18923]: info: Loading plugin "mpd"... Jan 29 03:38:32 volumio go-librespot[18961]: time="2026-01-29T03:38:32+07:00" level=debug msg="completed keyexchange" Jan 29 03:38:32 volumio go-librespot[18961]: time="2026-01-29T03:38:32+07:00" level=debug msg="completed challenge" Jan 29 03:38:32 volumio go-librespot[18961]: time="2026-01-29T03:38:32+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 29 03:38:32 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 29 03:38:32 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 29 03:38:33 volumio volumio[18923]: info: Loading plugin "upnp_browser"... Jan 29 03:38:33 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 29 03:38:33 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 29 03:38:33 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 29 03:38:35 volumio sudo[18979]: pam_unix(sudo:session): session closed for user root Jan 29 03:38:35 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 17. Jan 29 03:38:35 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 29 03:38:35 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 29 03:38:35 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 29 03:38:35 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 29 03:38:36 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 29 03:38:36 volumio go-librespot[19002]: go-librespot daemon starting... Jan 29 03:38:36 volumio go-librespot[19003]: time="2026-01-29T03:38:36+07:00" level=info msg="running go-librespot 0.4.0" Jan 29 03:38:36 volumio go-librespot[19003]: time="2026-01-29T03:38:36+07:00" level=debug msg="app state loaded" Jan 29 03:38:36 volumio go-librespot[19003]: time="2026-01-29T03:38:36+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 29 03:38:36 volumio volumio[18923]: info: Starting UPNP Browser Jan 29 03:38:36 volumio volumio[18923]: info: Loading plugin "alarm-clock"... Jan 29 03:38:36 volumio go-librespot[19003]: time="2026-01-29T03:38:36+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 29 03:38:36 volumio go-librespot[19003]: time="2026-01-29T03:38:36+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 29 03:38:36 volumio go-librespot[19003]: time="2026-01-29T03:38:36+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 29 03:38:36 volumio go-librespot[19003]: time="2026-01-29T03:38:36+07:00" level=info msg="zeroconf server listening on port 46833" Jan 29 03:38:36 volumio volumio[18923]: info: Loading plugin "airplay_emulation"... Jan 29 03:38:36 volumio volumio[18923]: info: Starting Shairport Sync Jan 29 03:38:36 volumio volumio[18923]: info: Loading plugin "last_100"... Jan 29 03:38:36 volumio volumio[18923]: info: Loading plugin "webradio"... Jan 29 03:38:36 volumio go-librespot[19003]: time="2026-01-29T03:38:36+07:00" level=debug msg="obtained new client token: AABsw92PX0OvZA5cN8LE8OGoyJ4m/gv6HtIrCUYd1Hb/44owCYqPy9zTXW9OdiVIvkYwtozpvP3s6+pV37eeER2prEbOtI/r/kIwD0RRD9nKdrrbhwVmiuSuSYZ39zH0E39sdxDcw4g9/RIE2SRWgRYh+fhNKwKXWegUCIDbltuuuXslI9/bo7h8uwGQjwcjYnItZFUMzLfWt8z5mzHjmW9RInwkTFIkR2S7QHqiC5PwyF7kDLMh9rzCAvw=" Jan 29 03:38:36 volumio go-librespot[19003]: time="2026-01-29T03:38:36+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 29 03:38:36 volumio volumio[18923]: info: Loading plugin "i2s_dacs"... Jan 29 03:38:36 volumio volumio[18923]: info: Loading plugin "volumiodiscovery"... Jan 29 03:38:37 volumio go-librespot[19003]: time="2026-01-29T03:38:37+07:00" level=debug msg="completed keyexchange" Jan 29 03:38:37 volumio volumio[18923]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 29 03:38:37 volumio volumio[18923]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 29 03:38:37 volumio volumio[18923]: *** WARNING *** For more information see Jan 29 03:38:37 volumio node[18923]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 29 03:38:37 volumio volumio[18923]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 29 03:38:37 volumio volumio[18923]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 29 03:38:37 volumio volumio[18923]: *** WARNING *** For more information see Jan 29 03:38:37 volumio go-librespot[19003]: time="2026-01-29T03:38:37+07:00" level=debug msg="completed challenge" Jan 29 03:38:37 volumio node[18923]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 29 03:38:37 volumio node[18923]: *** WARNING *** For more information see Jan 29 03:38:37 volumio node[18923]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 29 03:38:37 volumio node[18923]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 29 03:38:37 volumio node[18923]: *** WARNING *** For more information see Jan 29 03:38:37 volumio volumio[18923]: info: Applying required configuration parameters for plugin volumiodiscovery Jan 29 03:38:37 volumio volumio[18923]: info: Discovery: Started advertising with name: Volumio Jan 29 03:38:37 volumio go-librespot[19003]: time="2026-01-29T03:38:37+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 29 03:38:37 volumio volumio[18923]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 29 03:38:37 volumio volumio[18923]: info: Loading plugin "spop"... Jan 29 03:38:37 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 29 03:38:37 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 29 03:38:37 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 29 03:38:37 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 29 03:38:37 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 29 03:38:38 volumio volumio[18923]: info: Loading plugin "ytcr"... Jan 29 03:38:39 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 29 03:38:39 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 29 03:38:39 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 29 03:38:40 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 18. Jan 29 03:38:40 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 29 03:38:40 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 29 03:38:40 volumio go-librespot[19013]: go-librespot daemon starting... Jan 29 03:38:40 volumio go-librespot[19014]: time="2026-01-29T03:38:40+07:00" level=info msg="running go-librespot 0.4.0" Jan 29 03:38:40 volumio go-librespot[19014]: time="2026-01-29T03:38:40+07:00" level=debug msg="app state loaded" Jan 29 03:38:40 volumio go-librespot[19014]: time="2026-01-29T03:38:40+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 29 03:38:40 volumio go-librespot[19014]: time="2026-01-29T03:38:40+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 29 03:38:40 volumio go-librespot[19014]: time="2026-01-29T03:38:40+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 29 03:38:40 volumio go-librespot[19014]: time="2026-01-29T03:38:40+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 29 03:38:40 volumio go-librespot[19014]: time="2026-01-29T03:38:40+07:00" level=info msg="zeroconf server listening on port 41933" Jan 29 03:38:41 volumio go-librespot[19014]: time="2026-01-29T03:38:41+07:00" level=debug msg="obtained new client token: AABD7zputrbYPIpwXcGAuzgehPm+UphzIHHrq3XSvs//dxb4EpP3GUU1x0Rjlg4mHhgBJt9UatJgavsByQ9jz4iRH2ily2DkpKSgPIcmsMH8Ik/r0+3rQCw68YmuHAFSPdlCqUEH2O4S17YY0QLmlYcpxZ8PhnJIFBDt6xXIQsaA1t9CH42A9OSl8nOEU9GbeA+d8zZjSQxzoFMjp2wxFXBH2/RtWcaDfqLsjdDJHJOCA0DNEV1zelMi" Jan 29 03:38:41 volumio go-librespot[19014]: time="2026-01-29T03:38:41+07:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:4070, retrying with a different AP" error="dial tcp 104.199.241.202:4070: connect: connection refused" Jan 29 03:38:41 volumio go-librespot[19014]: time="2026-01-29T03:38:41+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Jan 29 03:38:41 volumio go-librespot[19014]: time="2026-01-29T03:38:41+07:00" level=debug msg="completed keyexchange" Jan 29 03:38:41 volumio go-librespot[19014]: time="2026-01-29T03:38:41+07:00" level=debug msg="completed challenge" Jan 29 03:38:41 volumio go-librespot[19014]: time="2026-01-29T03:38:41+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 29 03:38:41 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 29 03:38:41 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 29 03:38:41 volumio volumio[18923]: info: Loading plugin "ytmusic"... Jan 29 03:38:41 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 29 03:38:41 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 29 03:38:41 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 29 03:38:42 volumio volumio-remote-updater[628]: [2026-01-29 03:38:42] [connect] Successful connection Jan 29 03:38:42 volumio volumio[18923]: info: Loading plugin "outputs"... Jan 29 03:38:42 volumio volumio[18923]: info: Loading plugin "albumart"... Jan 29 03:38:42 volumio volumio[18923]: info: Plugin example_plugin is not enabled Jan 29 03:38:42 volumio volumio[18923]: info: Loading plugin "inputs"... Jan 29 03:38:42 volumio volumio[18923]: info: Loading plugin "updater_comm"... Jan 29 03:38:43 volumio volumio[18923]: info: Plugin mpdemulation is not enabled Jan 29 03:38:43 volumio volumio[18923]: info: Loading plugin "rest_api"... Jan 29 03:38:43 volumio volumio[18923]: info: Loading plugin "websocket"... Jan 29 03:38:43 volumio volumio[18923]: info: Starting Socket.io Server version 1.7.4 Jan 29 03:38:43 volumio volumio[18923]: info: Loading plugin "RoonBridge"... Jan 29 03:38:43 volumio volumio[18923]: info: Applying required configuration parameters for plugin RoonBridge Jan 29 03:38:43 volumio volumio[18923]: info: Loading i18n strings for locale en Jan 29 03:38:43 volumio volumio[18923]: Updating browse sources language Jan 29 03:38:43 volumio volumio[18923]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 29 03:38:43 volumio volumio[19036]: Forking 3 albumart workers Jan 29 03:38:43 volumio volumio[18923]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 29 03:38:43 volumio volumio[18923]: info: CoreCommandRouter::initPlayerControls Jan 29 03:38:43 volumio volumio[18923]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 29 03:38:43 volumio volumio[18923]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 29 03:38:43 volumio volumio[18923]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 29 03:38:43 volumio volumio[18923]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 29 03:38:43 volumio volumio[18923]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 29 03:38:43 volumio volumio[18923]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 29 03:38:43 volumio volumio[18923]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 29 03:38:43 volumio volumio[18923]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 29 03:38:43 volumio volumio[18923]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 29 03:38:43 volumio volumio[18923]: Express server listening on port 3000 Jan 29 03:38:43 volumio volumio[18923]: [Metrics] WebUI: 16s 132.05ms Jan 29 03:38:44 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 29 03:38:44 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 29 03:38:44 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 29 03:38:44 volumio volumio[18923]: info: CoreStateMachine::resetVolumioState Jan 29 03:38:44 volumio volumio[18923]: info: CoreStateMachine::getcurrentVolume Jan 29 03:38:44 volumio volumio[18923]: info: CoreCommandRouter::volumioRetrievevolume Jan 29 03:38:44 volumio sudo[19082]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 29 03:38:44 volumio sudo[19082]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 29 03:38:44 volumio volumio[18923]: info: Volumio Network Manager: Network status updated: 1 Jan 29 03:38:44 volumio sudo[19082]: pam_unix(sudo:session): session closed for user root Jan 29 03:38:44 volumio sudo[19084]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 29 03:38:44 volumio sudo[19084]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 29 03:38:44 volumio sudo[19084]: pam_unix(sudo:session): session closed for user root Jan 29 03:38:44 volumio volumio[18923]: info: VolumeController:: Volume=100 Mute =false Jan 29 03:38:44 volumio volumio[18923]: info: CoreStateMachine::pushState Jan 29 03:38:44 volumio volumio[18923]: info: CorePlayQueue::getTrack 0 Jan 29 03:38:44 volumio volumio[18923]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 29 03:38:44 volumio volumio[18923]: info: CoreCommandRouter::volumioPushState Jan 29 03:38:44 volumio volumio[18923]: info: CoreStateMachine::updateTrackBlock Jan 29 03:38:44 volumio volumio[18923]: info: CorePlayQueue::getTrackBlock Jan 29 03:38:44 volumio volumio[18923]: info: CoreCommandRouter::volumioRetrievevolume Jan 29 03:38:44 volumio volumio-remote-updater[628]: [2026-01-29 03:38:44] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1769632722 101 Jan 29 03:38:44 volumio volumio[18923]: 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 29 03:38:44 volumio volumio[18923]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 29 03:38:44 volumio volumio[18923]: info: Reloading queue from file Jan 29 03:38:44 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 19. Jan 29 03:38:44 volumio volumio[18923]: info: CoreStateMachine::setRepeat null single undefined Jan 29 03:38:44 volumio volumio[18923]: info: CoreStateMachine::pushState Jan 29 03:38:44 volumio volumio[18923]: info: CorePlayQueue::getTrack 0 Jan 29 03:38:44 volumio volumio[18923]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 29 03:38:44 volumio volumio[18923]: info: CoreCommandRouter::volumioPushState Jan 29 03:38:44 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 29 03:38:44 volumio volumio[18923]: info: CoreStateMachine::setRandom null Jan 29 03:38:44 volumio volumio[18923]: info: CoreStateMachine::pushState Jan 29 03:38:44 volumio volumio[18923]: info: CorePlayQueue::getTrack 0 Jan 29 03:38:44 volumio volumio[18923]: info: CoreCommandRouter::volumioPushState Jan 29 03:38:44 volumio volumio[18923]: info: Setting Device type: Raspberry PI Jan 29 03:38:44 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 29 03:38:44 volumio go-librespot[19095]: go-librespot daemon starting... Jan 29 03:38:44 volumio volumio[18923]: info: Completed loading Core Plugins Jan 29 03:38:44 volumio go-librespot[19097]: time="2026-01-29T03:38:44+07:00" level=info msg="running go-librespot 0.4.0" Jan 29 03:38:44 volumio go-librespot[19097]: time="2026-01-29T03:38:44+07:00" level=debug msg="app state loaded" Jan 29 03:38:44 volumio go-librespot[19097]: time="2026-01-29T03:38:44+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 29 03:38:44 volumio volumio[18923]: info: Preparing to generate the ALSA configuration file Jan 29 03:38:45 volumio volumio[18923]: info: VolumeController:: Volume=100 Mute =false Jan 29 03:38:45 volumio volumio[18923]: info: CoreStateMachine::pushState Jan 29 03:38:45 volumio volumio[18923]: info: CorePlayQueue::getTrack 0 Jan 29 03:38:45 volumio volumio[18923]: info: CoreCommandRouter::volumioPushState Jan 29 03:38:45 volumio volumio[18923]: info: Asound.conf file unchanged, so no further update is needed Jan 29 03:38:45 volumio volumio[18923]: info: Output device has changed, restarting MPD Jan 29 03:38:45 volumio sudo[19106]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Jan 29 03:38:45 volumio sudo[19106]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 29 03:38:45 volumio volumio[18923]: info: Output device has changed, restarting Shairport Sync Jan 29 03:38:45 volumio volumio[18923]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 29 03:38:45 volumio volumio[18923]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 29 03:38:45 volumio volumio[18923]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 29 03:38:45 volumio volumio[18923]: info: ___________ START PLUGINS ___________ Jan 29 03:38:45 volumio sudo[19111]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 29 03:38:45 volumio sudo[19111]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 29 03:38:45 volumio sudo[19108]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 29 03:38:45 volumio volumio[18923]: info: ControllerMpd::onStart: Initializing MPD Jan 29 03:38:45 volumio volumio[18923]: info: Creating MPD Configuration file Jan 29 03:38:45 volumio sudo[19106]: pam_unix(sudo:session): session closed for user root Jan 29 03:38:45 volumio sudo[19108]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 29 03:38:45 volumio sudo[19108]: pam_unix(sudo:session): session closed for user root Jan 29 03:38:45 volumio volumio[18923]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 29 03:38:45 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Jan 29 03:38:45 volumio volumio[18923]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 29 03:38:45 volumio volumio[18923]: info: [1769632725439] CoreMusicLibrary::Adding element Media Servers Jan 29 03:38:45 volumio volumio[18923]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 29 03:38:45 volumio volumio[18923]: info: UPNP Browser: Client initialized successfully Jan 29 03:38:45 volumio go-librespot[19097]: time="2026-01-29T03:38:45+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 29 03:38:45 volumio go-librespot[19097]: time="2026-01-29T03:38:45+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 29 03:38:45 volumio go-librespot[19097]: time="2026-01-29T03:38:45+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 29 03:38:45 volumio sudo[19120]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 29 03:38:45 volumio sudo[19120]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 29 03:38:45 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 29 03:38:45 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 29 03:38:45 volumio systemd[1]: mpd.service: Consumed 7.396s CPU time. Jan 29 03:38:45 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 29 03:38:45 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 29 03:38:45 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 29 03:38:45 volumio sudo[19120]: pam_unix(sudo:session): session closed for user root Jan 29 03:38:45 volumio go-librespot[19097]: time="2026-01-29T03:38:45+07:00" level=info msg="zeroconf server listening on port 41543" Jan 29 03:38:45 volumio sudo[19122]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 29 03:38:45 volumio sudo[19122]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 29 03:38:45 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 29 03:38:45 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 29 03:38:45 volumio volumio[18923]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 29 03:38:45 volumio volumio[18923]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 29 03:38:45 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 29 03:38:45 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 29 03:38:45 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 29 03:38:45 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 29 03:38:45 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 29 03:38:45 volumio volumio[18923]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 29 03:38:45 volumio volumio[18923]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 29 03:38:45 volumio volumio[18923]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 29 03:38:45 volumio volumio[18923]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 29 03:38:45 volumio volumio[18923]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 29 03:38:45 volumio volumio[18923]: info: [1769632725897] CoreMusicLibrary::Adding element Last_100 Jan 29 03:38:45 volumio volumio[18923]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 29 03:38:45 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 29 03:38:45 volumio volumio[18923]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 29 03:38:45 volumio volumio[18923]: info: [1769632725909] CoreMusicLibrary::Adding element Webradio Jan 29 03:38:45 volumio volumio[18923]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 29 03:38:45 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 29 03:38:45 volumio go-librespot[19097]: time="2026-01-29T03:38:45+07:00" level=debug msg="obtained new client token: AAAyF7PcO6Nt1c5YZ0EUDPQ/opy3s/xHI4Zg/Gs11ZLJgM8mDbrlBpukdd7k3j3TX1s+E48UvhGuwjJ7t2TR+Emo3kykt5f4VcYZJLujzF5b3JgKvZlRxBbK9/PfhUoedT83VRCb5/2wjW80rrsShuivMpyZGSvBmwDjMhOOA9MQXyhJIE6+XUmuNJ5s3Scy2pDXHOjGy3AJsZ0qxPUJ1UyepHDDVcaRzM0/lRoUU/2ZbjqdvkfpDuRGISI=" Jan 29 03:38:45 volumio volumio[18923]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 29 03:38:45 volumio volumio[18923]: info: Initializing BBC Radios Jan 29 03:38:46 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 29 03:38:46 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 29 03:38:46 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 29 03:38:46 volumio go-librespot[19097]: time="2026-01-29T03:38:46+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 29 03:38:46 volumio go-librespot[19097]: time="2026-01-29T03:38:46+07:00" level=debug msg="completed keyexchange" Jan 29 03:38:46 volumio go-librespot[19097]: time="2026-01-29T03:38:46+07:00" level=debug msg="completed challenge" Jan 29 03:38:46 volumio volumio[18923]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 29 03:38:46 volumio volumio[18923]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 29 03:38:46 volumio volumio[18923]: info: Creating Spotify config file Jan 29 03:38:46 volumio go-librespot[19097]: time="2026-01-29T03:38:46+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 29 03:38:46 volumio volumio[18923]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 29 03:38:46 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 29 03:38:46 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 29 03:38:46 volumio sudo[19136]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 29 03:38:46 volumio sudo[19136]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jan 29 03:38:46 volumio sudo[19136]: pam_unix(sudo:session): session closed for user root Jan 29 03:38:47 volumio volumio[19049]: Starting albumart workers Jan 29 03:38:47 volumio volumio[19048]: Starting albumart workers Jan 29 03:38:47 volumio volumio[18923]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 29 03:38:47 volumio volumio[18923]: info: [1769632727416] CoreMusicLibrary::Adding element YouTube Music Jan 29 03:38:47 volumio volumio[18923]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 29 03:38:47 volumio volumio[18923]: Cannot find translation for source YouTube Music Jan 29 03:38:47 volumio volumio[19046]: Starting albumart workers Jan 29 03:38:47 volumio volumio[18923]: info: Volumio Calling Home Jan 29 03:38:47 volumio sudo[19153]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Jan 29 03:38:47 volumio sudo[19153]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 29 03:38:47 volumio sudo[19153]: pam_unix(sudo:session): session closed for user root Jan 29 03:38:48 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 29 03:38:48 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 29 03:38:48 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 29 03:38:48 volumio volumio[18923]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Jan 29 03:38:48 volumio volumio[18923]: info: Discovery: Found device Volumio Jan 29 03:38:48 volumio volumio[18923]: info: CoreCommandRouter::volumioGetState Jan 29 03:38:48 volumio volumio[18923]: info: CorePlayQueue::getTrack 0 Jan 29 03:38:48 volumio volumio[18923]: info: MPD Permissions set Jan 29 03:38:48 volumio volumio[18923]: info: MPD Permissions set Jan 29 03:38:48 volumio volumio[18923]: info: Upmpdcli Daemon Started Jan 29 03:38:48 volumio volumio[18923]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Jan 29 03:38:48 volumio volumio[18923]: info: Discovery: Found device Volumio Jan 29 03:38:48 volumio volumio[18923]: info: CoreCommandRouter::volumioGetState Jan 29 03:38:48 volumio volumio[18923]: info: CorePlayQueue::getTrack 0 Jan 29 03:38:48 volumio volumio[18923]: info: Volumio called home Jan 29 03:38:48 volumio volumio[18923]: info: Spotify config file written Jan 29 03:38:48 volumio sudo[19159]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jan 29 03:38:48 volumio sudo[19159]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 29 03:38:48 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 29 03:38:49 volumio go-librespot[19161]: go-librespot daemon starting... Jan 29 03:38:49 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 29 03:38:49 volumio sudo[19159]: pam_unix(sudo:session): session closed for user root Jan 29 03:38:49 volumio go-librespot[19165]: time="2026-01-29T03:38:49+07:00" level=info msg="running go-librespot 0.4.0" Jan 29 03:38:49 volumio go-librespot[19165]: time="2026-01-29T03:38:49+07:00" level=debug msg="app state loaded" Jan 29 03:38:49 volumio go-librespot[19165]: time="2026-01-29T03:38:49+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 29 03:38:49 volumio volumio[18923]: 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 29 03:38:49 volumio volumio[18923]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 29 03:38:49 volumio volumio[18923]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 29 03:38:49 volumio volumio[18923]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 29 03:38:49 volumio volumio[18923]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 29 03:38:49 volumio volumio[18923]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 29 03:38:49 volumio volumio[18923]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 29 03:38:49 volumio volumio[18923]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 29 03:38:49 volumio volumio[18923]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 29 03:38:49 volumio volumio[18923]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 29 03:38:49 volumio volumio[18923]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 29 03:38:49 volumio volumio[18923]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 29 03:38:49 volumio volumio[18923]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 29 03:38:49 volumio volumio[18923]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 29 03:38:49 volumio volumio[18923]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 29 03:38:49 volumio volumio[18923]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 29 03:38:49 volumio volumio[18923]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 29 03:38:49 volumio volumio[18923]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 29 03:38:49 volumio volumio[18923]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 29 03:38:49 volumio volumio[18923]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 29 03:38:49 volumio volumio[18923]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 29 03:38:49 volumio volumio[18923]: info: No need to fix Spotify hosts Jan 29 03:38:49 volumio go-librespot[19165]: time="2026-01-29T03:38:49+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 29 03:38:49 volumio go-librespot[19165]: time="2026-01-29T03:38:49+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 29 03:38:49 volumio go-librespot[19165]: time="2026-01-29T03:38:49+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 29 03:38:49 volumio go-librespot[19165]: time="2026-01-29T03:38:49+07:00" level=info msg="zeroconf server listening on port 41295" Jan 29 03:38:50 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 29 03:38:50 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 29 03:38:50 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 29 03:38:50 volumio go-librespot[19165]: time="2026-01-29T03:38:50+07:00" level=debug msg="obtained new client token: AABeVUP95vkF0B/EPI5OX9x4y/Q+5W9Ic7l6RCBKyGc/frde37xTWLSb3snsbEtHB7E1HJ5OvITV9DyPNWAZDKm+qsiGmBPDoZYYPt4GT1DyS2Iz0JyxMrpLgh/DV4T65+dof4Jq1imDZZED0wDg/BH8m9UhxAkDQR/lDVlS+cH1Yzh97Mq5GHSvSNqCTuBivXFcEZAt/FpGozkMvzXulRSwz7krDBgNxMD8jpVQBVN2BdtKJfSKhbEq" Jan 29 03:38:50 volumio go-librespot[19165]: time="2026-01-29T03:38:50+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 29 03:38:50 volumio volumio[18923]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 29 03:38:50 volumio volumio[18923]: SPOTIFY: BQCmwfJas2UrjSg0o6wL5OzQYXEfcwuGDboVhv-1v3rVv380SgDcJyRjnfVFxNGcu89sEk_JZEkBNOUnNTacDUmOOomsO9g9yuoXvjVD0L6N3Ou2X0_q7EkOrnlTvUaJ45Xpw2NQ0swjoBOc9yRUz2hKBCIW1qlJConr-OuAL_I0hhCMQnds26nY7R_tm7XrzD1Xz5eoWCSlufbN4Gu2UqRxkNXrAE8hAGyHbZ7R0FQAlwFUMEwcNtU6RgpFIPG5XeSnnRRD7gRNO3CG_AqDoevtI1WQdNdr6NpHJieOT1ANqLVnSpzCfx9P Jan 29 03:38:50 volumio volumio[18923]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 29 03:38:50 volumio volumio[18923]: info: New Spotify access token = BQCmwfJas2UrjSg0o6wL5OzQYXEfcwuGDboVhv-1v3rVv380SgDcJyRjnfVFxNGcu89sEk_JZEkBNOUnNTacDUmOOomsO9g9yuoXvjVD0L6N3Ou2X0_q7EkOrnlTvUaJ45Xpw2NQ0swjoBOc9yRUz2hKBCIW1qlJConr-OuAL_I0hhCMQnds26nY7R_tm7XrzD1Xz5eoWCSlufbN4Gu2UqRxkNXrAE8hAGyHbZ7R0FQAlwFUMEwcNtU6RgpFIPG5XeSnnRRD7gRNO3CG_AqDoevtI1WQdNdr6NpHJieOT1ANqLVnSpzCfx9P Jan 29 03:38:50 volumio volumio[18923]: info: Spotify credentials grant success - running version from March 24, 2019 Jan 29 03:38:50 volumio volumio[18923]: info: Starting Shairport Sync Jan 29 03:38:50 volumio volumio[18923]: info: Starting Shairport Sync Jan 29 03:38:50 volumio go-librespot[19165]: time="2026-01-29T03:38:50+07:00" level=debug msg="completed keyexchange" Jan 29 03:38:50 volumio volumio[18923]: info: Starting Shairport Sync Jan 29 03:38:50 volumio go-librespot[19165]: time="2026-01-29T03:38:50+07:00" level=debug msg="completed challenge" Jan 29 03:38:50 volumio sudo[19200]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 29 03:38:50 volumio sudo[19198]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 29 03:38:50 volumio sudo[19200]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 29 03:38:50 volumio sudo[19198]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 29 03:38:50 volumio go-librespot[19165]: time="2026-01-29T03:38:50+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 29 03:38:50 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 29 03:38:50 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 29 03:38:50 volumio sudo[19202]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 29 03:38:50 volumio sudo[19202]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 29 03:38:50 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 29 03:38:50 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Jan 29 03:38:50 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 29 03:38:50 volumio systemd[1]: shairport-sync.service: Consumed 2.348s CPU time. Jan 29 03:38:50 volumio volumio[18923]: info: CoreCommandRouter::volumioGetState Jan 29 03:38:50 volumio volumio[18923]: info: CorePlayQueue::getTrack 0 Jan 29 03:38:50 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 29 03:38:50 volumio sudo[19198]: pam_unix(sudo:session): session closed for user root Jan 29 03:38:50 volumio sudo[19200]: pam_unix(sudo:session): session closed for user root Jan 29 03:38:50 volumio sudo[19202]: pam_unix(sudo:session): session closed for user root Jan 29 03:38:50 volumio volumio[18923]: info: Shairport-Sync Started Jan 29 03:38:50 volumio volumio[18923]: Error adding Membership: Error: addMembership EINVAL Jan 29 03:38:50 volumio volumio[18923]: info: Shairport-Sync Started Jan 29 03:38:50 volumio volumio[18923]: info: Shairport-Sync Started Jan 29 03:38:51 volumio volumio[18923]: 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 29 03:38:51 volumio volumio[18923]: info: Spotify Successfully logged in Jan 29 03:38:51 volumio volumio[18923]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 29 03:38:51 volumio volumio[18923]: info: [1769632731061] CoreMusicLibrary::Adding element Spotify Jan 29 03:38:51 volumio volumio[18923]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 29 03:38:51 volumio volumio[18923]: Cannot find translation for source YouTube Music Jan 29 03:38:51 volumio volumio[18923]: Cannot find translation for source Spotify Jan 29 03:38:51 volumio volumio[18923]: info: [yt-cast-receiver] DIAL server listening on port 8098 Jan 29 03:38:51 volumio volumio[18923]: info: CoreCommandRouter::volumioRetrievevolume Jan 29 03:38:52 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 29 03:38:52 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 29 03:38:52 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 29 03:38:52 volumio volumio[18923]: info: VolumeController:: Volume=100 Mute =false Jan 29 03:38:52 volumio volumio[18923]: info: CoreCommandRouter::volumioGetState Jan 29 03:38:52 volumio volumio[18923]: info: CorePlayQueue::getTrack 0 Jan 29 03:38:52 volumio volumio[18923]: info: CoreStateMachine::pushState Jan 29 03:38:52 volumio volumio[18923]: info: CorePlayQueue::getTrack 0 Jan 29 03:38:52 volumio volumio[18923]: info: CoreCommandRouter::volumioPushState Jan 29 03:38:53 volumio volumio[18923]: info: go-librespot daemon successfully initialized Jan 29 03:38:53 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 20. Jan 29 03:38:53 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 29 03:38:53 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 29 03:38:53 volumio go-librespot[19240]: go-librespot daemon starting... Jan 29 03:38:53 volumio go-librespot[19241]: time="2026-01-29T03:38:53+07:00" level=info msg="running go-librespot 0.4.0" Jan 29 03:38:53 volumio go-librespot[19241]: time="2026-01-29T03:38:53+07:00" level=debug msg="app state loaded" Jan 29 03:38:53 volumio go-librespot[19241]: time="2026-01-29T03:38:53+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 29 03:38:53 volumio mpd[19151]: 2026-01-29T03:38:53 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 29 03:38:53 volumio systemd[1]: Started mpd.service - Music Player Daemon. Jan 29 03:38:53 volumio sudo[19122]: pam_unix(sudo:session): session closed for user root Jan 29 03:38:53 volumio sudo[19111]: pam_unix(sudo:session): session closed for user root Jan 29 03:38:54 volumio volumio[18923]: error: MPD error: The expression evaluated to a falsy value: Jan 29 03:38:54 volumio volumio[18923]: assert.ok(self.idling) Jan 29 03:38:54 volumio volumio[18923]: error: The expression evaluated to a falsy value: Jan 29 03:38:54 volumio volumio[18923]: assert.ok(self.idling) Jan 29 03:38:54 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 29 03:38:54 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 29 03:38:54 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 29 03:38:54 volumio volumio[18923]: error: updateQueue error: null Jan 29 03:38:54 volumio volumio[18923]: info: MPD running with PID19151 Jan 29 03:38:54 volumio volumio[18923]: ,establishing connection Jan 29 03:38:54 volumio volumio[18923]: error: updateQueue error: null Jan 29 03:38:54 volumio volumio[18923]: info: Completed starting Core Plugins Jan 29 03:38:54 volumio volumio[18923]: info: ------------------------------------------- Jan 29 03:38:54 volumio volumio[18923]: info: ----- MyVolumio plugins startup ---- Jan 29 03:38:54 volumio volumio[18923]: info: ------------------------------------------- Jan 29 03:38:54 volumio volumio[18923]: info: [MyVolumio PluginManager] Fetching plans data.... Jan 29 03:38:54 volumio go-librespot[19241]: time="2026-01-29T03:38: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 29 03:38:54 volumio go-librespot[19241]: time="2026-01-29T03:38:54+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 29 03:38:54 volumio go-librespot[19241]: time="2026-01-29T03:38:54+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 29 03:38:54 volumio go-librespot[19241]: time="2026-01-29T03:38:54+07:00" level=info msg="zeroconf server listening on port 38353" Jan 29 03:38:54 volumio go-librespot[19241]: time="2026-01-29T03:38:54+07:00" level=debug msg="obtained new client token: AAAUPCgbzV86wn8i0c8XNq9hef6uV5Fc8en/cbLlU2NwoUjMQlCz0UQRRVj3wCMiH82yUfTTyJaGa0YAq6H316XB8hGPpqYBxOOql05XLdgb+jqysjozbGxm/s9AP4xyAybguOiNtfn7blisfoSbzF54kAXzbH98mZQXImJWAnJI5Di08liiXqwIHfBDn5TD/ToJrZzGFsKdPt7Eu/+gzDxkaGKZdEGrtgjuzHsm85sAtzal2FfDyBSRCdA=" Jan 29 03:38:54 volumio go-librespot[19241]: time="2026-01-29T03:38:54+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 29 03:38:54 volumio go-librespot[19241]: time="2026-01-29T03:38:54+07:00" level=debug msg="completed keyexchange" Jan 29 03:38:54 volumio go-librespot[19241]: time="2026-01-29T03:38:54+07:00" level=debug msg="completed challenge" Jan 29 03:38:54 volumio go-librespot[19241]: time="2026-01-29T03:38:54+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 29 03:38:54 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 29 03:38:54 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 29 03:38:56 volumio volumio[18923]: info: Initializing connection to go-librespot Websocket Jan 29 03:38:56 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 29 03:38:56 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 29 03:38:56 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 29 03:38:56 volumio volumio[18923]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 29 03:38:57 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 21. Jan 29 03:38:57 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 29 03:38:58 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 29 03:38:58 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 29 03:38:58 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 29 03:38:58 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 29 03:38:58 volumio go-librespot[19252]: go-librespot daemon starting... Jan 29 03:38:58 volumio go-librespot[19253]: time="2026-01-29T03:38:58+07:00" level=info msg="running go-librespot 0.4.0" Jan 29 03:38:58 volumio go-librespot[19253]: time="2026-01-29T03:38:58+07:00" level=debug msg="app state loaded" Jan 29 03:38:58 volumio go-librespot[19253]: time="2026-01-29T03:38:58+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 29 03:38:58 volumio go-librespot[19253]: time="2026-01-29T03:38:58+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 29 03:38:58 volumio go-librespot[19253]: time="2026-01-29T03:38:58+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 29 03:38:58 volumio go-librespot[19253]: time="2026-01-29T03:38:58+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 29 03:38:58 volumio go-librespot[19253]: time="2026-01-29T03:38:58+07:00" level=info msg="zeroconf server listening on port 46541" Jan 29 03:38:58 volumio go-librespot[19253]: time="2026-01-29T03:38:58+07:00" level=debug msg="obtained new client token: AAB/FgFpC7QZ7RSTB/e0Avqozx0pNlthW/e9nkXDjZwuZvZfFZgajk2D/djw6MJ7q3xEz7J9IXwuNQyVsQ+p0IqMahGNi6UIRfVGnZJarxc++BweU2Bh5jrhqcLQgpQfRR/8DQag1a9P+i0R0qSTv6u0ZyvoL1nk6twEyndHXteM20wecrYNYtPZM/xoPzHWImE7uoEm+VMUrsVvuyJ5CRNF3ojYwp479UN9io+vO/VhlUeLbuPmxQZeGJU=" Jan 29 03:38:58 volumio volumio[18923]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Jan 29 03:38:58 volumio go-librespot[19253]: time="2026-01-29T03:38:58+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 29 03:38:59 volumio go-librespot[19253]: time="2026-01-29T03:38:59+07:00" level=debug msg="completed keyexchange" Jan 29 03:38:59 volumio go-librespot[19253]: time="2026-01-29T03:38:59+07:00" level=debug msg="completed challenge" Jan 29 03:38:59 volumio volumio[18923]: info: Initializing connection to go-librespot Websocket Jan 29 03:38:59 volumio go-librespot[19253]: time="2026-01-29T03:38:59+07:00" level=debug msg="new websocket client" Jan 29 03:38:59 volumio volumio[18923]: info: Connection to go-librespot Websocket established Jan 29 03:38:59 volumio go-librespot[19253]: time="2026-01-29T03:38: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 29 03:38:59 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 29 03:38:59 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 29 03:38:59 volumio volumio[18923]: info: Connection to go-librespot Websocket closed Jan 29 03:39:00 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 29 03:39:00 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 29 03:39:00 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 29 03:39:02 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 29 03:39:02 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 29 03:39:02 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 29 03:39:02 volumio volumio[18923]: info: Getting Spotify volume Jan 29 03:39:02 volumio volumio[18923]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 29 03:39:02 volumio volumio[18923]: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 29 03:39:02 volumio volumio[18923]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Jan 29 03:39:02 volumio volumio[18923]: errno: -111, Jan 29 03:39:02 volumio volumio[18923]: code: 'ECONNREFUSED', Jan 29 03:39:02 volumio volumio[18923]: syscall: 'connect', Jan 29 03:39:02 volumio volumio[18923]: address: '127.0.0.1', Jan 29 03:39:02 volumio volumio[18923]: port: 9879, Jan 29 03:39:02 volumio volumio[18923]: response: undefined Jan 29 03:39:02 volumio volumio[18923]: } Jan 29 03:39:02 volumio volumio[18923]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 29 03:39:02 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 22. Jan 29 03:39:02 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 29 03:39:02 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 29 03:39:02 volumio go-librespot[19271]: go-librespot daemon starting... Jan 29 03:39:02 volumio go-librespot[19272]: time="2026-01-29T03:39:02+07:00" level=info msg="running go-librespot 0.4.0" Jan 29 03:39:02 volumio go-librespot[19272]: time="2026-01-29T03:39:02+07:00" level=debug msg="app state loaded" Jan 29 03:39:02 volumio go-librespot[19272]: time="2026-01-29T03:39:02+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 29 03:39:02 volumio go-librespot[19272]: time="2026-01-29T03:39:02+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 29 03:39:02 volumio go-librespot[19272]: time="2026-01-29T03:39:02+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 29 03:39:02 volumio go-librespot[19272]: time="2026-01-29T03:39:02+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 29 03:39:02 volumio go-librespot[19272]: time="2026-01-29T03:39:02+07:00" level=info msg="zeroconf server listening on port 43549" Jan 29 03:39:03 volumio go-librespot[19272]: time="2026-01-29T03:39:03+07:00" level=debug msg="obtained new client token: AAB4qqC8rENBpw/6+010NrPajg2zhQiJ7+IgjwUH5vUfhcc2MFDgJ88HLVGBX5JHjvx3d5IWFH9nqQJAyqcHdisSoHRU8fWP+iS/MKKqX0mQ1bJ7gGf3VTe4xLxUz1ErkQ19+6Sxr567lmdH1gN1a9TYcYZx5uS7uXY3LYnRGO4NAGGrlfkJiL5oW/XeSDy4z7F1yVvzk2UrPgI4w1LIoUX0UXVDeKA3fAiN2ZNUaAWQ3twhXP46w9G8" Jan 29 03:39:03 volumio go-librespot[19272]: time="2026-01-29T03:39:03+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 29 03:39:03 volumio go-librespot[19272]: time="2026-01-29T03:39:03+07:00" level=debug msg="completed keyexchange" Jan 29 03:39:03 volumio go-librespot[19272]: time="2026-01-29T03:39:03+07:00" level=debug msg="completed challenge" Jan 29 03:39:03 volumio go-librespot[19272]: time="2026-01-29T03:39:03+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 29 03:39:03 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 29 03:39:03 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 29 03:39:03 volumio sudo[19297]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-01-29 03:38' Jan 29 03:39:03 volumio sudo[19297]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 29 03:39:03 volumio sudo[19297]: pam_unix(sudo:session): session closed for user root Jan 29 03:39:04 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 29 03:39:04 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 29 03:39:04 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 29 03:39:04 volumio volumio-remote-updater[628]: [2026-01-29 03:39:04] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Jan 29 03:39:04 volumio volumio-remote-updater[628]: [2026-01-29 03:39:04] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Jan 29 03:39:04 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Jan 29 03:39:04 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Jan 29 03:39:04 volumio systemd[1]: volumio.service: Consumed 56.977s CPU time. Jan 29 03:39:04 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 29 03:39:04 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Jan 29 03:39:04 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 11090. Jan 29 03:39:04 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 29 03:39:04 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Jan 29 03:39:04 volumio systemd[1]: volumio.service: Consumed 56.977s CPU time. Jan 29 03:39:04 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Jan 29 03:39:04 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Jan 29 03:39:06 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 29 03:39:06 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 29 03:39:06 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 29 03:39:06 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 23. Jan 29 03:39:06 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 29 03:39:06 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 29 03:39:06 volumio go-librespot[19324]: go-librespot daemon starting... Jan 29 03:39:06 volumio go-librespot[19325]: time="2026-01-29T03:39:06+07:00" level=info msg="running go-librespot 0.4.0" Jan 29 03:39:06 volumio go-librespot[19325]: time="2026-01-29T03:39:06+07:00" level=debug msg="app state loaded" Jan 29 03:39:06 volumio go-librespot[19325]: time="2026-01-29T03:39:06+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 29 03:39:07 volumio go-librespot[19325]: time="2026-01-29T03:39: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 29 03:39:07 volumio go-librespot[19325]: time="2026-01-29T03:39: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 29 03:39:07 volumio go-librespot[19325]: time="2026-01-29T03:39: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 29 03:39:07 volumio go-librespot[19325]: time="2026-01-29T03:39:07+07:00" level=info msg="zeroconf server listening on port 36017" Jan 29 03:39:07 volumio go-librespot[19325]: time="2026-01-29T03:39:07+07:00" level=debug msg="obtained new client token: AAD0Sx5UTSUsLx/U1hTbUuv88w21Zq5fGEswQfZzXeiR0pn0U+/6JX4brVPlXaO1aH21jBwb7rtJyFztwJ5CVGc3mLzLmg+z/gfDg83V6C/Ye4aHlISH+bq6qknzLTxXPVRvqIcByckKDSXMRRP6InDgAt2hF8AkHHFx/heKc5jKL6QFlDMBDTXDFHOqzzwU6cRCy5SwIvj5MJVIR3MpLvb1PJbJ1kB8Q7xZd3FnkjN45jGRq2Uc2pTcjiw=" Jan 29 03:39:07 volumio go-librespot[19325]: time="2026-01-29T03:39:07+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 29 03:39:07 volumio go-librespot[19325]: time="2026-01-29T03:39:07+07:00" level=debug msg="completed keyexchange" Jan 29 03:39:07 volumio go-librespot[19325]: time="2026-01-29T03:39:07+07:00" level=debug msg="completed challenge" Jan 29 03:39:07 volumio go-librespot[19325]: time="2026-01-29T03:39: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 29 03:39:07 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 29 03:39:07 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 29 03:39:07 volumio volumio[19309]: info: ------------------------------------------- Jan 29 03:39:07 volumio volumio[19309]: info: ----- Volumio3 ---- Jan 29 03:39:07 volumio volumio[19309]: info: ------------------------------------------- Jan 29 03:39:07 volumio volumio[19309]: info: ----- System startup ---- Jan 29 03:39:07 volumio volumio[19309]: info: ------------------------------------------- Jan 29 03:39:08 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 29 03:39:08 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 29 03:39:08 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 29 03:39:09 volumio volumio-remote-updater[628]: [2026-01-29 03:39:09] [connect] Successful connection Jan 29 03:39:09 volumio volumio[19309]: info: MYVOLUMIO Environment detected Jan 29 03:39:09 volumio volumio[19309]: info: Plugin folders cleanup Jan 29 03:39:09 volumio volumio[19309]: info: Scanning into folder /volumio/app/plugins/ Jan 29 03:39:09 volumio volumio[19309]: info: Scanning category audio_interface Jan 29 03:39:09 volumio volumio[19309]: info: Scanning category miscellanea Jan 29 03:39:09 volumio volumio[19309]: info: Scanning category music_service Jan 29 03:39:09 volumio volumio[19309]: info: Scanning category plugins.json Jan 29 03:39:09 volumio volumio[19309]: info: Scanning category system_controller Jan 29 03:39:09 volumio volumio[19309]: info: Scanning category user_interface Jan 29 03:39:09 volumio volumio[19309]: info: Scanning into folder /data/plugins/ Jan 29 03:39:09 volumio volumio[19309]: info: Scanning category music_service Jan 29 03:39:09 volumio volumio[19309]: info: Plugin folders cleanup completed Jan 29 03:39:09 volumio volumio[19309]: info: ------------------------------------------- Jan 29 03:39:09 volumio volumio[19309]: info: ----- Core plugins startup ---- Jan 29 03:39:09 volumio volumio[19309]: info: ------------------------------------------- Jan 29 03:39:09 volumio volumio[19309]: info: Loading plugins from folder /volumio/app/plugins/ Jan 29 03:39:09 volumio volumio[19309]: info: Adding plugin upnp to MyMusic Plugins Jan 29 03:39:09 volumio volumio[19309]: info: Adding plugin airplay_emulation to MyMusic Plugins Jan 29 03:39:09 volumio volumio[19309]: info: Adding plugin upnp_browser to MyMusic Plugins Jan 29 03:39:09 volumio volumio[19309]: info: Loading plugins from folder /data/plugins/ Jan 29 03:39:09 volumio volumio[19309]: info: Loading plugin "system"... Jan 29 03:39:09 volumio volumio[19309]: info: Loading plugin "appearance"... Jan 29 03:39:10 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 29 03:39:10 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 29 03:39:10 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 29 03:39:10 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 24. Jan 29 03:39:10 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 29 03:39:11 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 29 03:39:11 volumio go-librespot[19345]: go-librespot daemon starting... Jan 29 03:39:11 volumio go-librespot[19347]: time="2026-01-29T03:39:11+07:00" level=info msg="running go-librespot 0.4.0" Jan 29 03:39:11 volumio go-librespot[19347]: time="2026-01-29T03:39:11+07:00" level=debug msg="app state loaded" Jan 29 03:39:11 volumio go-librespot[19347]: time="2026-01-29T03:39:11+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 29 03:39:11 volumio volumio[19309]: info: Loading plugin "network"... Jan 29 03:39:11 volumio volumio[19309]: info: Refreshing Cached IP Addresses Jan 29 03:39:11 volumio sudo[19354]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 29 03:39:11 volumio sudo[19354]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 29 03:39:11 volumio sudo[19354]: pam_unix(sudo:session): session closed for user root Jan 29 03:39:11 volumio sudo[19359]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 29 03:39:11 volumio sudo[19359]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 29 03:39:11 volumio volumio[19309]: info: Loading plugin "services"... Jan 29 03:39:11 volumio volumio[19309]: info: Loading plugin "alsa_controller"... Jan 29 03:39:11 volumio sudo[19359]: pam_unix(sudo:session): session closed for user root Jan 29 03:39:11 volumio sudo[19366]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Jan 29 03:39:11 volumio sudo[19366]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 29 03:39:11 volumio volumio[19309]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 29 03:39:11 volumio volumio[19309]: info: Loading plugin "wizard"... Jan 29 03:39:11 volumio volumio[19309]: info: Loading plugin "networkfs"... Jan 29 03:39:11 volumio go-librespot[19347]: time="2026-01-29T03:39:11+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 29 03:39:11 volumio go-librespot[19347]: time="2026-01-29T03:39:11+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 29 03:39:11 volumio go-librespot[19347]: time="2026-01-29T03:39:11+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 29 03:39:11 volumio volumio[19309]: info: Starting Udev Watcher for removable devices Jan 29 03:39:11 volumio go-librespot[19347]: time="2026-01-29T03:39:11+07:00" level=info msg="zeroconf server listening on port 39999" Jan 29 03:39:11 volumio volumio[19309]: info: Ignoring mount for partition: boot Jan 29 03:39:11 volumio volumio[19309]: info: Ignoring mount for partition: volumio Jan 29 03:39:11 volumio volumio[19309]: info: Ignoring mount for partition: volumio_data Jan 29 03:39:11 volumio volumio[19309]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 29 03:39:11 volumio volumio[19309]: info: Loading plugin "volumio_command_line_client"... Jan 29 03:39:11 volumio volumio[19309]: info: Loading plugin "upnp"... Jan 29 03:39:11 volumio volumio[19309]: info: [1769632751836] Starting Upmpd Daemon Jan 29 03:39:11 volumio volumio[19309]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 29 03:39:11 volumio volumio[19309]: info: Loading plugin "my_music"... Jan 29 03:39:11 volumio volumio[19309]: info: Loading plugin "mpd"... Jan 29 03:39:11 volumio go-librespot[19347]: time="2026-01-29T03:39:11+07:00" level=debug msg="obtained new client token: AACUqkAjsEvXZcZ/Hz7IwqkB6/krQhvBuZ5AEryTtpn5xBPvInGj0CLKj30LcApTt6i6pZFtHrbeP8AgQ5gQhUNk+O3c06PzqSDFbEw+J0T1AILRyALK/2q+C90EkJExkyM9J2BThhlivLB1qiwA3taNf2jDcIGq9UCCGWcxQfarL7J7rFjcP3WFpf9JYvd5ZHDBeKw6Tz87IB77blDODO17B3989tKLx4OOomkn8CWmevPKbgun5+F/XyE=" Jan 29 03:39:12 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 29 03:39:12 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 29 03:39:12 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 29 03:39:12 volumio go-librespot[19347]: time="2026-01-29T03:39:12+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 29 03:39:12 volumio go-librespot[19347]: time="2026-01-29T03:39:12+07:00" level=debug msg="completed keyexchange" Jan 29 03:39:12 volumio go-librespot[19347]: time="2026-01-29T03:39:12+07:00" level=debug msg="completed challenge" Jan 29 03:39:12 volumio go-librespot[19347]: time="2026-01-29T03:39: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 29 03:39:12 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 29 03:39:12 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 29 03:39:12 volumio volumio[19309]: info: Loading plugin "upnp_browser"... Jan 29 03:39:14 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 29 03:39:14 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 29 03:39:14 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 29 03:39:14 volumio sudo[19366]: pam_unix(sudo:session): session closed for user root Jan 29 03:39:15 volumio volumio[19309]: info: Starting UPNP Browser Jan 29 03:39:15 volumio volumio[19309]: info: Loading plugin "alarm-clock"... Jan 29 03:39:15 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 25. Jan 29 03:39:15 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 29 03:39:15 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 29 03:39:15 volumio go-librespot[19391]: go-librespot daemon starting... Jan 29 03:39:15 volumio go-librespot[19392]: time="2026-01-29T03:39:15+07:00" level=info msg="running go-librespot 0.4.0" Jan 29 03:39:15 volumio go-librespot[19392]: time="2026-01-29T03:39:15+07:00" level=debug msg="app state loaded" Jan 29 03:39:15 volumio go-librespot[19392]: time="2026-01-29T03:39:15+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 29 03:39:15 volumio volumio[19309]: info: Loading plugin "airplay_emulation"... Jan 29 03:39:15 volumio volumio[19309]: info: Starting Shairport Sync Jan 29 03:39:15 volumio volumio[19309]: info: Loading plugin "last_100"... Jan 29 03:39:15 volumio volumio[19309]: info: Loading plugin "webradio"... Jan 29 03:39:15 volumio volumio[19309]: info: Loading plugin "i2s_dacs"... Jan 29 03:39:15 volumio volumio[19309]: info: Loading plugin "volumiodiscovery"... Jan 29 03:39:16 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 29 03:39:16 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 29 03:39:16 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 29 03:39:16 volumio volumio[19309]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 29 03:39:16 volumio volumio[19309]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 29 03:39:16 volumio volumio[19309]: *** WARNING *** For more information see Jan 29 03:39:16 volumio volumio[19309]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 29 03:39:16 volumio volumio[19309]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 29 03:39:16 volumio volumio[19309]: *** WARNING *** For more information see Jan 29 03:39:16 volumio node[19309]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 29 03:39:16 volumio node[19309]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 29 03:39:16 volumio node[19309]: *** WARNING *** For more information see Jan 29 03:39:16 volumio node[19309]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 29 03:39:16 volumio node[19309]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 29 03:39:16 volumio node[19309]: *** WARNING *** For more information see Jan 29 03:39:16 volumio volumio[19309]: info: Applying required configuration parameters for plugin volumiodiscovery Jan 29 03:39:16 volumio volumio[19309]: info: Discovery: Started advertising with name: Volumio Jan 29 03:39:16 volumio go-librespot[19392]: time="2026-01-29T03:39: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 29 03:39:16 volumio go-librespot[19392]: time="2026-01-29T03:39: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 29 03:39:16 volumio go-librespot[19392]: time="2026-01-29T03:39: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 29 03:39:16 volumio volumio[19309]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 29 03:39:16 volumio volumio[19309]: info: Loading plugin "spop"... Jan 29 03:39:16 volumio go-librespot[19392]: time="2026-01-29T03:39:16+07:00" level=info msg="zeroconf server listening on port 37329" Jan 29 03:39:16 volumio go-librespot[19392]: time="2026-01-29T03:39:16+07:00" level=debug msg="obtained new client token: AAB+PQmKH37uK4VlVfDUzSZfbQ4icRpcqGSjZFYf99czaACGV0nFzWs2Z1xXJin6y4Sh1He3xRMZJ2cyI9w6rM+Bf8Sxcbi/plhFBoYBXNoupxFvrbSf6YN5AkMmzwZ6gCXmCOCJRrynwuAGT8LpzgpItjVhtbfC/c9BC9Xfz2FXsTNU22A3XuOsMbAMM81hlENAb0YfcrQpwtesD7RWqs5QGWZWdikxrYrfhUh5eUzEW0ofyyEQpDLsM2E=" Jan 29 03:39:16 volumio go-librespot[19392]: time="2026-01-29T03:39:16+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 29 03:39:16 volumio go-librespot[19392]: time="2026-01-29T03:39:16+07:00" level=debug msg="completed keyexchange" Jan 29 03:39:16 volumio go-librespot[19392]: time="2026-01-29T03:39:16+07:00" level=debug msg="completed challenge" Jan 29 03:39:16 volumio go-librespot[19392]: time="2026-01-29T03:39: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 29 03:39:16 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 29 03:39:16 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 29 03:39:17 volumio volumio[19309]: info: Loading plugin "ytcr"... Jan 29 03:39:18 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 29 03:39:18 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 29 03:39:18 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 29 03:39:19 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 26. Jan 29 03:39:19 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 29 03:39:19 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 29 03:39:19 volumio go-librespot[19401]: go-librespot daemon starting... Jan 29 03:39:19 volumio go-librespot[19402]: time="2026-01-29T03:39:19+07:00" level=info msg="running go-librespot 0.4.0" Jan 29 03:39:19 volumio go-librespot[19402]: time="2026-01-29T03:39:19+07:00" level=debug msg="app state loaded" Jan 29 03:39:19 volumio go-librespot[19402]: time="2026-01-29T03:39:19+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 29 03:39:20 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 29 03:39:20 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 29 03:39:20 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 29 03:39:20 volumio go-librespot[19402]: time="2026-01-29T03:39: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 29 03:39:20 volumio go-librespot[19402]: time="2026-01-29T03:39: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 29 03:39:20 volumio go-librespot[19402]: time="2026-01-29T03:39: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 29 03:39:20 volumio go-librespot[19402]: time="2026-01-29T03:39:20+07:00" level=info msg="zeroconf server listening on port 46277" Jan 29 03:39:20 volumio go-librespot[19402]: time="2026-01-29T03:39:20+07:00" level=debug msg="obtained new client token: AAA0HioXuDJwjwGVXgACbrNwaIHVs3A/9CkvjJ3mkxNTmjVUotep81lchyKRY1sivF7FsmmDLz9P3uS953+6rTfkGP/o6Mlk6s4LQw4jElZJOIG2dbe/jdIIHYTXzgLqEK5pblESf1DvWUXTVP8FONmWN4ajlGaJhn2pw2rP0MdKQJ3m5mE97uh3DnuztzvZOfVZEe4vDDAk/FAw1PoSgz+iNMoju40TJe/OsIeoWXh3CvXZ4rv4p9Vll/8=" Jan 29 03:39:20 volumio volumio[19309]: info: Loading plugin "ytmusic"... Jan 29 03:39:20 volumio go-librespot[19402]: time="2026-01-29T03:39:20+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 29 03:39:20 volumio go-librespot[19402]: time="2026-01-29T03:39:20+07:00" level=debug msg="completed keyexchange" Jan 29 03:39:20 volumio go-librespot[19402]: time="2026-01-29T03:39:20+07:00" level=debug msg="completed challenge" Jan 29 03:39:20 volumio go-librespot[19402]: time="2026-01-29T03:39:20+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 29 03:39:20 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 29 03:39:20 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 29 03:39:21 volumio volumio-remote-updater[628]: [2026-01-29 03:39:21] [connect] Successful connection Jan 29 03:39:21 volumio volumio[19309]: info: Loading plugin "outputs"... Jan 29 03:39:21 volumio volumio[19309]: info: Loading plugin "albumart"... Jan 29 03:39:21 volumio volumio[19309]: info: Plugin example_plugin is not enabled Jan 29 03:39:21 volumio volumio[19309]: info: Loading plugin "inputs"... Jan 29 03:39:21 volumio volumio[19309]: info: Loading plugin "updater_comm"... Jan 29 03:39:22 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 29 03:39:22 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 29 03:39:22 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 29 03:39:22 volumio volumio[19309]: info: Plugin mpdemulation is not enabled Jan 29 03:39:22 volumio volumio[19309]: info: Loading plugin "rest_api"... Jan 29 03:39:22 volumio volumio[19309]: info: Loading plugin "websocket"... Jan 29 03:39:22 volumio volumio[19309]: info: Starting Socket.io Server version 1.7.4 Jan 29 03:39:22 volumio volumio[19309]: info: Loading plugin "RoonBridge"... Jan 29 03:39:22 volumio volumio[19309]: info: Applying required configuration parameters for plugin RoonBridge Jan 29 03:39:22 volumio volumio[19309]: info: Loading i18n strings for locale en Jan 29 03:39:22 volumio volumio[19309]: Updating browse sources language Jan 29 03:39:22 volumio volumio[19309]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 29 03:39:22 volumio volumio[19423]: Forking 3 albumart workers Jan 29 03:39:22 volumio volumio[19309]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 29 03:39:22 volumio volumio[19309]: info: CoreCommandRouter::initPlayerControls Jan 29 03:39:22 volumio volumio[19309]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 29 03:39:22 volumio volumio[19309]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 29 03:39:22 volumio volumio[19309]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 29 03:39:22 volumio volumio[19309]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 29 03:39:22 volumio volumio[19309]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 29 03:39:22 volumio volumio[19309]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 29 03:39:22 volumio volumio[19309]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 29 03:39:22 volumio volumio[19309]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 29 03:39:22 volumio volumio[19309]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 29 03:39:22 volumio volumio[19309]: Express server listening on port 3000 Jan 29 03:39:22 volumio volumio[19309]: [Metrics] WebUI: 16s 50.97ms Jan 29 03:39:22 volumio volumio[19309]: info: CoreStateMachine::resetVolumioState Jan 29 03:39:23 volumio volumio[19309]: info: CoreStateMachine::getcurrentVolume Jan 29 03:39:23 volumio volumio[19309]: info: CoreCommandRouter::volumioRetrievevolume Jan 29 03:39:23 volumio sudo[19465]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 29 03:39:23 volumio sudo[19465]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 29 03:39:23 volumio sudo[19465]: pam_unix(sudo:session): session closed for user root Jan 29 03:39:23 volumio sudo[19467]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 29 03:39:23 volumio sudo[19467]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 29 03:39:23 volumio sudo[19467]: pam_unix(sudo:session): session closed for user root Jan 29 03:39:23 volumio volumio[19309]: info: Volumio Network Manager: Network status updated: 1 Jan 29 03:39:23 volumio volumio[19309]: info: VolumeController:: Volume=100 Mute =false Jan 29 03:39:23 volumio volumio[19309]: info: CoreStateMachine::pushState Jan 29 03:39:23 volumio volumio[19309]: info: CorePlayQueue::getTrack 0 Jan 29 03:39:23 volumio volumio[19309]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 29 03:39:23 volumio volumio[19309]: info: CoreCommandRouter::volumioPushState Jan 29 03:39:23 volumio volumio[19309]: info: CoreStateMachine::updateTrackBlock Jan 29 03:39:23 volumio volumio[19309]: info: CorePlayQueue::getTrackBlock Jan 29 03:39:23 volumio volumio[19309]: info: CoreCommandRouter::volumioRetrievevolume Jan 29 03:39:23 volumio volumio-remote-updater[628]: [2026-01-29 03:39:23] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1769632761 101 Jan 29 03:39:23 volumio volumio[19309]: 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 29 03:39:23 volumio volumio[19309]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 29 03:39:23 volumio volumio[19309]: info: Reloading queue from file Jan 29 03:39:23 volumio volumio[19309]: info: CoreStateMachine::setRepeat null single undefined Jan 29 03:39:23 volumio volumio[19309]: info: CoreStateMachine::pushState Jan 29 03:39:23 volumio volumio[19309]: info: CorePlayQueue::getTrack 0 Jan 29 03:39:23 volumio volumio[19309]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 29 03:39:23 volumio volumio[19309]: info: CoreCommandRouter::volumioPushState Jan 29 03:39:23 volumio volumio[19309]: info: CoreStateMachine::setRandom null Jan 29 03:39:23 volumio volumio[19309]: info: CoreStateMachine::pushState Jan 29 03:39:23 volumio volumio[19309]: info: CorePlayQueue::getTrack 0 Jan 29 03:39:23 volumio volumio[19309]: info: CoreCommandRouter::volumioPushState Jan 29 03:39:23 volumio volumio[19309]: info: Setting Device type: Raspberry PI Jan 29 03:39:23 volumio volumio[19309]: info: Completed loading Core Plugins Jan 29 03:39:23 volumio volumio[19309]: info: Preparing to generate the ALSA configuration file Jan 29 03:39:23 volumio volumio[19309]: info: VolumeController:: Volume=100 Mute =false Jan 29 03:39:23 volumio volumio[19309]: info: CoreStateMachine::pushState Jan 29 03:39:23 volumio volumio[19309]: info: CorePlayQueue::getTrack 0 Jan 29 03:39:23 volumio volumio[19309]: info: CoreCommandRouter::volumioPushState Jan 29 03:39:23 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 27. Jan 29 03:39:23 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 29 03:39:24 volumio volumio[19309]: info: Asound.conf file unchanged, so no further update is needed Jan 29 03:39:24 volumio volumio[19309]: info: Output device has changed, restarting MPD Jan 29 03:39:24 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 29 03:39:24 volumio go-librespot[19483]: go-librespot daemon starting... Jan 29 03:39:24 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 29 03:39:24 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 29 03:39:24 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 29 03:39:24 volumio volumio[19309]: info: Output device has changed, restarting Shairport Sync Jan 29 03:39:24 volumio sudo[19485]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Jan 29 03:39:24 volumio volumio[19309]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 29 03:39:24 volumio volumio[19309]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 29 03:39:24 volumio sudo[19485]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 29 03:39:24 volumio sudo[19487]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 29 03:39:24 volumio go-librespot[19488]: time="2026-01-29T03:39:24+07:00" level=info msg="running go-librespot 0.4.0" Jan 29 03:39:24 volumio go-librespot[19488]: time="2026-01-29T03:39:24+07:00" level=debug msg="app state loaded" Jan 29 03:39:24 volumio sudo[19487]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 29 03:39:24 volumio go-librespot[19488]: time="2026-01-29T03:39:24+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 29 03:39:24 volumio sudo[19487]: pam_unix(sudo:session): session closed for user root Jan 29 03:39:24 volumio volumio[19309]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 29 03:39:24 volumio volumio[19309]: info: ___________ START PLUGINS ___________ Jan 29 03:39:24 volumio sudo[19495]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 29 03:39:24 volumio sudo[19495]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 29 03:39:24 volumio volumio[19309]: info: ControllerMpd::onStart: Initializing MPD Jan 29 03:39:24 volumio sudo[19485]: pam_unix(sudo:session): session closed for user root Jan 29 03:39:24 volumio volumio[19309]: info: Creating MPD Configuration file Jan 29 03:39:24 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Jan 29 03:39:24 volumio volumio[19309]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 29 03:39:24 volumio volumio[19309]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 29 03:39:24 volumio volumio[19309]: info: [1769632764487] CoreMusicLibrary::Adding element Media Servers Jan 29 03:39:24 volumio volumio[19309]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 29 03:39:24 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 29 03:39:24 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 29 03:39:24 volumio systemd[1]: mpd.service: Consumed 7.330s CPU time. Jan 29 03:39:24 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 29 03:39:24 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 29 03:39:24 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 29 03:39:24 volumio sudo[19508]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 29 03:39:24 volumio sudo[19506]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 29 03:39:24 volumio sudo[19506]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 29 03:39:24 volumio volumio[19309]: info: UPNP Browser: Client initialized successfully Jan 29 03:39:24 volumio sudo[19508]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 29 03:39:24 volumio sudo[19506]: pam_unix(sudo:session): session closed for user root Jan 29 03:39:24 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 29 03:39:24 volumio volumio[19309]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 29 03:39:24 volumio volumio[19309]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 29 03:39:24 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 29 03:39:24 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 29 03:39:24 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 29 03:39:24 volumio volumio[19309]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 29 03:39:24 volumio volumio[19309]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 29 03:39:24 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 29 03:39:24 volumio volumio[19309]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 29 03:39:24 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 29 03:39:24 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 29 03:39:24 volumio go-librespot[19488]: time="2026-01-29T03:39: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 29 03:39:24 volumio go-librespot[19488]: time="2026-01-29T03:39: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 29 03:39:24 volumio go-librespot[19488]: time="2026-01-29T03:39: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 29 03:39:24 volumio go-librespot[19488]: time="2026-01-29T03:39:24+07:00" level=info msg="zeroconf server listening on port 35339" Jan 29 03:39:24 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 29 03:39:24 volumio volumio[19309]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 29 03:39:24 volumio volumio[19309]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 29 03:39:24 volumio volumio[19309]: info: [1769632764936] CoreMusicLibrary::Adding element Last_100 Jan 29 03:39:24 volumio volumio[19309]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 29 03:39:24 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 29 03:39:24 volumio volumio[19309]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 29 03:39:24 volumio volumio[19309]: info: [1769632764962] CoreMusicLibrary::Adding element Webradio Jan 29 03:39:24 volumio volumio[19309]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 29 03:39:24 volumio volumio[19309]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 29 03:39:25 volumio volumio[19309]: info: Initializing BBC Radios Jan 29 03:39:25 volumio go-librespot[19488]: time="2026-01-29T03:39:25+07:00" level=debug msg="obtained new client token: AADshHVKlZ7XPjdf7B26XB16wuCjx0bB3jpL6ae8UZHfEOwFjlNOfJ/LR8CS5PNrSXUkwqYpSiIVAr4E/jKfMc0YPoR2c7+jjfrTZ4zXCrlJMdBTNKErBo7Gqqh/KulNPeMf5PHg3GiJuhUU7EpBdxv9zOpZb7oixng1Qat59kYr0GEg/3nVcBrDTxdrme853kEk3NhAcPPQAsE5SCJIMDcbnAPe9NPP0bjiOSxLNb3Xb2+Sfo6/nSbb" Jan 29 03:39:25 volumio volumio[19309]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 29 03:39:25 volumio volumio[19309]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 29 03:39:25 volumio volumio[19309]: info: Creating Spotify config file Jan 29 03:39:25 volumio volumio[19309]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 29 03:39:25 volumio go-librespot[19488]: time="2026-01-29T03:39:25+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 29 03:39:25 volumio go-librespot[19488]: time="2026-01-29T03:39:25+07:00" level=debug msg="completed keyexchange" Jan 29 03:39:25 volumio go-librespot[19488]: time="2026-01-29T03:39:25+07:00" level=debug msg="completed challenge" Jan 29 03:39:25 volumio sudo[19522]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 29 03:39:25 volumio sudo[19522]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jan 29 03:39:25 volumio sudo[19522]: pam_unix(sudo:session): session closed for user root Jan 29 03:39:25 volumio go-librespot[19488]: time="2026-01-29T03:39:25+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 29 03:39:25 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 29 03:39:25 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 29 03:39:26 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 29 03:39:26 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 29 03:39:26 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 29 03:39:26 volumio volumio[19309]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 29 03:39:26 volumio volumio[19309]: info: [1769632766347] CoreMusicLibrary::Adding element YouTube Music Jan 29 03:39:26 volumio volumio[19309]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 29 03:39:26 volumio volumio[19309]: Cannot find translation for source YouTube Music Jan 29 03:39:26 volumio volumio[19309]: info: Volumio Calling Home Jan 29 03:39:26 volumio volumio[19435]: Starting albumart workers Jan 29 03:39:26 volumio volumio[19434]: Starting albumart workers Jan 29 03:39:26 volumio sudo[19539]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Jan 29 03:39:26 volumio sudo[19539]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 29 03:39:26 volumio volumio[19433]: Starting albumart workers Jan 29 03:39:26 volumio sudo[19539]: pam_unix(sudo:session): session closed for user root Jan 29 03:39:27 volumio volumio[19309]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Jan 29 03:39:27 volumio volumio[19309]: info: Discovery: Found device Volumio Jan 29 03:39:27 volumio volumio[19309]: info: CoreCommandRouter::volumioGetState Jan 29 03:39:27 volumio volumio[19309]: info: CorePlayQueue::getTrack 0 Jan 29 03:39:27 volumio volumio[19309]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Jan 29 03:39:27 volumio volumio[19309]: info: Discovery: Found device Volumio Jan 29 03:39:27 volumio volumio[19309]: info: CoreCommandRouter::volumioGetState Jan 29 03:39:27 volumio volumio[19309]: info: CorePlayQueue::getTrack 0 Jan 29 03:39:27 volumio volumio[19309]: info: MPD Permissions set Jan 29 03:39:27 volumio volumio[19309]: info: MPD Permissions set Jan 29 03:39:27 volumio volumio[19309]: info: Upmpdcli Daemon Started Jan 29 03:39:27 volumio volumio[19309]: info: Volumio called home Jan 29 03:39:27 volumio volumio[19309]: info: Spotify config file written Jan 29 03:39:27 volumio volumio[19309]: 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 29 03:39:27 volumio volumio[19309]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 29 03:39:27 volumio volumio[19309]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 29 03:39:27 volumio volumio[19309]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 29 03:39:27 volumio volumio[19309]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 29 03:39:27 volumio volumio[19309]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 29 03:39:27 volumio volumio[19309]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 29 03:39:27 volumio volumio[19309]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 29 03:39:27 volumio volumio[19309]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 29 03:39:27 volumio volumio[19309]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 29 03:39:27 volumio sudo[19545]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jan 29 03:39:27 volumio sudo[19545]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 29 03:39:27 volumio volumio[19309]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 29 03:39:27 volumio volumio[19309]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 29 03:39:27 volumio volumio[19309]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 29 03:39:27 volumio volumio[19309]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 29 03:39:27 volumio volumio[19309]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 29 03:39:27 volumio volumio[19309]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 29 03:39:27 volumio volumio[19309]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 29 03:39:27 volumio volumio[19309]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 29 03:39:27 volumio volumio[19309]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 29 03:39:27 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 29 03:39:27 volumio volumio[19309]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 29 03:39:27 volumio volumio[19309]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 29 03:39:27 volumio volumio[19309]: info: No need to fix Spotify hosts Jan 29 03:39:27 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 29 03:39:27 volumio go-librespot[19557]: go-librespot daemon starting... Jan 29 03:39:27 volumio sudo[19545]: pam_unix(sudo:session): session closed for user root Jan 29 03:39:27 volumio go-librespot[19558]: time="2026-01-29T03:39:27+07:00" level=info msg="running go-librespot 0.4.0" Jan 29 03:39:27 volumio go-librespot[19558]: time="2026-01-29T03:39:27+07:00" level=debug msg="app state loaded" Jan 29 03:39:27 volumio go-librespot[19558]: time="2026-01-29T03:39:27+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 29 03:39:28 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 29 03:39:28 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 29 03:39:28 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 29 03:39:28 volumio go-librespot[19558]: time="2026-01-29T03:39:28+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 29 03:39:28 volumio go-librespot[19558]: time="2026-01-29T03:39:28+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 29 03:39:28 volumio go-librespot[19558]: time="2026-01-29T03:39:28+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 29 03:39:28 volumio go-librespot[19558]: time="2026-01-29T03:39:28+07:00" level=info msg="zeroconf server listening on port 43061" Jan 29 03:39:28 volumio go-librespot[19558]: time="2026-01-29T03:39:28+07:00" level=debug msg="obtained new client token: AAD/xo7AeD4kUfcyWKnDDZJLgmlo0nWB5mKXDNl2Z08xf072bFUFLfXbp7EdPp5BdtFNDPb8skzHbN3zZaxjMD+U430DmYGpErFuKgVnuRpR+tqUrnec4+qaUf5//8dqb+Z2YVHFM5IxX1AwEffl5PmdZqCseUp1hwJjVb2tXkQDYs9U8pnoMecR89+AvdVUMjH6VJeEivpAUxBJaGjSv+MBV3iXqGORk/hWwnpeGFVUCoJOWRNZsLFY9Lw=" Jan 29 03:39:28 volumio go-librespot[19558]: time="2026-01-29T03:39:28+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 29 03:39:29 volumio go-librespot[19558]: time="2026-01-29T03:39:29+07:00" level=debug msg="completed keyexchange" Jan 29 03:39:29 volumio go-librespot[19558]: time="2026-01-29T03:39:29+07:00" level=debug msg="completed challenge" Jan 29 03:39:29 volumio go-librespot[19558]: time="2026-01-29T03:39:29+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 29 03:39:29 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 29 03:39:29 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 29 03:39:29 volumio volumio[19309]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 29 03:39:29 volumio volumio[19309]: SPOTIFY: BQA2_BahtpHYZvUfLNPRp-I3pF8qi1qw_5AWrdbRQWAq-7dqOR6Q0cPg1R4uQCREuuHSNZ1ByfkLMNvY8rdTW8GA-LTE4E9ScgXinhscigiywjuGkGfh6Kyz9snaRh_q45dtc7QcQkHlgjHddEb2l19gqq5cGLwuKNa4FoqX_9r2jnGmd_814CwjVHgzlJgOy7ATNwtba3rhvhUrLFkK9TfzqFxqy6joDKAVLsGV2jZ71hf36d9YI9ODzI2TIu6Zi2r_2JcrKrPDWbcDHUqh48Cc3nCwMTDftP3e_O6Znnwe-A9h0OFxjWe_ Jan 29 03:39:29 volumio volumio[19309]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 29 03:39:29 volumio volumio[19309]: info: New Spotify access token = BQA2_BahtpHYZvUfLNPRp-I3pF8qi1qw_5AWrdbRQWAq-7dqOR6Q0cPg1R4uQCREuuHSNZ1ByfkLMNvY8rdTW8GA-LTE4E9ScgXinhscigiywjuGkGfh6Kyz9snaRh_q45dtc7QcQkHlgjHddEb2l19gqq5cGLwuKNa4FoqX_9r2jnGmd_814CwjVHgzlJgOy7ATNwtba3rhvhUrLFkK9TfzqFxqy6joDKAVLsGV2jZ71hf36d9YI9ODzI2TIu6Zi2r_2JcrKrPDWbcDHUqh48Cc3nCwMTDftP3e_O6Znnwe-A9h0OFxjWe_ Jan 29 03:39:29 volumio volumio[19309]: info: Spotify credentials grant success - running version from March 24, 2019 Jan 29 03:39:29 volumio volumio[19309]: info: Starting Shairport Sync Jan 29 03:39:29 volumio volumio[19309]: info: Starting Shairport Sync Jan 29 03:39:29 volumio volumio[19309]: info: Starting Shairport Sync Jan 29 03:39:29 volumio sudo[19586]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 29 03:39:29 volumio sudo[19586]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 29 03:39:29 volumio sudo[19590]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 29 03:39:29 volumio sudo[19590]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 29 03:39:29 volumio sudo[19588]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 29 03:39:29 volumio sudo[19588]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 29 03:39:29 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 29 03:39:29 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Jan 29 03:39:29 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 29 03:39:29 volumio systemd[1]: shairport-sync.service: Consumed 2.290s CPU time. Jan 29 03:39:29 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 29 03:39:29 volumio sudo[19586]: pam_unix(sudo:session): session closed for user root Jan 29 03:39:29 volumio sudo[19590]: pam_unix(sudo:session): session closed for user root Jan 29 03:39:29 volumio sudo[19588]: pam_unix(sudo:session): session closed for user root Jan 29 03:39:29 volumio volumio[19309]: info: CoreCommandRouter::volumioGetState Jan 29 03:39:29 volumio volumio[19309]: info: CorePlayQueue::getTrack 0 Jan 29 03:39:29 volumio volumio[19309]: info: Shairport-Sync Started Jan 29 03:39:29 volumio volumio[19309]: Error adding Membership: Error: addMembership EINVAL Jan 29 03:39:29 volumio volumio[19309]: info: Shairport-Sync Started Jan 29 03:39:29 volumio volumio[19309]: info: Shairport-Sync Started Jan 29 03:39:30 volumio volumio[19309]: 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 29 03:39:30 volumio volumio[19309]: info: Spotify Successfully logged in Jan 29 03:39:30 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 29 03:39:30 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 29 03:39:30 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 29 03:39:30 volumio volumio[19309]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 29 03:39:30 volumio volumio[19309]: info: [1769632770071] CoreMusicLibrary::Adding element Spotify Jan 29 03:39:30 volumio volumio[19309]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 29 03:39:30 volumio volumio[19309]: Cannot find translation for source YouTube Music Jan 29 03:39:30 volumio volumio[19309]: Cannot find translation for source Spotify Jan 29 03:39:30 volumio volumio[19309]: info: [yt-cast-receiver] DIAL server listening on port 8098 Jan 29 03:39:30 volumio volumio[19309]: info: CoreCommandRouter::volumioRetrievevolume Jan 29 03:39:31 volumio volumio[19309]: info: VolumeController:: Volume=100 Mute =false Jan 29 03:39:31 volumio volumio[19309]: info: CoreCommandRouter::volumioGetState Jan 29 03:39:31 volumio volumio[19309]: info: CorePlayQueue::getTrack 0 Jan 29 03:39:31 volumio volumio[19309]: info: CoreStateMachine::pushState Jan 29 03:39:31 volumio volumio[19309]: info: CorePlayQueue::getTrack 0 Jan 29 03:39:31 volumio volumio[19309]: info: CoreCommandRouter::volumioPushState Jan 29 03:39:32 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 29 03:39:32 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 29 03:39:32 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 29 03:39:32 volumio volumio[19309]: info: go-librespot daemon successfully initialized Jan 29 03:39:32 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 28. Jan 29 03:39:32 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 29 03:39:32 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 29 03:39:32 volumio go-librespot[19625]: go-librespot daemon starting... Jan 29 03:39:32 volumio go-librespot[19626]: time="2026-01-29T03:39:32+07:00" level=info msg="running go-librespot 0.4.0" Jan 29 03:39:32 volumio go-librespot[19626]: time="2026-01-29T03:39:32+07:00" level=debug msg="app state loaded" Jan 29 03:39:32 volumio go-librespot[19626]: time="2026-01-29T03:39:32+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 29 03:39:32 volumio mpd[19537]: 2026-01-29T03:39:32 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 29 03:39:32 volumio systemd[1]: Started mpd.service - Music Player Daemon. Jan 29 03:39:32 volumio sudo[19495]: pam_unix(sudo:session): session closed for user root Jan 29 03:39:32 volumio sudo[19508]: pam_unix(sudo:session): session closed for user root Jan 29 03:39:32 volumio go-librespot[19626]: time="2026-01-29T03:39:32+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 29 03:39:32 volumio go-librespot[19626]: time="2026-01-29T03:39:32+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 29 03:39:32 volumio go-librespot[19626]: time="2026-01-29T03:39:32+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 29 03:39:32 volumio volumio[19309]: error: MPD error: The expression evaluated to a falsy value: Jan 29 03:39:32 volumio volumio[19309]: assert.ok(self.idling) Jan 29 03:39:32 volumio go-librespot[19626]: time="2026-01-29T03:39:32+07:00" level=info msg="zeroconf server listening on port 32853" Jan 29 03:39:32 volumio volumio[19309]: error: The expression evaluated to a falsy value: Jan 29 03:39:32 volumio volumio[19309]: assert.ok(self.idling) Jan 29 03:39:32 volumio volumio[19309]: info: MPD running with PID19537 Jan 29 03:39:32 volumio volumio[19309]: ,establishing connection Jan 29 03:39:32 volumio volumio[19309]: error: updateQueue error: null Jan 29 03:39:33 volumio volumio[19309]: info: Completed starting Core Plugins Jan 29 03:39:33 volumio volumio[19309]: info: ------------------------------------------- Jan 29 03:39:33 volumio volumio[19309]: info: ----- MyVolumio plugins startup ---- Jan 29 03:39:33 volumio volumio[19309]: info: ------------------------------------------- Jan 29 03:39:33 volumio volumio[19309]: info: [MyVolumio PluginManager] Fetching plans data.... Jan 29 03:39:33 volumio volumio[19309]: error: updateQueue error: null Jan 29 03:39:33 volumio go-librespot[19626]: time="2026-01-29T03:39:33+07:00" level=debug msg="obtained new client token: AACGdRrpGxCDAIs1/6qO98zk9p6UR2iiKOssYmLL3LHrPm3+sFin2P92w44q42NQZG2DTDHFh7Ty7AmUuhpZDaWWruPV8qlSvRCjQplhwrMGEIHTJaOPNm7l8AngHxB6JprZDxLXQr7gMjik3Hie/Tfpn18cD1EypJfOYxc7g0w4Zy43bKn6QGBOi69XGSdmQfOz8iTMXQVY1c1occsOGU4/z5Zs/Oq1TVbikpCOQH3QoFbVj2gor23B" Jan 29 03:39:33 volumio go-librespot[19626]: time="2026-01-29T03:39:33+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 29 03:39:33 volumio go-librespot[19626]: time="2026-01-29T03:39:33+07:00" level=debug msg="completed keyexchange" Jan 29 03:39:33 volumio go-librespot[19626]: time="2026-01-29T03:39:33+07:00" level=debug msg="completed challenge" Jan 29 03:39:33 volumio go-librespot[19626]: time="2026-01-29T03:39:33+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 29 03:39:33 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 29 03:39:33 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 29 03:39:34 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 29 03:39:34 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 29 03:39:34 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 29 03:39:35 volumio volumio[19309]: info: Initializing connection to go-librespot Websocket Jan 29 03:39:35 volumio volumio[19309]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 29 03:39:36 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 29 03:39:36 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 29 03:39:36 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 29 03:39:36 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 29. Jan 29 03:39:36 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 29 03:39:36 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 29 03:39:36 volumio go-librespot[19639]: go-librespot daemon starting... Jan 29 03:39:36 volumio go-librespot[19640]: time="2026-01-29T03:39:36+07:00" level=info msg="running go-librespot 0.4.0" Jan 29 03:39:36 volumio go-librespot[19640]: time="2026-01-29T03:39:36+07:00" level=debug msg="app state loaded" Jan 29 03:39:36 volumio go-librespot[19640]: time="2026-01-29T03:39:36+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 29 03:39:37 volumio go-librespot[19640]: time="2026-01-29T03:39:37+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 29 03:39:37 volumio go-librespot[19640]: time="2026-01-29T03:39:37+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 29 03:39:37 volumio go-librespot[19640]: time="2026-01-29T03:39:37+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 29 03:39:37 volumio go-librespot[19640]: time="2026-01-29T03:39:37+07:00" level=info msg="zeroconf server listening on port 40195" Jan 29 03:39:37 volumio go-librespot[19640]: time="2026-01-29T03:39:37+07:00" level=debug msg="obtained new client token: AADBbgsGjGtfadoo+1PG4AtMZ+GUli544CkKukU79iHpplEeJJyXvEy9N236Uukx5nyUr4laFwCdE6BPylb3Qc2J/qP4UH8S1vtuyl4D2sz43VIezxrG11/GJ2h4nqrR35JAoiKK10VDAZF/k6ZfNiksny0hUydCG4w/fvwJ0qZKcp0Te8Ue2sEnyJ1ZCnV6+V3NeyWulrVxUadeMg2ws5E3gNFCLOduzkDCkIUXNuROae373elZJXYxlAc=" Jan 29 03:39:37 volumio go-librespot[19640]: time="2026-01-29T03:39:37+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 29 03:39:37 volumio volumio[19309]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Jan 29 03:39:37 volumio go-librespot[19640]: time="2026-01-29T03:39:37+07:00" level=debug msg="completed keyexchange" Jan 29 03:39:37 volumio go-librespot[19640]: time="2026-01-29T03:39:37+07:00" level=debug msg="completed challenge" Jan 29 03:39:37 volumio go-librespot[19640]: time="2026-01-29T03:39:37+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 29 03:39:37 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 29 03:39:37 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 29 03:39:38 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 29 03:39:38 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 29 03:39:38 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 29 03:39:38 volumio volumio[19309]: info: Initializing connection to go-librespot Websocket Jan 29 03:39:38 volumio volumio[19309]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 29 03:39:40 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 29 03:39:40 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 29 03:39:40 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 29 03:39:40 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 30. Jan 29 03:39:40 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 29 03:39:41 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 29 03:39:41 volumio go-librespot[19650]: go-librespot daemon starting... Jan 29 03:39:41 volumio go-librespot[19651]: time="2026-01-29T03:39:41+07:00" level=info msg="running go-librespot 0.4.0" Jan 29 03:39:41 volumio go-librespot[19651]: time="2026-01-29T03:39:41+07:00" level=debug msg="app state loaded" Jan 29 03:39:41 volumio go-librespot[19651]: time="2026-01-29T03:39:41+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 29 03:39:41 volumio volumio[19309]: info: Initializing connection to go-librespot Websocket Jan 29 03:39:41 volumio go-librespot[19651]: time="2026-01-29T03:39:41+07:00" level=debug msg="new websocket client" Jan 29 03:39:41 volumio volumio[19309]: info: Connection to go-librespot Websocket established Jan 29 03:39:41 volumio go-librespot[19651]: time="2026-01-29T03:39:41+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 29 03:39:41 volumio go-librespot[19651]: time="2026-01-29T03:39:41+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 29 03:39:41 volumio go-librespot[19651]: time="2026-01-29T03:39:41+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 29 03:39:41 volumio go-librespot[19651]: time="2026-01-29T03:39:41+07:00" level=info msg="zeroconf server listening on port 43583" Jan 29 03:39:41 volumio go-librespot[19651]: time="2026-01-29T03:39:41+07:00" level=debug msg="obtained new client token: AABOSHyo6GJs0LC/sUp0ihoSzFiVKv59jKCvIudmW8+lZQ/eyiUCtCyIGTk/+RCfuoIh/QLumg3td4ncAVBXOqzOV3bwm6dlKU8UWGN6G+ExDhkaIC02HFmklXSLFa4Pb/6KNfMb+k2+oj1hSTDPC8lzesTP+L5xd34lkh4h69ZxlEjHzq35cHqWEZzt07DGMDNZQHIgYgzB9ngP3yV0WCAFRIuE0SL8aCTSKbFQ8ikW+2i6qOaUy4UseX8=" Jan 29 03:39:41 volumio volumio[19309]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Jan 29 03:39:41 volumio volumio[19309]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Jan 29 03:39:41 volumio volumio[19309]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Jan 29 03:39:41 volumio volumio[19309]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Jan 29 03:39:41 volumio volumio[19309]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Jan 29 03:39:41 volumio volumio[19309]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Jan 29 03:39:41 volumio volumio[19309]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Jan 29 03:39:41 volumio volumio[19309]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Jan 29 03:39:41 volumio volumio[19309]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Jan 29 03:39:41 volumio volumio[19309]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Jan 29 03:39:41 volumio volumio[19309]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Jan 29 03:39:41 volumio volumio[19309]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Jan 29 03:39:41 volumio volumio[19309]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Jan 29 03:39:41 volumio volumio[19309]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Jan 29 03:39:41 volumio volumio[19309]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Jan 29 03:39:41 volumio volumio[19309]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Jan 29 03:39:41 volumio volumio[19309]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Jan 29 03:39:41 volumio volumio[19309]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Jan 29 03:39:41 volumio volumio[19309]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Jan 29 03:39:41 volumio volumio[19309]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Jan 29 03:39:41 volumio volumio[19309]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Jan 29 03:39:41 volumio volumio[19309]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Jan 29 03:39:41 volumio volumio[19309]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Jan 29 03:39:41 volumio volumio[19309]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Jan 29 03:39:41 volumio volumio[19309]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Jan 29 03:39:41 volumio volumio[19309]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Jan 29 03:39:41 volumio volumio[19309]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Jan 29 03:39:41 volumio volumio[19309]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Jan 29 03:39:41 volumio volumio[19309]: info: Adding plugin bluetooth to MyMusic Plugins Jan 29 03:39:41 volumio volumio[19309]: info: Adding plugin multiroom to MyMusic Plugins Jan 29 03:39:41 volumio volumio[19309]: info: Adding plugin metavolumio to MyMusic Plugins Jan 29 03:39:41 volumio volumio[19309]: info: Adding plugin cd_controller to MyMusic Plugins Jan 29 03:39:41 volumio volumio[19309]: info: Adding plugin qobuzconnect to MyMusic Plugins Jan 29 03:39:41 volumio volumio[19309]: info: Adding plugin smart_inputs to MyMusic Plugins Jan 29 03:39:41 volumio volumio[19309]: info: Adding plugin tidalconnect to MyMusic Plugins Jan 29 03:39:41 volumio volumio[19309]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Jan 29 03:39:41 volumio go-librespot[19651]: time="2026-01-29T03:39:41+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 29 03:39:41 volumio go-librespot[19651]: time="2026-01-29T03:39:41+07:00" level=debug msg="completed keyexchange" Jan 29 03:39:41 volumio go-librespot[19651]: time="2026-01-29T03:39:41+07:00" level=debug msg="completed challenge" Jan 29 03:39:42 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 29 03:39:42 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 29 03:39:42 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 29 03:39:42 volumio go-librespot[19651]: time="2026-01-29T03:39:42+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 29 03:39:42 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 29 03:39:42 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 29 03:39:43 volumio volumio[19309]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Jan 29 03:39:43 volumio volumio[19309]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Jan 29 03:39:43 volumio volumio[19309]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 29 03:39:43 volumio volumio[19309]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 29 03:39:43 volumio volumio[19309]: info: Starting MyVolumio Remote Streaming Endpoints Jan 29 03:39:43 volumio volumio[19309]: info: MyVolumio login type: Token Jan 29 03:39:43 volumio volumio[19309]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Jan 29 03:39:43 volumio volumio[19309]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Jan 29 03:39:44 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 29 03:39:44 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 29 03:39:44 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 29 03:39:45 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 31. Jan 29 03:39:45 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 29 03:39:45 volumio volumio[19309]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Jan 29 03:39:45 volumio volumio[19309]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Jan 29 03:39:45 volumio volumio[19309]: info: Streaming services startup Jan 29 03:39:45 volumio volumio[19309]: info: Starting Streaming Daemon Jan 29 03:39:45 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 29 03:39:45 volumio go-librespot[19672]: go-librespot daemon starting... Jan 29 03:39:45 volumio volumio[19309]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Jan 29 03:39:45 volumio sudo[19675]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jan 29 03:39:45 volumio sudo[19675]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 29 03:39:45 volumio go-librespot[19679]: time="2026-01-29T03:39:45+07:00" level=info msg="running go-librespot 0.4.0" Jan 29 03:39:45 volumio go-librespot[19679]: time="2026-01-29T03:39:45+07:00" level=debug msg="app state loaded" Jan 29 03:39:45 volumio go-librespot[19679]: time="2026-01-29T03:39:45+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 29 03:39:45 volumio sudo[19675]: pam_unix(sudo:session): session closed for user root Jan 29 03:39:45 volumio volumio[19309]: info: Getting Spotify volume Jan 29 03:39:45 volumio volumio[19309]: info: Connection to go-librespot Websocket closed Jan 29 03:39:45 volumio volumio[19309]: error: Cannot start Volumio Streaming Daemon Jan 29 03:39:45 volumio volumio[19309]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Jan 29 03:39:45 volumio volumio[19309]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Jan 29 03:39:45 volumio volumio[19309]: 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 29 03:39:45 volumio volumio[19309]: info: CoreCommandRouter::volumioGetState Jan 29 03:39:45 volumio volumio[19309]: info: CorePlayQueue::getTrack 0 Jan 29 03:39:45 volumio volumio[19309]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jan 29 03:39:45 volumio volumio[19309]: SPOTIFY: SPOTIFY VOLUME undefined Jan 29 03:39:45 volumio volumio[19309]: SPOTIFY: VOLUMIO VOLUME 100 Jan 29 03:39:45 volumio volumio[19309]: info: Aligning Spotify Volume to Volumio Volume Jan 29 03:39:45 volumio volumio[19309]: info: CoreCommandRouter::volumioGetState Jan 29 03:39:45 volumio volumio[19309]: info: CorePlayQueue::getTrack 0 Jan 29 03:39:45 volumio volumio[19309]: info: Setting Spotify Volume from Volumio: 100 Jan 29 03:39:45 volumio go-librespot[19679]: time="2026-01-29T03:39:45+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 29 03:39:45 volumio go-librespot[19679]: time="2026-01-29T03:39:45+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 29 03:39:45 volumio go-librespot[19679]: time="2026-01-29T03:39:45+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 29 03:39:45 volumio go-librespot[19679]: time="2026-01-29T03:39:45+07:00" level=info msg="zeroconf server listening on port 44003" Jan 29 03:39:46 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 29 03:39:46 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 29 03:39:46 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 29 03:39:46 volumio go-librespot[19679]: time="2026-01-29T03:39:46+07:00" level=debug msg="obtained new client token: AAAj8cy1t5mX79C/n9CWC4aYJZ9ISqpXaifLmqeNGkDzTmqHQSQ6Lf7d7zgSlRHk9lJ9Uy5tY+wmBpVPMy8Qto62OQx7w1DULzng3ynY7OKM+MC7Wa27HHU39byJLyBqQRoL0Pd0Nck7P1NuE7pdfBtxvr7MXiaS1yzE1m23ryLeFfDcALig4D6uthj89eAqV0ufTaU2rjgt4sAV92mZ4/z1CZNtQm8A7zmJhp8b7XvdbYGN5o5y0i/x" Jan 29 03:39:46 volumio go-librespot[19679]: time="2026-01-29T03:39:46+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 29 03:39:46 volumio go-librespot[19679]: time="2026-01-29T03:39:46+07:00" level=debug msg="completed keyexchange" Jan 29 03:39:46 volumio go-librespot[19679]: time="2026-01-29T03:39:46+07:00" level=debug msg="completed challenge" Jan 29 03:39:46 volumio go-librespot[19679]: time="2026-01-29T03:39:46+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 29 03:39:46 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 29 03:39:46 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 29 03:39:46 volumio volumio[19309]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 29 03:39:46 volumio volumio[19309]: Error: socket hang up Jan 29 03:39:46 volumio volumio[19309]: at connResetException (node:internal/errors:720:14) Jan 29 03:39:46 volumio volumio[19309]: at Socket.socketOnEnd (node:_http_client:519:23) Jan 29 03:39:46 volumio volumio[19309]: at Socket.emit (node:events:526:35) Jan 29 03:39:46 volumio volumio[19309]: at endReadableNT (node:internal/streams/readable:1376:12) Jan 29 03:39:46 volumio volumio[19309]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Jan 29 03:39:46 volumio volumio[19309]: code: 'ECONNRESET', Jan 29 03:39:46 volumio volumio[19309]: response: undefined Jan 29 03:39:46 volumio volumio[19309]: } Jan 29 03:39:46 volumio volumio[19309]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 29 03:39:47 volumio sudo[19704]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-01-29 03:38' Jan 29 03:39:47 volumio sudo[19704]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 29 03:39:48 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 29 03:39:48 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 29 03:39:48 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 PRETTY_NAME="Raspbian GNU/Linux 12 (bookworm)" NAME="Raspbian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="b05a530ca81d05eb9a84d0acf82089f0a60b8ee6" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="4ad85e2147d972f0b838d33c21382d2d813b2ae8" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu Dec 25 09:13:19 UTC 2025" VOLUMIO_VERSION="4.084" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="792f09af7488531aecd1aadcaa9b175e"