Jan 28 11:45:00 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 15. Jan 28 11:45:00 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 11:45:01 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 11:45:01 volumio go-librespot[14950]: go-librespot daemon starting... Jan 28 11:45:01 volumio go-librespot[14951]: time="2026-01-28T11:45:01+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 11:45:01 volumio go-librespot[14951]: time="2026-01-28T11:45:01+07:00" level=debug msg="app state loaded" Jan 28 11:45:01 volumio go-librespot[14951]: time="2026-01-28T11:45:01+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 11:45:01 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 11:45:01 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 11:45:01 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 11:45:01 volumio volumio[14859]: info: Loading plugin "ytmusic"... Jan 28 11:45:01 volumio go-librespot[14951]: time="2026-01-28T11:45:01+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 11:45:01 volumio go-librespot[14951]: time="2026-01-28T11:45:01+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 28 11:45:01 volumio go-librespot[14951]: time="2026-01-28T11:45:01+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 28 11:45:01 volumio go-librespot[14951]: time="2026-01-28T11:45:01+07:00" level=info msg="zeroconf server listening on port 38417" Jan 28 11:45:01 volumio go-librespot[14951]: time="2026-01-28T11:45:01+07:00" level=debug msg="obtained new client token: AADh8cmDwuTNQGqFL1EtMzwxtpYP/a5tf+ECApYwtDOw080+/cc8bRMhapBW2D0E06IkfpuI/SXEn6CCw1eVxVhnmqwNXYpd45xMUMTzjTfI642fwSpMmSLDqj3XokcMYoht2H3u+zvnzst6c4kra9VU+PNFeO4mpk9nQvqgGMiKQrg9hVamsUr4vOPpmvMxT2KVXOYI+Ft2eghGZt3bnvTOeNqpRiCXp901TeQGDM7I5nmCVfqAiOpvlic=" Jan 28 11:45:02 volumio go-librespot[14951]: time="2026-01-28T11:45:02+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 11:45:02 volumio go-librespot[14951]: time="2026-01-28T11:45:02+07:00" level=debug msg="completed keyexchange" Jan 28 11:45:02 volumio go-librespot[14951]: time="2026-01-28T11:45:02+07:00" level=debug msg="completed challenge" Jan 28 11:45:02 volumio go-librespot[14951]: time="2026-01-28T11:45:02+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 11:45:02 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 11:45:02 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 11:45:02 volumio volumio-remote-updater[628]: [2026-01-28 11:45:02] [connect] Successful connection Jan 28 11:45:02 volumio volumio[14859]: info: Loading plugin "outputs"... Jan 28 11:45:02 volumio volumio[14859]: info: Loading plugin "albumart"... Jan 28 11:45:02 volumio volumio[14859]: info: Plugin example_plugin is not enabled Jan 28 11:45:02 volumio volumio[14859]: info: Loading plugin "inputs"... Jan 28 11:45:02 volumio volumio[14859]: info: Loading plugin "updater_comm"... Jan 28 11:45:02 volumio volumio[14859]: info: Plugin mpdemulation is not enabled Jan 28 11:45:02 volumio volumio[14859]: info: Loading plugin "rest_api"... Jan 28 11:45:02 volumio volumio[14859]: info: Loading plugin "websocket"... Jan 28 11:45:02 volumio volumio[14859]: info: Starting Socket.io Server version 1.7.4 Jan 28 11:45:02 volumio volumio[14859]: info: Loading plugin "RoonBridge"... Jan 28 11:45:03 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 11:45:03 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 11:45:03 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 11:45:03 volumio volumio[14859]: info: Applying required configuration parameters for plugin RoonBridge Jan 28 11:45:03 volumio volumio[14859]: info: Loading i18n strings for locale en Jan 28 11:45:03 volumio volumio[14859]: Updating browse sources language Jan 28 11:45:03 volumio volumio[14859]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 11:45:03 volumio volumio[14859]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 28 11:45:03 volumio volumio[14859]: info: CoreCommandRouter::initPlayerControls Jan 28 11:45:03 volumio volumio[14859]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:45:03 volumio volumio[14859]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:45:03 volumio volumio[14859]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:45:03 volumio volumio[14859]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:45:03 volumio volumio[14859]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:45:03 volumio volumio[14859]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:45:03 volumio volumio[14859]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:45:03 volumio volumio[14859]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:45:03 volumio volumio[14972]: Forking 3 albumart workers Jan 28 11:45:03 volumio volumio[14859]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 28 11:45:03 volumio volumio[14859]: Express server listening on port 3000 Jan 28 11:45:03 volumio volumio[14859]: [Metrics] WebUI: 16s 75.49ms Jan 28 11:45:03 volumio volumio[14859]: info: CoreStateMachine::resetVolumioState Jan 28 11:45:03 volumio volumio[14859]: info: CoreStateMachine::getcurrentVolume Jan 28 11:45:03 volumio volumio[14859]: info: CoreCommandRouter::volumioRetrievevolume Jan 28 11:45:04 volumio sudo[15006]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 28 11:45:04 volumio sudo[15006]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:45:04 volumio sudo[15006]: pam_unix(sudo:session): session closed for user root Jan 28 11:45:04 volumio sudo[15011]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 28 11:45:04 volumio sudo[15011]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:45:04 volumio sudo[15011]: pam_unix(sudo:session): session closed for user root Jan 28 11:45:04 volumio volumio[14859]: info: Volumio Network Manager: Network status updated: 1 Jan 28 11:45:04 volumio volumio-remote-updater[628]: [2026-01-28 11:45:04] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1769575502 101 Jan 28 11:45:04 volumio volumio[14859]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 1 Jan 28 11:45:04 volumio volumio[14859]: info: VolumeController:: Volume=100 Mute =false Jan 28 11:45:04 volumio volumio[14859]: info: CoreStateMachine::pushState Jan 28 11:45:04 volumio volumio[14859]: info: CorePlayQueue::getTrack 0 Jan 28 11:45:04 volumio volumio[14859]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 28 11:45:04 volumio volumio[14859]: info: CoreCommandRouter::volumioPushState Jan 28 11:45:04 volumio volumio[14859]: info: CoreStateMachine::updateTrackBlock Jan 28 11:45:04 volumio volumio[14859]: info: CorePlayQueue::getTrackBlock Jan 28 11:45:04 volumio volumio[14859]: info: CoreCommandRouter::volumioRetrievevolume Jan 28 11:45:04 volumio volumio[14859]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 11:45:04 volumio volumio[14859]: info: Reloading queue from file Jan 28 11:45:04 volumio volumio[14859]: info: CoreStateMachine::setRepeat null single undefined Jan 28 11:45:04 volumio volumio[14859]: info: CoreStateMachine::pushState Jan 28 11:45:04 volumio volumio[14859]: info: CorePlayQueue::getTrack 0 Jan 28 11:45:04 volumio volumio[14859]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 28 11:45:04 volumio volumio[14859]: info: CoreCommandRouter::volumioPushState Jan 28 11:45:04 volumio volumio[14859]: info: CoreStateMachine::setRandom null Jan 28 11:45:04 volumio volumio[14859]: info: CoreStateMachine::pushState Jan 28 11:45:04 volumio volumio[14859]: info: CorePlayQueue::getTrack 0 Jan 28 11:45:04 volumio volumio[14859]: info: CoreCommandRouter::volumioPushState Jan 28 11:45:04 volumio volumio[14859]: info: Setting Device type: Raspberry PI Jan 28 11:45:04 volumio volumio[14859]: info: Completed loading Core Plugins Jan 28 11:45:04 volumio volumio[14859]: info: Preparing to generate the ALSA configuration file Jan 28 11:45:04 volumio volumio[14859]: info: VolumeController:: Volume=100 Mute =false Jan 28 11:45:04 volumio volumio[14859]: info: CoreStateMachine::pushState Jan 28 11:45:04 volumio volumio[14859]: info: CorePlayQueue::getTrack 0 Jan 28 11:45:04 volumio volumio[14859]: info: CoreCommandRouter::volumioPushState Jan 28 11:45:04 volumio volumio[14859]: info: Asound.conf file unchanged, so no further update is needed Jan 28 11:45:04 volumio volumio[14859]: info: Output device has changed, restarting MPD Jan 28 11:45:04 volumio volumio[14859]: info: Output device has changed, restarting Shairport Sync Jan 28 11:45:04 volumio volumio[14859]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:45:04 volumio volumio[14859]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 11:45:04 volumio sudo[15033]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Jan 28 11:45:04 volumio sudo[15033]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:45:04 volumio volumio[14859]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 28 11:45:04 volumio volumio[14859]: info: ___________ START PLUGINS ___________ Jan 28 11:45:05 volumio sudo[15035]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 28 11:45:05 volumio sudo[15035]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:45:05 volumio volumio[14859]: info: ControllerMpd::onStart: Initializing MPD Jan 28 11:45:05 volumio volumio[14859]: info: Creating MPD Configuration file Jan 28 11:45:05 volumio sudo[15037]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 28 11:45:05 volumio sudo[15037]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:45:05 volumio sudo[15035]: pam_unix(sudo:session): session closed for user root Jan 28 11:45:05 volumio volumio[14859]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 28 11:45:05 volumio sudo[15033]: pam_unix(sudo:session): session closed for user root Jan 28 11:45:05 volumio volumio[14859]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 11:45:05 volumio volumio[14859]: info: [1769575505104] CoreMusicLibrary::Adding element Media Servers Jan 28 11:45:05 volumio volumio[14859]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 11:45:05 volumio volumio[14859]: info: UPNP Browser: Client initialized successfully Jan 28 11:45:05 volumio sudo[15047]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 28 11:45:05 volumio sudo[15048]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 28 11:45:05 volumio sudo[15047]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:45:05 volumio sudo[15047]: pam_unix(sudo:session): session closed for user root Jan 28 11:45:05 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Jan 28 11:45:05 volumio sudo[15048]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:45:05 volumio volumio[14859]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:45:05 volumio volumio[14859]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 11:45:05 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 11:45:05 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 11:45:05 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 11:45:05 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 16. Jan 28 11:45:05 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 11:45:05 volumio volumio[14859]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 28 11:45:05 volumio volumio[14859]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:45:05 volumio volumio[14859]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 11:45:05 volumio go-librespot[15056]: go-librespot daemon starting... Jan 28 11:45:05 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 11:45:05 volumio volumio[14859]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 28 11:45:05 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 28 11:45:05 volumio volumio[14859]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 11:45:05 volumio volumio[14859]: info: [1769575505437] CoreMusicLibrary::Adding element Last_100 Jan 28 11:45:05 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 28 11:45:05 volumio volumio[14859]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 11:45:05 volumio systemd[1]: mpd.service: Consumed 7.445s CPU time. Jan 28 11:45:05 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 28 11:45:05 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 28 11:45:05 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 28 11:45:05 volumio volumio[14859]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 11:45:05 volumio volumio[14859]: info: [1769575505467] CoreMusicLibrary::Adding element Webradio Jan 28 11:45:05 volumio volumio[14859]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 11:45:05 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 28 11:45:05 volumio go-librespot[15060]: time="2026-01-28T11:45:05+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 11:45:05 volumio go-librespot[15060]: time="2026-01-28T11:45:05+07:00" level=debug msg="app state loaded" Jan 28 11:45:05 volumio go-librespot[15060]: time="2026-01-28T11:45:05+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 11:45:05 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 28 11:45:05 volumio volumio[14859]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 28 11:45:05 volumio volumio[14859]: info: Initializing BBC Radios Jan 28 11:45:05 volumio volumio[14859]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 28 11:45:05 volumio volumio[14859]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 11:45:05 volumio volumio[14859]: info: Creating Spotify config file Jan 28 11:45:05 volumio volumio[14859]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:45:06 volumio sudo[15067]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 28 11:45:06 volumio sudo[15067]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jan 28 11:45:06 volumio sudo[15067]: pam_unix(sudo:session): session closed for user root Jan 28 11:45:06 volumio go-librespot[15060]: time="2026-01-28T11:45:06+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 11:45:06 volumio go-librespot[15060]: time="2026-01-28T11:45:06+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 28 11:45:06 volumio go-librespot[15060]: time="2026-01-28T11:45:06+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 28 11:45:06 volumio go-librespot[15060]: time="2026-01-28T11:45:06+07:00" level=info msg="zeroconf server listening on port 35683" Jan 28 11:45:06 volumio go-librespot[15060]: time="2026-01-28T11:45:06+07:00" level=debug msg="obtained new client token: AACcvJjLU8llYP4ZxPQjvhUTk5b6mxRkAwiVe6R5kyUYL6QB2fZRHBbP3M0X212cf3wz5NeGwXH2dpYdde1VDfpDtR1QMZjJ7l1LNTT4nEi3rJ+8iecRY6AjzJwRKpmjoVwsWe9OBjBSIz4ZPWiGRKs5s/IJdwCZPTjvNln4gSVYvp8JvNVG5HH33HjjvGlbEVyGa2HD50te4/D80cxNlzDgIrdXMJfKFNBPBzlWPoO4WfK4HMUPhhRTdC0=" Jan 28 11:45:06 volumio go-librespot[15060]: time="2026-01-28T11:45:06+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 11:45:06 volumio go-librespot[15060]: time="2026-01-28T11:45:06+07:00" level=debug msg="completed keyexchange" Jan 28 11:45:06 volumio go-librespot[15060]: time="2026-01-28T11:45:06+07:00" level=debug msg="completed challenge" Jan 28 11:45:06 volumio go-librespot[15060]: time="2026-01-28T11:45:06+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 11:45:06 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 11:45:06 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 11:45:07 volumio volumio[14859]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 11:45:07 volumio volumio[14859]: info: [1769575507303] CoreMusicLibrary::Adding element YouTube Music Jan 28 11:45:07 volumio volumio[14859]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 11:45:07 volumio volumio[14859]: Cannot find translation for source YouTube Music Jan 28 11:45:07 volumio volumio[14982]: Starting albumart workers Jan 28 11:45:07 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 11:45:07 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 11:45:07 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 11:45:07 volumio volumio[14859]: info: Volumio Calling Home Jan 28 11:45:07 volumio volumio[14986]: Starting albumart workers Jan 28 11:45:07 volumio sudo[15086]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Jan 28 11:45:07 volumio sudo[15086]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:45:07 volumio sudo[15086]: pam_unix(sudo:session): session closed for user root Jan 28 11:45:07 volumio volumio[14987]: Starting albumart workers Jan 28 11:45:08 volumio volumio[14859]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Jan 28 11:45:08 volumio volumio[14859]: info: Discovery: Found device Volumio Jan 28 11:45:08 volumio volumio[14859]: info: CoreCommandRouter::volumioGetState Jan 28 11:45:08 volumio volumio[14859]: info: CorePlayQueue::getTrack 0 Jan 28 11:45:08 volumio volumio[14859]: info: MPD Permissions set Jan 28 11:45:08 volumio volumio[14859]: info: MPD Permissions set Jan 28 11:45:08 volumio volumio[14859]: info: Upmpdcli Daemon Started Jan 28 11:45:08 volumio volumio[14859]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Jan 28 11:45:08 volumio volumio[14859]: info: Discovery: Found device Volumio Jan 28 11:45:08 volumio volumio[14859]: info: CoreCommandRouter::volumioGetState Jan 28 11:45:08 volumio volumio[14859]: info: CorePlayQueue::getTrack 0 Jan 28 11:45:08 volumio volumio[14859]: info: Spotify config file written Jan 28 11:45:08 volumio sudo[15092]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jan 28 11:45:08 volumio sudo[15092]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:45:08 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 11:45:08 volumio volumio[14859]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Jan 28 11:45:08 volumio volumio[14859]: info: Volumio called home Jan 28 11:45:08 volumio volumio[14859]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:45:08 volumio volumio[14859]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:45:08 volumio volumio[14859]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:45:08 volumio volumio[14859]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:45:08 volumio volumio[14859]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:45:08 volumio volumio[14859]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:45:08 volumio volumio[14859]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:45:08 volumio volumio[14859]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:45:08 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 11:45:08 volumio go-librespot[15094]: go-librespot daemon starting... Jan 28 11:45:09 volumio sudo[15092]: pam_unix(sudo:session): session closed for user root Jan 28 11:45:09 volumio go-librespot[15097]: time="2026-01-28T11:45:09+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 11:45:09 volumio go-librespot[15097]: time="2026-01-28T11:45:09+07:00" level=debug msg="app state loaded" Jan 28 11:45:09 volumio volumio[14859]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 11:45:09 volumio volumio[14859]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:45:09 volumio volumio[14859]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:45:09 volumio go-librespot[15097]: time="2026-01-28T11:45:09+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 11:45:09 volumio volumio[14859]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:45:09 volumio volumio[14859]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:45:09 volumio volumio[14859]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:45:09 volumio volumio[14859]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:45:09 volumio volumio[14859]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:45:09 volumio volumio[14859]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:45:09 volumio volumio[14859]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:45:09 volumio volumio[14859]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 11:45:09 volumio volumio[14859]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:45:09 volumio volumio[14859]: info: No need to fix Spotify hosts Jan 28 11:45:09 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 11:45:09 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 11:45:09 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 11:45:09 volumio go-librespot[15097]: time="2026-01-28T11:45:09+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 28 11:45:09 volumio go-librespot[15097]: time="2026-01-28T11:45:09+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Jan 28 11:45:09 volumio go-librespot[15097]: time="2026-01-28T11:45:09+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Jan 28 11:45:09 volumio go-librespot[15097]: time="2026-01-28T11:45:09+07:00" level=info msg="zeroconf server listening on port 45445" Jan 28 11:45:09 volumio go-librespot[15097]: time="2026-01-28T11:45:09+07:00" level=debug msg="obtained new client token: AAB3OlLtJXc4EpoI05WOISG4XcB5ZHz0yBW4t5ZPRR6v1Q/CNpLfnWemkkvkZDq4TPzvZiYdAXNBDS1VG36pQDHxOqwvpbh0TU+7KMJ7ZXKFHcDo+o7Lf4f7L6GyD8FLIGmlKndc1WtxYCqvMeER9JuHcCex+ZU8GAXlI6l/8PXABEsCXB2Tva4LhxULmpOj4APUZfymXAndA6cod0C9QainI4V/KZM4BHWPe6YdVoGxtBAn+n7uHNJcLgw=" Jan 28 11:45:10 volumio go-librespot[15097]: time="2026-01-28T11:45:10+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 11:45:10 volumio volumio[14859]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 28 11:45:10 volumio volumio[14859]: SPOTIFY: BQD_DNol-7IVsIvqlgxWool2yRot_OvstZkF5wENeFXGOvyKhIOVP00BfQApPJGtft5cpO9tN4SD0Bo7prV7vJN0snPfuM2p82GtcXY4KMi4mKPeTiFbDem5KJqrv7Bgs1MlL5_ULDcvc2vZKXLdlT-I_X-q3kcgz0urxctMhgmLnY-oTptyqQCJcHSMS26_T4dmCoy-vcGn96YQ0fKWZpAhtvBH8PzN1ss6x_HTprL30oWTbNTQiDTnZxmedzUqCQmbb3ggWJ3GsM-qkK1XoVKp6A6YchFyHbRB868Dt_C6vIgb8usMicjH Jan 28 11:45:10 volumio volumio[14859]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 28 11:45:10 volumio volumio[14859]: info: New Spotify access token = BQD_DNol-7IVsIvqlgxWool2yRot_OvstZkF5wENeFXGOvyKhIOVP00BfQApPJGtft5cpO9tN4SD0Bo7prV7vJN0snPfuM2p82GtcXY4KMi4mKPeTiFbDem5KJqrv7Bgs1MlL5_ULDcvc2vZKXLdlT-I_X-q3kcgz0urxctMhgmLnY-oTptyqQCJcHSMS26_T4dmCoy-vcGn96YQ0fKWZpAhtvBH8PzN1ss6x_HTprL30oWTbNTQiDTnZxmedzUqCQmbb3ggWJ3GsM-qkK1XoVKp6A6YchFyHbRB868Dt_C6vIgb8usMicjH Jan 28 11:45:10 volumio volumio[14859]: info: Spotify credentials grant success - running version from March 24, 2019 Jan 28 11:45:10 volumio go-librespot[15097]: time="2026-01-28T11:45:10+07:00" level=debug msg="completed keyexchange" Jan 28 11:45:10 volumio go-librespot[15097]: time="2026-01-28T11:45:10+07:00" level=debug msg="completed challenge" Jan 28 11:45:10 volumio volumio[14859]: info: Starting Shairport Sync Jan 28 11:45:10 volumio volumio[14859]: info: Starting Shairport Sync Jan 28 11:45:10 volumio go-librespot[15097]: time="2026-01-28T11:45:10+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 11:45:10 volumio volumio[14859]: info: Starting Shairport Sync Jan 28 11:45:10 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 11:45:10 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 11:45:10 volumio sudo[15132]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 28 11:45:10 volumio sudo[15132]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:45:10 volumio sudo[15136]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 28 11:45:10 volumio sudo[15136]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:45:10 volumio sudo[15134]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 28 11:45:10 volumio sudo[15134]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:45:10 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 28 11:45:10 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Jan 28 11:45:10 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 28 11:45:10 volumio systemd[1]: shairport-sync.service: Consumed 2.316s CPU time. Jan 28 11:45:10 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 28 11:45:10 volumio sudo[15136]: pam_unix(sudo:session): session closed for user root Jan 28 11:45:10 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 28 11:45:10 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Jan 28 11:45:10 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 28 11:45:10 volumio volumio[14859]: info: Shairport-Sync Started Jan 28 11:45:10 volumio volumio[14859]: Error adding Membership: Error: addMembership EINVAL Jan 28 11:45:10 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 28 11:45:10 volumio sudo[15134]: pam_unix(sudo:session): session closed for user root Jan 28 11:45:10 volumio sudo[15132]: pam_unix(sudo:session): session closed for user root Jan 28 11:45:10 volumio volumio[14859]: info: CoreCommandRouter::volumioGetState Jan 28 11:45:10 volumio volumio[14859]: info: CorePlayQueue::getTrack 0 Jan 28 11:45:10 volumio volumio[14859]: info: Shairport-Sync Started Jan 28 11:45:11 volumio volumio[14859]: info: Shairport-Sync Started Jan 28 11:45:11 volumio volumio[14859]: SPOTIFY: User informations: {"country":"PK","display_name":"215mmgea6kss3jxeqsqdquvji","email":"linh.ngotran@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/215mmgea6kss3jxeqsqdquvji"},"followers":{"href":null,"total":1},"href":"https://api.spotify.com/v1/users/215mmgea6kss3jxeqsqdquvji","id":"215mmgea6kss3jxeqsqdquvji","images":[],"product":"premium","type":"user","uri":"spotify:user:215mmgea6kss3jxeqsqdquvji"} Jan 28 11:45:11 volumio volumio[14859]: info: Spotify Successfully logged in Jan 28 11:45:11 volumio volumio[14859]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 11:45:11 volumio volumio[14859]: info: [1769575511158] CoreMusicLibrary::Adding element Spotify Jan 28 11:45:11 volumio volumio[14859]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 11:45:11 volumio volumio[14859]: Cannot find translation for source YouTube Music Jan 28 11:45:11 volumio volumio[14859]: Cannot find translation for source Spotify Jan 28 11:45:11 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 11:45:11 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 11:45:11 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 11:45:11 volumio volumio[14859]: info: [yt-cast-receiver] DIAL server listening on port 8098 Jan 28 11:45:11 volumio volumio[14859]: info: CoreCommandRouter::volumioRetrievevolume Jan 28 11:45:12 volumio volumio[14859]: info: VolumeController:: Volume=100 Mute =false Jan 28 11:45:12 volumio volumio[14859]: info: CoreCommandRouter::volumioGetState Jan 28 11:45:12 volumio volumio[14859]: info: CorePlayQueue::getTrack 0 Jan 28 11:45:12 volumio volumio[14859]: info: CoreStateMachine::pushState Jan 28 11:45:12 volumio volumio[14859]: info: CorePlayQueue::getTrack 0 Jan 28 11:45:12 volumio volumio[14859]: info: CoreCommandRouter::volumioPushState Jan 28 11:45:13 volumio volumio[14859]: info: go-librespot daemon successfully initialized Jan 28 11:45:13 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 11:45:13 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 11:45:13 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 11:45:13 volumio mpd[15083]: 2026-01-28T11:45:13 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 28 11:45:13 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 17. Jan 28 11:45:13 volumio systemd[1]: Started mpd.service - Music Player Daemon. Jan 28 11:45:13 volumio sudo[15048]: pam_unix(sudo:session): session closed for user root Jan 28 11:45:13 volumio sudo[15037]: pam_unix(sudo:session): session closed for user root Jan 28 11:45:13 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 11:45:13 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 11:45:13 volumio go-librespot[15188]: go-librespot daemon starting... Jan 28 11:45:13 volumio go-librespot[15191]: time="2026-01-28T11:45:13+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 11:45:13 volumio go-librespot[15191]: time="2026-01-28T11:45:13+07:00" level=debug msg="app state loaded" Jan 28 11:45:13 volumio go-librespot[15191]: time="2026-01-28T11:45:13+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 11:45:13 volumio volumio[14859]: error: MPD error: The expression evaluated to a falsy value: Jan 28 11:45:13 volumio volumio[14859]: assert.ok(self.idling) Jan 28 11:45:13 volumio volumio[14859]: error: The expression evaluated to a falsy value: Jan 28 11:45:13 volumio volumio[14859]: assert.ok(self.idling) Jan 28 11:45:13 volumio volumio[14859]: error: updateQueue error: null Jan 28 11:45:13 volumio volumio[14859]: info: MPD running with PID15083 Jan 28 11:45:13 volumio volumio[14859]: ,establishing connection Jan 28 11:45:13 volumio volumio[14859]: info: Completed starting Core Plugins Jan 28 11:45:13 volumio volumio[14859]: info: ------------------------------------------- Jan 28 11:45:13 volumio volumio[14859]: info: ----- MyVolumio plugins startup ---- Jan 28 11:45:13 volumio volumio[14859]: info: ------------------------------------------- Jan 28 11:45:13 volumio volumio[14859]: info: [MyVolumio PluginManager] Fetching plans data.... Jan 28 11:45:13 volumio volumio[14859]: error: updateQueue error: null Jan 28 11:45:14 volumio go-librespot[15191]: time="2026-01-28T11:45:14+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 11:45:14 volumio go-librespot[15191]: time="2026-01-28T11:45:14+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 28 11:45:14 volumio go-librespot[15191]: time="2026-01-28T11:45:14+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 28 11:45:14 volumio go-librespot[15191]: time="2026-01-28T11:45:14+07:00" level=info msg="zeroconf server listening on port 34621" Jan 28 11:45:14 volumio go-librespot[15191]: time="2026-01-28T11:45:14+07:00" level=debug msg="obtained new client token: AADdD4DlHYbyZ4OEwNBPaNBtCINpo6OMzwhN1M7C1nQpa0ALN6a6g5Oq4YUzPkPilamLyvkPAhujFqn76zGZ2JQ8Imlld89gtku+p21SfFzXDv1CIDgwiC7z7BuF/PohQmKS+M+qHfhtzzg9WEtjq3FKnnU4a7n6nwCal8QvZXuLShiD5iiK8ySuPlBwEpsSJX4LRWE22VZg7VQK/2ra6mWKOkpgRA96/TK1N+atSre2M3RlEBf/IfWnVgM=" Jan 28 11:45:14 volumio go-librespot[15191]: time="2026-01-28T11:45:14+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 11:45:14 volumio go-librespot[15191]: time="2026-01-28T11:45:14+07:00" level=debug msg="completed keyexchange" Jan 28 11:45:14 volumio go-librespot[15191]: time="2026-01-28T11:45:14+07:00" level=debug msg="completed challenge" Jan 28 11:45:14 volumio go-librespot[15191]: time="2026-01-28T11:45:14+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 11:45:14 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 11:45:14 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 11:45:15 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 11:45:15 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 11:45:15 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 11:45:16 volumio volumio[14859]: info: Initializing connection to go-librespot Websocket Jan 28 11:45:16 volumio volumio[14859]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 28 11:45:17 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 11:45:17 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 11:45:17 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 11:45:17 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 18. Jan 28 11:45:17 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 11:45:18 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 11:45:18 volumio go-librespot[15200]: go-librespot daemon starting... Jan 28 11:45:18 volumio go-librespot[15201]: time="2026-01-28T11:45:18+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 11:45:18 volumio go-librespot[15201]: time="2026-01-28T11:45:18+07:00" level=debug msg="app state loaded" Jan 28 11:45:18 volumio go-librespot[15201]: time="2026-01-28T11:45:18+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 11:45:18 volumio volumio[14859]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Jan 28 11:45:18 volumio go-librespot[15201]: time="2026-01-28T11:45:18+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 28 11:45:18 volumio go-librespot[15201]: time="2026-01-28T11:45:18+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Jan 28 11:45:18 volumio go-librespot[15201]: time="2026-01-28T11:45:18+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Jan 28 11:45:18 volumio go-librespot[15201]: time="2026-01-28T11:45:18+07:00" level=info msg="zeroconf server listening on port 40113" Jan 28 11:45:18 volumio go-librespot[15201]: time="2026-01-28T11:45:18+07:00" level=debug msg="obtained new client token: AADweU+z/Qw6mjiG3qm96K29PL1AYWlNOy5F58HKYlxLO56q9RK6o2J6KgmrnsUKlMvNJ0F9AS03TYSeXpBRzd0RqovTi7d8fs7h492mRqG2W5CmXIYLbbZcrklhoD+tGzdCmS1wSvhdkxODNQTFogRTdY7zNtccTBRYR8J0qqdDb8oW4UHYLFv/tbXY57xYb7pksg02yopLaCxEb9BUY2HOc8izcqaDRNXaeWuuMtxe9OF/ws5n/toy/FQ=" Jan 28 11:45:19 volumio go-librespot[15201]: time="2026-01-28T11:45:19+07:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:4070, retrying with a different AP" error="dial tcp 104.199.241.202:4070: connect: connection refused" Jan 28 11:45:19 volumio go-librespot[15201]: time="2026-01-28T11:45:19+07:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:443, retrying with a different AP" error="dial tcp 104.199.241.202:443: connect: connection refused" Jan 28 11:45:19 volumio go-librespot[15201]: time="2026-01-28T11:45:19+07:00" level=debug msg="connected to ap-gae2.spotify.com:80" Jan 28 11:45:19 volumio volumio[14859]: info: Initializing connection to go-librespot Websocket Jan 28 11:45:19 volumio go-librespot[15201]: time="2026-01-28T11:45:19+07:00" level=debug msg="new websocket client" Jan 28 11:45:19 volumio volumio[14859]: info: Connection to go-librespot Websocket established Jan 28 11:45:19 volumio go-librespot[15201]: time="2026-01-28T11:45:19+07:00" level=debug msg="completed keyexchange" Jan 28 11:45:19 volumio go-librespot[15201]: time="2026-01-28T11:45:19+07:00" level=debug msg="completed challenge" Jan 28 11:45:19 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 11:45:19 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 11:45:19 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 11:45:19 volumio go-librespot[15201]: time="2026-01-28T11:45:19+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 11:45:19 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 11:45:19 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 11:45:19 volumio volumio[14859]: info: Connection to go-librespot Websocket closed Jan 28 11:45:21 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 11:45:21 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 11:45:21 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 11:45:22 volumio volumio[14859]: info: Getting Spotify volume Jan 28 11:45:22 volumio volumio[14859]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 28 11:45:22 volumio volumio[14859]: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 28 11:45:22 volumio volumio[14859]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Jan 28 11:45:22 volumio volumio[14859]: errno: -111, Jan 28 11:45:22 volumio volumio[14859]: code: 'ECONNREFUSED', Jan 28 11:45:22 volumio volumio[14859]: syscall: 'connect', Jan 28 11:45:22 volumio volumio[14859]: address: '127.0.0.1', Jan 28 11:45:22 volumio volumio[14859]: port: 9879, Jan 28 11:45:22 volumio volumio[14859]: response: undefined Jan 28 11:45:22 volumio volumio[14859]: } Jan 28 11:45:22 volumio volumio[14859]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 28 11:45:22 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 19. Jan 28 11:45:22 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 11:45:22 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 11:45:22 volumio go-librespot[15219]: go-librespot daemon starting... Jan 28 11:45:22 volumio go-librespot[15221]: time="2026-01-28T11:45:22+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 11:45:22 volumio go-librespot[15221]: time="2026-01-28T11:45:22+07:00" level=debug msg="app state loaded" Jan 28 11:45:22 volumio go-librespot[15221]: time="2026-01-28T11:45:22+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 11:45:23 volumio go-librespot[15221]: time="2026-01-28T11:45: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 28 11:45:23 volumio go-librespot[15221]: time="2026-01-28T11:45: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 28 11:45:23 volumio go-librespot[15221]: time="2026-01-28T11:45: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 28 11:45:23 volumio go-librespot[15221]: time="2026-01-28T11:45:23+07:00" level=info msg="zeroconf server listening on port 33533" Jan 28 11:45:23 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 11:45:23 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 11:45:23 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 11:45:23 volumio go-librespot[15221]: time="2026-01-28T11:45:23+07:00" level=debug msg="obtained new client token: AACM52JjR5F6uK8wpe57lE6Z4WDKfg+U1LgP/y4NYAeFXtwSqePrwtX87+DMtzRAGTEVioM22J4TshGearQNB/e6RP0U8nUoAz4PJlfMK3YDKeC4QnjLrycfy0ikE6bjHlJsbGCMkZJPVmkpvT5LMQjiUbi3yfePOZVCqlLkNCKR5yGwg/krmz2O7qJLZXLzde7sKOH95lbriYYI93GgCqG3mR33moma6tcR3tta42lquIetK+ODH3sB1Xg=" Jan 28 11:45:23 volumio go-librespot[15221]: time="2026-01-28T11:45:23+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 11:45:23 volumio go-librespot[15221]: time="2026-01-28T11:45:23+07:00" level=debug msg="completed keyexchange" Jan 28 11:45:23 volumio go-librespot[15221]: time="2026-01-28T11:45:23+07:00" level=debug msg="completed challenge" Jan 28 11:45:23 volumio go-librespot[15221]: time="2026-01-28T11:45:23+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 11:45:23 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 11:45:23 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 11:45:23 volumio sudo[15246]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-01-28 11:44' Jan 28 11:45:23 volumio sudo[15246]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:45:24 volumio sudo[15246]: pam_unix(sudo:session): session closed for user root Jan 28 11:45:24 volumio volumio-remote-updater[628]: [2026-01-28 11:45:24] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Jan 28 11:45:24 volumio volumio-remote-updater[628]: [2026-01-28 11:45:24] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Jan 28 11:45:24 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Jan 28 11:45:24 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Jan 28 11:45:24 volumio systemd[1]: volumio.service: Consumed 53.024s CPU time. Jan 28 11:45:24 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 28 11:45:24 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Jan 28 11:45:24 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 10064. Jan 28 11:45:24 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 28 11:45:24 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Jan 28 11:45:24 volumio systemd[1]: volumio.service: Consumed 53.024s CPU time. Jan 28 11:45:24 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Jan 28 11:45:24 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Jan 28 11:45:25 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 11:45:25 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 11:45:25 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 11:45:26 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 20. Jan 28 11:45:26 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 11:45:26 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 11:45:26 volumio go-librespot[15273]: go-librespot daemon starting... Jan 28 11:45:26 volumio go-librespot[15274]: time="2026-01-28T11:45:26+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 11:45:26 volumio go-librespot[15274]: time="2026-01-28T11:45:26+07:00" level=debug msg="app state loaded" Jan 28 11:45:26 volumio go-librespot[15274]: time="2026-01-28T11:45:26+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 11:45:27 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 11:45:27 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 11:45:27 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 11:45:27 volumio go-librespot[15274]: time="2026-01-28T11:45: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-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 11:45:27 volumio go-librespot[15274]: time="2026-01-28T11:45:27+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 28 11:45:27 volumio go-librespot[15274]: time="2026-01-28T11:45:27+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 28 11:45:27 volumio go-librespot[15274]: time="2026-01-28T11:45:27+07:00" level=info msg="zeroconf server listening on port 46043" Jan 28 11:45:27 volumio go-librespot[15274]: time="2026-01-28T11:45:27+07:00" level=debug msg="obtained new client token: AABvPxfNTDxNX6LXL71rTCD2HfeVcMYtc5e0TJhWmR+YdaLpNA+KNktYirDfnzaQ9beqU0WtzR+Cw53IhzriIrqkcg2s4HTK1s0O7yOwPQuYAKEJfRduKLVGpo/5fqrJ0uhartFYLUwud2HZOnO7OXUpVFlIK6EsDxrlOTX+4gfJBNf7A/CJaUxeyd8qHnP/wgBwE/+sd7s5vJ1ra7illjJfJ9WxUlxEnC3cDlu9SiasD3tO25ObAYfUXDs=" Jan 28 11:45:27 volumio go-librespot[15274]: time="2026-01-28T11:45:27+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 11:45:27 volumio go-librespot[15274]: time="2026-01-28T11:45:27+07:00" level=debug msg="completed keyexchange" Jan 28 11:45:27 volumio go-librespot[15274]: time="2026-01-28T11:45:27+07:00" level=debug msg="completed challenge" Jan 28 11:45:27 volumio go-librespot[15274]: time="2026-01-28T11:45:27+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 11:45:27 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 11:45:27 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 11:45:28 volumio volumio[15258]: info: ------------------------------------------- Jan 28 11:45:28 volumio volumio[15258]: info: ----- Volumio3 ---- Jan 28 11:45:28 volumio volumio[15258]: info: ------------------------------------------- Jan 28 11:45:28 volumio volumio[15258]: info: ----- System startup ---- Jan 28 11:45:28 volumio volumio[15258]: info: ------------------------------------------- Jan 28 11:45:29 volumio volumio-remote-updater[628]: [2026-01-28 11:45:29] [connect] Successful connection Jan 28 11:45:29 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 11:45:29 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 11:45:29 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 11:45:29 volumio volumio[15258]: info: MYVOLUMIO Environment detected Jan 28 11:45:29 volumio volumio[15258]: info: Plugin folders cleanup Jan 28 11:45:29 volumio volumio[15258]: info: Scanning into folder /volumio/app/plugins/ Jan 28 11:45:29 volumio volumio[15258]: info: Scanning category audio_interface Jan 28 11:45:29 volumio volumio[15258]: info: Scanning category miscellanea Jan 28 11:45:29 volumio volumio[15258]: info: Scanning category music_service Jan 28 11:45:29 volumio volumio[15258]: info: Scanning category plugins.json Jan 28 11:45:29 volumio volumio[15258]: info: Scanning category system_controller Jan 28 11:45:29 volumio volumio[15258]: info: Scanning category user_interface Jan 28 11:45:29 volumio volumio[15258]: info: Scanning into folder /data/plugins/ Jan 28 11:45:29 volumio volumio[15258]: info: Scanning category music_service Jan 28 11:45:29 volumio volumio[15258]: info: Plugin folders cleanup completed Jan 28 11:45:29 volumio volumio[15258]: info: ------------------------------------------- Jan 28 11:45:29 volumio volumio[15258]: info: ----- Core plugins startup ---- Jan 28 11:45:29 volumio volumio[15258]: info: ------------------------------------------- Jan 28 11:45:29 volumio volumio[15258]: info: Loading plugins from folder /volumio/app/plugins/ Jan 28 11:45:29 volumio volumio[15258]: info: Adding plugin upnp to MyMusic Plugins Jan 28 11:45:29 volumio volumio[15258]: info: Adding plugin airplay_emulation to MyMusic Plugins Jan 28 11:45:29 volumio volumio[15258]: info: Adding plugin upnp_browser to MyMusic Plugins Jan 28 11:45:29 volumio volumio[15258]: info: Loading plugins from folder /data/plugins/ Jan 28 11:45:29 volumio volumio[15258]: info: Loading plugin "system"... Jan 28 11:45:29 volumio volumio[15258]: info: Loading plugin "appearance"... Jan 28 11:45:30 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 21. Jan 28 11:45:30 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 11:45:31 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 11:45:31 volumio go-librespot[15294]: go-librespot daemon starting... Jan 28 11:45:31 volumio go-librespot[15295]: time="2026-01-28T11:45:31+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 11:45:31 volumio go-librespot[15295]: time="2026-01-28T11:45:31+07:00" level=debug msg="app state loaded" Jan 28 11:45:31 volumio go-librespot[15295]: time="2026-01-28T11:45:31+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 11:45:31 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 11:45:31 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 11:45:31 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 11:45:31 volumio go-librespot[15295]: time="2026-01-28T11:45:31+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 28 11:45:31 volumio go-librespot[15295]: time="2026-01-28T11:45:31+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Jan 28 11:45:31 volumio go-librespot[15295]: time="2026-01-28T11:45:31+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Jan 28 11:45:31 volumio go-librespot[15295]: time="2026-01-28T11:45:31+07:00" level=info msg="zeroconf server listening on port 39937" Jan 28 11:45:31 volumio volumio[15258]: info: Loading plugin "network"... Jan 28 11:45:31 volumio volumio[15258]: info: Refreshing Cached IP Addresses Jan 28 11:45:31 volumio sudo[15303]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 28 11:45:31 volumio sudo[15303]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:45:31 volumio sudo[15305]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 28 11:45:31 volumio sudo[15305]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:45:31 volumio sudo[15303]: pam_unix(sudo:session): session closed for user root Jan 28 11:45:31 volumio sudo[15305]: pam_unix(sudo:session): session closed for user root Jan 28 11:45:31 volumio volumio[15258]: info: Loading plugin "services"... Jan 28 11:45:31 volumio volumio[15258]: info: Loading plugin "alsa_controller"... Jan 28 11:45:31 volumio sudo[15314]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Jan 28 11:45:31 volumio sudo[15314]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:45:31 volumio go-librespot[15295]: time="2026-01-28T11:45:31+07:00" level=debug msg="obtained new client token: AADSR+oNN+XvsdwX1HVT9vfgz0JRstVqncOwBnOgXmjsPg22VDzMTi/mOafNtnnA7c4zpqiCZVHaVgUmKq8lpAMepTN3hC4o8gib/q/d386kI0SDulZqZuGAT/eB5vT+sNjnQomnx/nygjWtB9Ok1R3wNvRr70pX8DLlP3WMSk0gCKS7/2xAJk3Jy3PZFmLa5tlpbhp3FZuoCY/y/u6tIgyXadkBZ/B7Gb3aHd4y6Az/Lx8iC3ewcze2VjI=" Jan 28 11:45:32 volumio volumio[15258]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 28 11:45:32 volumio volumio[15258]: info: Loading plugin "wizard"... Jan 28 11:45:32 volumio volumio[15258]: info: Loading plugin "networkfs"... Jan 28 11:45:32 volumio go-librespot[15295]: time="2026-01-28T11:45:32+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 11:45:32 volumio volumio[15258]: info: Starting Udev Watcher for removable devices Jan 28 11:45:32 volumio go-librespot[15295]: time="2026-01-28T11:45:32+07:00" level=debug msg="completed keyexchange" Jan 28 11:45:32 volumio go-librespot[15295]: time="2026-01-28T11:45:32+07:00" level=debug msg="completed challenge" Jan 28 11:45:32 volumio volumio[15258]: info: Ignoring mount for partition: boot Jan 28 11:45:32 volumio volumio[15258]: info: Ignoring mount for partition: volumio Jan 28 11:45:32 volumio volumio[15258]: info: Ignoring mount for partition: volumio_data Jan 28 11:45:32 volumio volumio[15258]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 28 11:45:32 volumio volumio[15258]: info: Loading plugin "volumio_command_line_client"... Jan 28 11:45:32 volumio volumio[15258]: info: Loading plugin "upnp"... Jan 28 11:45:32 volumio volumio[15258]: info: [1769575532185] Starting Upmpd Daemon Jan 28 11:45:32 volumio volumio[15258]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 28 11:45:32 volumio volumio[15258]: info: Loading plugin "my_music"... Jan 28 11:45:32 volumio volumio[15258]: info: Loading plugin "mpd"... Jan 28 11:45:32 volumio go-librespot[15295]: time="2026-01-28T11:45:32+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 11:45:32 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 11:45:32 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 11:45:32 volumio volumio[15258]: info: Loading plugin "upnp_browser"... Jan 28 11:45:33 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 11:45:33 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 11:45:33 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 11:45:34 volumio sudo[15314]: pam_unix(sudo:session): session closed for user root Jan 28 11:45:35 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 22. Jan 28 11:45:35 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 11:45:35 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 11:45:35 volumio go-librespot[15337]: go-librespot daemon starting... Jan 28 11:45:35 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 11:45:35 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 11:45:35 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 11:45:35 volumio go-librespot[15338]: time="2026-01-28T11:45:35+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 11:45:35 volumio go-librespot[15338]: time="2026-01-28T11:45:35+07:00" level=debug msg="app state loaded" Jan 28 11:45:35 volumio go-librespot[15338]: time="2026-01-28T11:45:35+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 11:45:35 volumio volumio[15258]: info: Starting UPNP Browser Jan 28 11:45:35 volumio volumio[15258]: info: Loading plugin "alarm-clock"... Jan 28 11:45:35 volumio go-librespot[15338]: time="2026-01-28T11:45:35+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 11:45:35 volumio go-librespot[15338]: time="2026-01-28T11:45:35+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 28 11:45:35 volumio go-librespot[15338]: time="2026-01-28T11:45:35+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 28 11:45:35 volumio go-librespot[15338]: time="2026-01-28T11:45:35+07:00" level=info msg="zeroconf server listening on port 38587" Jan 28 11:45:36 volumio volumio[15258]: info: Loading plugin "airplay_emulation"... Jan 28 11:45:36 volumio volumio[15258]: info: Starting Shairport Sync Jan 28 11:45:36 volumio volumio[15258]: info: Loading plugin "last_100"... Jan 28 11:45:36 volumio volumio[15258]: info: Loading plugin "webradio"... Jan 28 11:45:36 volumio go-librespot[15338]: time="2026-01-28T11:45:36+07:00" level=debug msg="obtained new client token: AAAyEJzS4UKvZe8F845YdOnxwNAzqonZ9xUSlbF+bP3xhTNW3OGEtqfPinffinQOMpwmSeBdtKfB+Is9YW+63ZnroRHVh52cowFQVCCwuk3M+hv6LUOiUvoUcSqwv9IifA7bNuCBpb3YXoL5HvdeRinCK799gjNzUSVoeAI3+cXA6NeBXZk2Xebz96xdbJDdfNJ43R92IO3QrLIWGzb0sPPV1OBdQFwZrVKG4GDetmSQXEbKSOiQsiH2" Jan 28 11:45:36 volumio go-librespot[15338]: time="2026-01-28T11:45:36+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 11:45:36 volumio volumio[15258]: info: Loading plugin "i2s_dacs"... Jan 28 11:45:36 volumio volumio[15258]: info: Loading plugin "volumiodiscovery"... Jan 28 11:45:36 volumio go-librespot[15338]: time="2026-01-28T11:45:36+07:00" level=debug msg="completed keyexchange" Jan 28 11:45:36 volumio go-librespot[15338]: time="2026-01-28T11:45:36+07:00" level=debug msg="completed challenge" Jan 28 11:45:36 volumio volumio[15258]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 28 11:45:36 volumio volumio[15258]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 11:45:36 volumio volumio[15258]: *** WARNING *** For more information see Jan 28 11:45:36 volumio volumio[15258]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 28 11:45:36 volumio volumio[15258]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 11:45:36 volumio volumio[15258]: *** WARNING *** For more information see Jan 28 11:45:36 volumio node[15258]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 28 11:45:36 volumio node[15258]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 11:45:36 volumio node[15258]: *** WARNING *** For more information see Jan 28 11:45:36 volumio node[15258]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 28 11:45:36 volumio node[15258]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 11:45:36 volumio node[15258]: *** WARNING *** For more information see Jan 28 11:45:36 volumio volumio[15258]: info: Applying required configuration parameters for plugin volumiodiscovery Jan 28 11:45:36 volumio volumio[15258]: info: Discovery: Started advertising with name: Volumio Jan 28 11:45:36 volumio go-librespot[15338]: time="2026-01-28T11:45:36+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 11:45:36 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 11:45:36 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 11:45:36 volumio volumio[15258]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 28 11:45:36 volumio volumio[15258]: info: Loading plugin "spop"... Jan 28 11:45:37 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 11:45:37 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 11:45:37 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 11:45:38 volumio volumio[15258]: info: Loading plugin "ytcr"... Jan 28 11:45:39 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 11:45:39 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 11:45:39 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 11:45:39 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 23. Jan 28 11:45:39 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 11:45:39 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 11:45:39 volumio go-librespot[15348]: go-librespot daemon starting... Jan 28 11:45:39 volumio go-librespot[15349]: time="2026-01-28T11:45:39+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 11:45:39 volumio go-librespot[15349]: time="2026-01-28T11:45:39+07:00" level=debug msg="app state loaded" Jan 28 11:45:39 volumio go-librespot[15349]: time="2026-01-28T11:45:39+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 11:45:40 volumio go-librespot[15349]: time="2026-01-28T11:45:40+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 28 11:45:40 volumio go-librespot[15349]: time="2026-01-28T11:45:40+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Jan 28 11:45:40 volumio go-librespot[15349]: time="2026-01-28T11:45:40+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Jan 28 11:45:40 volumio go-librespot[15349]: time="2026-01-28T11:45:40+07:00" level=info msg="zeroconf server listening on port 35251" Jan 28 11:45:40 volumio go-librespot[15349]: time="2026-01-28T11:45:40+07:00" level=debug msg="obtained new client token: AAA5glkImrUGkLy9BGB5SoCdeq6KcivGl/eCOBLbRE5Gy4andhzeb3v8jAG44lhW0Z+Ko6YNti2D5TBjlcf3atPQ6uJcDEuOljaq6tblA8VdH3yKeShP272zWCN5451iz6orTjUk6ILPy9UxsmyQAg95ACb051Xj7lM5TbRxTYBRVKjB5+5Sq7Bpl5NSg9cKLq1lFaDCjw3tVTBgaPEr0kXP96GaOEY1jcYepvN+HonxEUc/gH5YXqna/eo=" Jan 28 11:45:40 volumio go-librespot[15349]: time="2026-01-28T11:45:40+07:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:4070, retrying with a different AP" error="dial tcp 104.199.241.202:4070: connect: connection refused" Jan 28 11:45:40 volumio go-librespot[15349]: time="2026-01-28T11:45:40+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Jan 28 11:45:40 volumio go-librespot[15349]: time="2026-01-28T11:45:40+07:00" level=debug msg="completed keyexchange" Jan 28 11:45:40 volumio go-librespot[15349]: time="2026-01-28T11:45:40+07:00" level=debug msg="completed challenge" Jan 28 11:45:41 volumio go-librespot[15349]: time="2026-01-28T11:45: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 28 11:45:41 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 11:45:41 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 11:45:41 volumio volumio[15258]: info: Loading plugin "ytmusic"... Jan 28 11:45:41 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 11:45:41 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 11:45:41 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 11:45:41 volumio volumio-remote-updater[628]: [2026-01-28 11:45:41] [connect] Successful connection Jan 28 11:45:42 volumio volumio[15258]: info: Loading plugin "outputs"... Jan 28 11:45:42 volumio volumio[15258]: info: Loading plugin "albumart"... Jan 28 11:45:42 volumio volumio[15258]: info: Plugin example_plugin is not enabled Jan 28 11:45:42 volumio volumio[15258]: info: Loading plugin "inputs"... Jan 28 11:45:42 volumio volumio[15258]: info: Loading plugin "updater_comm"... Jan 28 11:45:42 volumio volumio[15258]: info: Plugin mpdemulation is not enabled Jan 28 11:45:42 volumio volumio[15258]: info: Loading plugin "rest_api"... Jan 28 11:45:42 volumio volumio[15258]: info: Loading plugin "websocket"... Jan 28 11:45:42 volumio volumio[15258]: info: Starting Socket.io Server version 1.7.4 Jan 28 11:45:42 volumio volumio[15258]: info: Loading plugin "RoonBridge"... Jan 28 11:45:42 volumio volumio[15258]: info: Applying required configuration parameters for plugin RoonBridge Jan 28 11:45:42 volumio volumio[15258]: info: Loading i18n strings for locale en Jan 28 11:45:42 volumio volumio[15258]: Updating browse sources language Jan 28 11:45:42 volumio volumio[15258]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 11:45:43 volumio volumio[15258]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 28 11:45:43 volumio volumio[15258]: info: CoreCommandRouter::initPlayerControls Jan 28 11:45:43 volumio volumio[15258]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:45:43 volumio volumio[15258]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:45:43 volumio volumio[15258]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:45:43 volumio volumio[15258]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:45:43 volumio volumio[15258]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:45:43 volumio volumio[15258]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:45:43 volumio volumio[15258]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:45:43 volumio volumio[15258]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:45:43 volumio volumio[15258]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 28 11:45:43 volumio volumio[15258]: Express server listening on port 3000 Jan 28 11:45:43 volumio volumio[15258]: [Metrics] WebUI: 16s 1.58ms Jan 28 11:45:43 volumio volumio[15370]: Forking 3 albumart workers Jan 28 11:45:43 volumio volumio[15258]: info: CoreStateMachine::resetVolumioState Jan 28 11:45:43 volumio volumio[15258]: info: CoreStateMachine::getcurrentVolume Jan 28 11:45:43 volumio volumio[15258]: info: CoreCommandRouter::volumioRetrievevolume Jan 28 11:45:43 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 11:45:43 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 11:45:43 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 11:45:43 volumio sudo[15412]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 28 11:45:43 volumio sudo[15412]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:45:43 volumio sudo[15412]: pam_unix(sudo:session): session closed for user root Jan 28 11:45:43 volumio sudo[15414]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 28 11:45:43 volumio sudo[15414]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:45:43 volumio sudo[15414]: pam_unix(sudo:session): session closed for user root Jan 28 11:45:43 volumio volumio[15258]: info: Volumio Network Manager: Network status updated: 1 Jan 28 11:45:43 volumio volumio[15258]: info: VolumeController:: Volume=100 Mute =false Jan 28 11:45:43 volumio volumio[15258]: info: CoreStateMachine::pushState Jan 28 11:45:43 volumio volumio[15258]: info: CorePlayQueue::getTrack 0 Jan 28 11:45:43 volumio volumio[15258]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 28 11:45:43 volumio volumio[15258]: info: CoreCommandRouter::volumioPushState Jan 28 11:45:43 volumio volumio[15258]: info: CoreStateMachine::updateTrackBlock Jan 28 11:45:43 volumio volumio[15258]: info: CorePlayQueue::getTrackBlock Jan 28 11:45:43 volumio volumio[15258]: info: CoreCommandRouter::volumioRetrievevolume Jan 28 11:45:43 volumio volumio-remote-updater[628]: [2026-01-28 11:45:43] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1769575541 101 Jan 28 11:45:44 volumio volumio[15258]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 1 Jan 28 11:45:44 volumio volumio[15258]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 11:45:44 volumio volumio[15258]: info: Reloading queue from file Jan 28 11:45:44 volumio volumio[15258]: info: CoreStateMachine::setRepeat null single undefined Jan 28 11:45:44 volumio volumio[15258]: info: CoreStateMachine::pushState Jan 28 11:45:44 volumio volumio[15258]: info: CorePlayQueue::getTrack 0 Jan 28 11:45:44 volumio volumio[15258]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 28 11:45:44 volumio volumio[15258]: info: CoreCommandRouter::volumioPushState Jan 28 11:45:44 volumio volumio[15258]: info: CoreStateMachine::setRandom null Jan 28 11:45:44 volumio volumio[15258]: info: CoreStateMachine::pushState Jan 28 11:45:44 volumio volumio[15258]: info: CorePlayQueue::getTrack 0 Jan 28 11:45:44 volumio volumio[15258]: info: CoreCommandRouter::volumioPushState Jan 28 11:45:44 volumio volumio[15258]: info: Setting Device type: Raspberry PI Jan 28 11:45:44 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 24. Jan 28 11:45:44 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 11:45:44 volumio volumio[15258]: info: Completed loading Core Plugins Jan 28 11:45:44 volumio volumio[15258]: info: Preparing to generate the ALSA configuration file Jan 28 11:45:44 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 11:45:44 volumio go-librespot[15429]: go-librespot daemon starting... Jan 28 11:45:44 volumio volumio[15258]: info: VolumeController:: Volume=100 Mute =false Jan 28 11:45:44 volumio volumio[15258]: info: CoreStateMachine::pushState Jan 28 11:45:44 volumio volumio[15258]: info: CorePlayQueue::getTrack 0 Jan 28 11:45:44 volumio volumio[15258]: info: CoreCommandRouter::volumioPushState Jan 28 11:45:44 volumio go-librespot[15430]: time="2026-01-28T11:45:44+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 11:45:44 volumio go-librespot[15430]: time="2026-01-28T11:45:44+07:00" level=debug msg="app state loaded" Jan 28 11:45:44 volumio go-librespot[15430]: time="2026-01-28T11:45:44+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 11:45:44 volumio volumio[15258]: info: Asound.conf file unchanged, so no further update is needed Jan 28 11:45:44 volumio volumio[15258]: info: Output device has changed, restarting MPD Jan 28 11:45:44 volumio sudo[15439]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Jan 28 11:45:44 volumio volumio[15258]: info: Output device has changed, restarting Shairport Sync Jan 28 11:45:44 volumio sudo[15439]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:45:44 volumio volumio[15258]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:45:44 volumio volumio[15258]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 11:45:44 volumio sudo[15441]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 28 11:45:44 volumio sudo[15441]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:45:44 volumio sudo[15444]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 28 11:45:44 volumio volumio[15258]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 28 11:45:44 volumio volumio[15258]: info: ___________ START PLUGINS ___________ Jan 28 11:45:44 volumio sudo[15444]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:45:44 volumio sudo[15439]: pam_unix(sudo:session): session closed for user root Jan 28 11:45:44 volumio sudo[15441]: pam_unix(sudo:session): session closed for user root Jan 28 11:45:44 volumio volumio[15258]: info: ControllerMpd::onStart: Initializing MPD Jan 28 11:45:44 volumio volumio[15258]: info: Creating MPD Configuration file Jan 28 11:45:44 volumio sudo[15452]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 28 11:45:44 volumio sudo[15452]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:45:44 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Jan 28 11:45:44 volumio sudo[15452]: pam_unix(sudo:session): session closed for user root Jan 28 11:45:44 volumio volumio[15258]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 28 11:45:44 volumio volumio[15258]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 11:45:44 volumio volumio[15258]: info: [1769575544835] CoreMusicLibrary::Adding element Media Servers Jan 28 11:45:44 volumio volumio[15258]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 11:45:44 volumio sudo[15455]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 28 11:45:44 volumio sudo[15455]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:45:44 volumio volumio[15258]: info: UPNP Browser: Client initialized successfully Jan 28 11:45:44 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 28 11:45:44 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 28 11:45:44 volumio systemd[1]: mpd.service: Consumed 7.400s CPU time. Jan 28 11:45:44 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 28 11:45:44 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 28 11:45:44 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 28 11:45:45 volumio volumio[15258]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:45:45 volumio volumio[15258]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 11:45:45 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 28 11:45:45 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 28 11:45:45 volumio go-librespot[15430]: time="2026-01-28T11:45: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 11:45:45 volumio go-librespot[15430]: time="2026-01-28T11:45:45+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 28 11:45:45 volumio go-librespot[15430]: time="2026-01-28T11:45:45+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 28 11:45:45 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 28 11:45:45 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 28 11:45:45 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 28 11:45:45 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 28 11:45:45 volumio go-librespot[15430]: time="2026-01-28T11:45:45+07:00" level=info msg="zeroconf server listening on port 42181" Jan 28 11:45:45 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 28 11:45:45 volumio volumio[15258]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 28 11:45:45 volumio volumio[15258]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:45:45 volumio volumio[15258]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 11:45:45 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 28 11:45:45 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 28 11:45:45 volumio volumio[15258]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 28 11:45:45 volumio volumio[15258]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 11:45:45 volumio volumio[15258]: info: [1769575545276] CoreMusicLibrary::Adding element Last_100 Jan 28 11:45:45 volumio volumio[15258]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 11:45:45 volumio volumio[15258]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 11:45:45 volumio volumio[15258]: info: [1769575545317] CoreMusicLibrary::Adding element Webradio Jan 28 11:45:45 volumio volumio[15258]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 11:45:45 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 11:45:45 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 11:45:45 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 11:45:45 volumio volumio[15258]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 28 11:45:45 volumio volumio[15258]: info: Initializing BBC Radios Jan 28 11:45:45 volumio go-librespot[15430]: time="2026-01-28T11:45:45+07:00" level=debug msg="obtained new client token: AAChn3M4nmjU9NSXoRavZxu2V1j6zZ4Tw9Z559KFgyxWubsTVPIORSFdFj/zxtyYbpNQNUtTZhR6f3AiUQHunlU0BAY9nz0/BGcdU/2Q4aAPM8ioHLxLaO4D6ZJvx8CawAkJ01U/8iRM7THlTrDSL9b9vNe5ATIPVa7JGD4yAdxkisrahld7vhHbNnxz+Z6R72dU6s+TUketntQcvbuUz5BoQU0N7AZ+n5BlGGAzvADfLsffYq6xo43++2Y=" Jan 28 11:45:45 volumio go-librespot[15430]: time="2026-01-28T11:45:45+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 11:45:45 volumio volumio[15258]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 28 11:45:45 volumio volumio[15258]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 11:45:45 volumio go-librespot[15430]: time="2026-01-28T11:45:45+07:00" level=debug msg="completed keyexchange" Jan 28 11:45:45 volumio go-librespot[15430]: time="2026-01-28T11:45:45+07:00" level=debug msg="completed challenge" Jan 28 11:45:45 volumio sudo[15467]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 28 11:45:45 volumio sudo[15467]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jan 28 11:45:45 volumio volumio[15258]: info: Creating Spotify config file Jan 28 11:45:45 volumio volumio[15258]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:45:45 volumio sudo[15467]: pam_unix(sudo:session): session closed for user root Jan 28 11:45:45 volumio go-librespot[15430]: time="2026-01-28T11:45:45+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 11:45:45 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 11:45:45 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 11:45:46 volumio volumio[15258]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 11:45:46 volumio volumio[15258]: info: [1769575546603] CoreMusicLibrary::Adding element YouTube Music Jan 28 11:45:46 volumio volumio[15258]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 11:45:46 volumio volumio[15258]: Cannot find translation for source YouTube Music Jan 28 11:45:46 volumio volumio[15258]: info: Volumio Calling Home Jan 28 11:45:46 volumio sudo[15490]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Jan 28 11:45:46 volumio sudo[15490]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:45:46 volumio volumio[15385]: Starting albumart workers Jan 28 11:45:46 volumio volumio[15384]: Starting albumart workers Jan 28 11:45:47 volumio sudo[15490]: pam_unix(sudo:session): session closed for user root Jan 28 11:45:47 volumio volumio[15383]: Starting albumart workers Jan 28 11:45:47 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 11:45:47 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 11:45:47 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 11:45:47 volumio volumio[15258]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Jan 28 11:45:47 volumio volumio[15258]: info: Discovery: Found device Volumio Jan 28 11:45:47 volumio volumio[15258]: info: CoreCommandRouter::volumioGetState Jan 28 11:45:47 volumio volumio[15258]: info: CorePlayQueue::getTrack 0 Jan 28 11:45:47 volumio volumio[15258]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Jan 28 11:45:47 volumio volumio[15258]: info: Discovery: Found device Volumio Jan 28 11:45:47 volumio volumio[15258]: info: CoreCommandRouter::volumioGetState Jan 28 11:45:47 volumio volumio[15258]: info: CorePlayQueue::getTrack 0 Jan 28 11:45:47 volumio volumio[15258]: info: MPD Permissions set Jan 28 11:45:47 volumio volumio[15258]: info: MPD Permissions set Jan 28 11:45:47 volumio volumio[15258]: info: Upmpdcli Daemon Started Jan 28 11:45:47 volumio volumio[15258]: info: Spotify config file written Jan 28 11:45:47 volumio sudo[15496]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jan 28 11:45:47 volumio sudo[15496]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:45:47 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 11:45:47 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 11:45:47 volumio go-librespot[15498]: go-librespot daemon starting... Jan 28 11:45:47 volumio sudo[15496]: pam_unix(sudo:session): session closed for user root Jan 28 11:45:47 volumio go-librespot[15499]: time="2026-01-28T11:45:47+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 11:45:47 volumio go-librespot[15499]: time="2026-01-28T11:45:47+07:00" level=debug msg="app state loaded" Jan 28 11:45:47 volumio go-librespot[15499]: time="2026-01-28T11:45:47+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 11:45:47 volumio volumio[15258]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Jan 28 11:45:48 volumio volumio[15258]: info: Volumio called home Jan 28 11:45:48 volumio volumio[15258]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:45:48 volumio volumio[15258]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:45:48 volumio volumio[15258]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:45:48 volumio volumio[15258]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:45:48 volumio volumio[15258]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:45:48 volumio volumio[15258]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:45:48 volumio volumio[15258]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:45:48 volumio volumio[15258]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:45:48 volumio volumio[15258]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 11:45:48 volumio volumio[15258]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:45:48 volumio volumio[15258]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:45:48 volumio volumio[15258]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:45:48 volumio volumio[15258]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:45:48 volumio volumio[15258]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:45:48 volumio volumio[15258]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:45:48 volumio volumio[15258]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:45:48 volumio volumio[15258]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:45:48 volumio volumio[15258]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:45:48 volumio volumio[15258]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 11:45:48 volumio volumio[15258]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:45:48 volumio volumio[15258]: info: No need to fix Spotify hosts Jan 28 11:45:48 volumio go-librespot[15499]: time="2026-01-28T11:45:48+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 11:45:48 volumio go-librespot[15499]: time="2026-01-28T11:45:48+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 28 11:45:48 volumio go-librespot[15499]: time="2026-01-28T11:45:48+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 28 11:45:48 volumio go-librespot[15499]: time="2026-01-28T11:45:48+07:00" level=info msg="zeroconf server listening on port 39961" Jan 28 11:45:48 volumio go-librespot[15499]: time="2026-01-28T11:45:48+07:00" level=debug msg="obtained new client token: AABFCq7dLSUljjMCiRVMr4DEKcMufJVsCIwN2TIHKPP3g9czBBKG6WVtqJP7kEGn8HghHMRyz9TsQR/XB2Qsqga55YiM6AUxOf1jQ7Hq8i9RKYsJsh6oEgY16dfiMd4yXAm7hZn645YumI0D/iUq+7T1jms/PomaRaR+oubYM6oTOHdr1j6lR9y+zH2s9bb0fwl34agPMUAeStonIfT7rB0nKwGHnj/G5FMiW3GIzOILB7wlFzXcuhFQUgk=" Jan 28 11:45:48 volumio go-librespot[15499]: time="2026-01-28T11:45:48+07:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:4070, retrying with a different AP" error="dial tcp 104.199.241.202:4070: connect: connection refused" Jan 28 11:45:48 volumio go-librespot[15499]: time="2026-01-28T11:45:48+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Jan 28 11:45:49 volumio go-librespot[15499]: time="2026-01-28T11:45:49+07:00" level=debug msg="completed keyexchange" Jan 28 11:45:49 volumio go-librespot[15499]: time="2026-01-28T11:45:49+07:00" level=debug msg="completed challenge" Jan 28 11:45:49 volumio go-librespot[15499]: time="2026-01-28T11:45:49+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 11:45:49 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 11:45:49 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 11:45:49 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 11:45:49 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 11:45:49 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 11:45:49 volumio volumio[15258]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 28 11:45:49 volumio volumio[15258]: SPOTIFY: BQDHHXr4V3KR-j2Wk91qV5HPLWPqHhOs4odu9zlb4f1ECPKOqfmRj4FPSVt_FZUIixAhXvoyj5dHlWtD592RfkkuhPsBsc13NCvFzPWVfFACz3Q4uWwgwEl2uTj_8gmttLM3PeJlN0cY2IrOnDUirdnxDselhFHEIMBWNNcxioE9DSg0InWLJfJlQ3eURfYdQzUyq0Am3piKIRDDSSWIKt_sj80q0LrCb2GTuGkFe2D87yN9fhbTWS_N74Nf12PZaWr8WZQ70nhcF44D5TKehW3cp8OKq2xmeS9_mnVsxtlRewTsSaDAJ1zr Jan 28 11:45:49 volumio volumio[15258]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 28 11:45:49 volumio volumio[15258]: info: New Spotify access token = BQDHHXr4V3KR-j2Wk91qV5HPLWPqHhOs4odu9zlb4f1ECPKOqfmRj4FPSVt_FZUIixAhXvoyj5dHlWtD592RfkkuhPsBsc13NCvFzPWVfFACz3Q4uWwgwEl2uTj_8gmttLM3PeJlN0cY2IrOnDUirdnxDselhFHEIMBWNNcxioE9DSg0InWLJfJlQ3eURfYdQzUyq0Am3piKIRDDSSWIKt_sj80q0LrCb2GTuGkFe2D87yN9fhbTWS_N74Nf12PZaWr8WZQ70nhcF44D5TKehW3cp8OKq2xmeS9_mnVsxtlRewTsSaDAJ1zr Jan 28 11:45:49 volumio volumio[15258]: info: Spotify credentials grant success - running version from March 24, 2019 Jan 28 11:45:49 volumio volumio[15258]: info: Starting Shairport Sync Jan 28 11:45:49 volumio volumio[15258]: info: Starting Shairport Sync Jan 28 11:45:49 volumio volumio[15258]: info: Starting Shairport Sync Jan 28 11:45:49 volumio sudo[15536]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 28 11:45:49 volumio sudo[15536]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:45:49 volumio sudo[15539]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 28 11:45:49 volumio sudo[15539]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:45:49 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 28 11:45:49 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Jan 28 11:45:49 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 28 11:45:49 volumio systemd[1]: shairport-sync.service: Consumed 2.280s CPU time. Jan 28 11:45:49 volumio sudo[15540]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 28 11:45:49 volumio sudo[15540]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:45:49 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 28 11:45:49 volumio sudo[15536]: pam_unix(sudo:session): session closed for user root Jan 28 11:45:50 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 28 11:45:50 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Jan 28 11:45:50 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 28 11:45:50 volumio volumio[15258]: info: Shairport-Sync Started Jan 28 11:45:50 volumio volumio[15258]: Error adding Membership: Error: addMembership EINVAL Jan 28 11:45:50 volumio volumio[15258]: info: CoreCommandRouter::volumioGetState Jan 28 11:45:50 volumio volumio[15258]: info: CorePlayQueue::getTrack 0 Jan 28 11:45:50 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 28 11:45:50 volumio sudo[15539]: pam_unix(sudo:session): session closed for user root Jan 28 11:45:50 volumio sudo[15540]: pam_unix(sudo:session): session closed for user root Jan 28 11:45:50 volumio volumio[15258]: info: Shairport-Sync Started Jan 28 11:45:50 volumio volumio[15258]: info: Shairport-Sync Started Jan 28 11:45:50 volumio volumio[15258]: SPOTIFY: User informations: {"country":"PK","display_name":"215mmgea6kss3jxeqsqdquvji","email":"linh.ngotran@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/215mmgea6kss3jxeqsqdquvji"},"followers":{"href":null,"total":1},"href":"https://api.spotify.com/v1/users/215mmgea6kss3jxeqsqdquvji","id":"215mmgea6kss3jxeqsqdquvji","images":[],"product":"premium","type":"user","uri":"spotify:user:215mmgea6kss3jxeqsqdquvji"} Jan 28 11:45:50 volumio volumio[15258]: info: Spotify Successfully logged in Jan 28 11:45:50 volumio volumio[15258]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 11:45:50 volumio volumio[15258]: info: [1769575550464] CoreMusicLibrary::Adding element Spotify Jan 28 11:45:50 volumio volumio[15258]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 11:45:50 volumio volumio[15258]: Cannot find translation for source YouTube Music Jan 28 11:45:50 volumio volumio[15258]: Cannot find translation for source Spotify Jan 28 11:45:51 volumio volumio[15258]: info: [yt-cast-receiver] DIAL server listening on port 8098 Jan 28 11:45:51 volumio volumio[15258]: info: CoreCommandRouter::volumioRetrievevolume Jan 28 11:45:51 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 11:45:51 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 11:45:51 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 11:45:51 volumio volumio[15258]: info: VolumeController:: Volume=100 Mute =false Jan 28 11:45:51 volumio volumio[15258]: info: CoreCommandRouter::volumioGetState Jan 28 11:45:51 volumio volumio[15258]: info: CorePlayQueue::getTrack 0 Jan 28 11:45:51 volumio volumio[15258]: info: CoreStateMachine::pushState Jan 28 11:45:51 volumio volumio[15258]: info: CorePlayQueue::getTrack 0 Jan 28 11:45:51 volumio volumio[15258]: info: CoreCommandRouter::volumioPushState Jan 28 11:45:52 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 25. Jan 28 11:45:52 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 11:45:52 volumio volumio[15258]: info: go-librespot daemon successfully initialized Jan 28 11:45:52 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 11:45:52 volumio go-librespot[15589]: go-librespot daemon starting... Jan 28 11:45:52 volumio go-librespot[15590]: time="2026-01-28T11:45:52+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 11:45:52 volumio go-librespot[15590]: time="2026-01-28T11:45:52+07:00" level=debug msg="app state loaded" Jan 28 11:45:52 volumio go-librespot[15590]: time="2026-01-28T11:45:52+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 11:45:52 volumio mpd[15484]: 2026-01-28T11:45:52 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 28 11:45:52 volumio systemd[1]: Started mpd.service - Music Player Daemon. Jan 28 11:45:52 volumio sudo[15455]: pam_unix(sudo:session): session closed for user root Jan 28 11:45:52 volumio sudo[15444]: pam_unix(sudo:session): session closed for user root Jan 28 11:45:52 volumio go-librespot[15590]: time="2026-01-28T11:45:52+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 11:45:52 volumio go-librespot[15590]: time="2026-01-28T11:45:52+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 28 11:45:52 volumio go-librespot[15590]: time="2026-01-28T11:45:52+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 28 11:45:52 volumio go-librespot[15590]: time="2026-01-28T11:45:52+07:00" level=info msg="zeroconf server listening on port 41591" Jan 28 11:45:53 volumio volumio[15258]: error: MPD error: The expression evaluated to a falsy value: Jan 28 11:45:53 volumio volumio[15258]: assert.ok(self.idling) Jan 28 11:45:53 volumio volumio[15258]: error: The expression evaluated to a falsy value: Jan 28 11:45:53 volumio volumio[15258]: assert.ok(self.idling) Jan 28 11:45:53 volumio volumio[15258]: error: updateQueue error: null Jan 28 11:45:53 volumio volumio[15258]: info: MPD running with PID15484 Jan 28 11:45:53 volumio volumio[15258]: ,establishing connection Jan 28 11:45:53 volumio volumio[15258]: info: Completed starting Core Plugins Jan 28 11:45:53 volumio volumio[15258]: info: ------------------------------------------- Jan 28 11:45:53 volumio volumio[15258]: info: ----- MyVolumio plugins startup ---- Jan 28 11:45:53 volumio volumio[15258]: info: ------------------------------------------- Jan 28 11:45:53 volumio volumio[15258]: info: [MyVolumio PluginManager] Fetching plans data.... Jan 28 11:45:53 volumio volumio[15258]: error: updateQueue error: null Jan 28 11:45:53 volumio go-librespot[15590]: time="2026-01-28T11:45:53+07:00" level=debug msg="obtained new client token: AAB8d6GUrFCAhUzcE9NPiBxwhtmoA5LJ8hKAIzTa6XIdh44sh+49NmoTHaWE5OPu7EMil8Nn1Boo/u+GRvuBYprjGT3uwXR0FLwbPDR6vUUUQH2LglXREfCiRmdZc+3eRSejVpu1kVoi8mxRjBEoTcyTuBwrs/hNJ51N/4ZaqgoAsXfVCiSOxqgdlL1gZHRKjaBASJ/uQtKJWxVSDa8BVCizDGPkxJkmviMRwTreZWxg6i6JlHV5lj1I" Jan 28 11:45:53 volumio go-librespot[15590]: time="2026-01-28T11:45:53+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 11:45:53 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 11:45:53 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 11:45:53 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 11:45:53 volumio go-librespot[15590]: time="2026-01-28T11:45:53+07:00" level=debug msg="completed keyexchange" Jan 28 11:45:53 volumio go-librespot[15590]: time="2026-01-28T11:45:53+07:00" level=debug msg="completed challenge" Jan 28 11:45:53 volumio go-librespot[15590]: time="2026-01-28T11:45:53+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 11:45:53 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 11:45:53 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 11:45:55 volumio volumio[15258]: info: Initializing connection to go-librespot Websocket Jan 28 11:45:55 volumio volumio[15258]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 28 11:45:55 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 11:45:55 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 11:45:55 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 11:45:56 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 26. Jan 28 11:45:56 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 11:45:56 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 11:45:56 volumio go-librespot[15601]: go-librespot daemon starting... Jan 28 11:45:56 volumio go-librespot[15602]: time="2026-01-28T11:45:56+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 11:45:56 volumio go-librespot[15602]: time="2026-01-28T11:45:56+07:00" level=debug msg="app state loaded" Jan 28 11:45:56 volumio go-librespot[15602]: time="2026-01-28T11:45:56+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 11:45:57 volumio go-librespot[15602]: time="2026-01-28T11:45:57+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 11:45:57 volumio go-librespot[15602]: time="2026-01-28T11:45:57+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 28 11:45:57 volumio go-librespot[15602]: time="2026-01-28T11:45:57+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 28 11:45:57 volumio go-librespot[15602]: time="2026-01-28T11:45:57+07:00" level=info msg="zeroconf server listening on port 45329" Jan 28 11:45:57 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 11:45:57 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 11:45:57 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 11:45:57 volumio go-librespot[15602]: time="2026-01-28T11:45:57+07:00" level=debug msg="obtained new client token: AACpC96L7LW8rhCjpIruyMB0u/OGLBqP2kTUkYx+CsR3UHS1RtdzUrvkSKzsFIerruFDUmXRZBpeIV4oEaRmliYwjv/wAvlBaGXrOW1i/+892VrcTubpZGI32xlCXs6AUxocu5RrrCa/glNesmPEs21+iLu/VElviZX5d1ZyeMTW4knMrk4YsIb1X8NK/F6fmWIJ3Jzi0z55h2QUX/HXgmCEW1Lm+UyeHxr3ZwOywH2tCWCrDKuru5Ze8bY=" Jan 28 11:45:57 volumio go-librespot[15602]: time="2026-01-28T11:45:57+07:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:4070, retrying with a different AP" error="dial tcp 104.199.241.202:4070: connect: connection refused" Jan 28 11:45:57 volumio go-librespot[15602]: time="2026-01-28T11:45:57+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Jan 28 11:45:57 volumio go-librespot[15602]: time="2026-01-28T11:45:57+07:00" level=debug msg="completed keyexchange" Jan 28 11:45:57 volumio go-librespot[15602]: time="2026-01-28T11:45:57+07:00" level=debug msg="completed challenge" Jan 28 11:45:57 volumio go-librespot[15602]: time="2026-01-28T11:45:57+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 11:45:57 volumio volumio[15258]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Jan 28 11:45:57 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 11:45:57 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 11:45:58 volumio volumio[15258]: info: Initializing connection to go-librespot Websocket Jan 28 11:45:58 volumio volumio[15258]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 28 11:45:59 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 11:45:59 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 11:45:59 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 11:46:00 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 27. Jan 28 11:46:00 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 11:46:01 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 11:46:01 volumio go-librespot[15610]: go-librespot daemon starting... Jan 28 11:46:01 volumio go-librespot[15611]: time="2026-01-28T11:46:01+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 11:46:01 volumio go-librespot[15611]: time="2026-01-28T11:46:01+07:00" level=debug msg="app state loaded" Jan 28 11:46:01 volumio go-librespot[15611]: time="2026-01-28T11:46:01+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 11:46:01 volumio volumio[15258]: info: Initializing connection to go-librespot Websocket Jan 28 11:46:01 volumio go-librespot[15611]: time="2026-01-28T11:46:01+07:00" level=debug msg="new websocket client" Jan 28 11:46:01 volumio volumio[15258]: info: Connection to go-librespot Websocket established Jan 28 11:46:01 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 11:46:01 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 11:46:01 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 11:46:01 volumio go-librespot[15611]: time="2026-01-28T11:46:01+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 28 11:46:01 volumio go-librespot[15611]: time="2026-01-28T11:46:01+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Jan 28 11:46:01 volumio go-librespot[15611]: time="2026-01-28T11:46:01+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Jan 28 11:46:01 volumio go-librespot[15611]: time="2026-01-28T11:46:01+07:00" level=info msg="zeroconf server listening on port 35037" Jan 28 11:46:01 volumio volumio[15258]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Jan 28 11:46:01 volumio volumio[15258]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Jan 28 11:46:01 volumio volumio[15258]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Jan 28 11:46:01 volumio volumio[15258]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Jan 28 11:46:01 volumio volumio[15258]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Jan 28 11:46:01 volumio volumio[15258]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Jan 28 11:46:01 volumio volumio[15258]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Jan 28 11:46:01 volumio volumio[15258]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Jan 28 11:46:01 volumio volumio[15258]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Jan 28 11:46:01 volumio volumio[15258]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Jan 28 11:46:01 volumio volumio[15258]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Jan 28 11:46:01 volumio volumio[15258]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Jan 28 11:46:01 volumio volumio[15258]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Jan 28 11:46:01 volumio go-librespot[15611]: time="2026-01-28T11:46:01+07:00" level=debug msg="obtained new client token: AAD3TqQtsGceSvbfxrR2U6D0bn4aGCi1wHbQE80n76+aGOFRvorod0aRVpGx3SLk+gnOmIqYZRK1lV4tN/oENu/lMOsdBUTE/FrCMOn+hQiBpQfsxzEG3omfxYAMB75llkqLdKZF37LCWpoj/Ny4m1v57mXcG4/FSuxUd8MnNc3viUah2Z6bScVn2Hj5PT6RNRniNVKm9crgDTZ2mqQljY4O+W9/cBsCzyV3IFYjdPr8CfdwIgvYBDG/XJg=" Jan 28 11:46:01 volumio volumio[15258]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Jan 28 11:46:01 volumio volumio[15258]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Jan 28 11:46:01 volumio volumio[15258]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Jan 28 11:46:01 volumio volumio[15258]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Jan 28 11:46:01 volumio volumio[15258]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Jan 28 11:46:01 volumio volumio[15258]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Jan 28 11:46:01 volumio volumio[15258]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Jan 28 11:46:01 volumio volumio[15258]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Jan 28 11:46:01 volumio volumio[15258]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Jan 28 11:46:01 volumio volumio[15258]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Jan 28 11:46:01 volumio volumio[15258]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Jan 28 11:46:01 volumio volumio[15258]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Jan 28 11:46:01 volumio volumio[15258]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Jan 28 11:46:01 volumio volumio[15258]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Jan 28 11:46:01 volumio volumio[15258]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Jan 28 11:46:01 volumio volumio[15258]: info: Adding plugin bluetooth to MyMusic Plugins Jan 28 11:46:01 volumio volumio[15258]: info: Adding plugin multiroom to MyMusic Plugins Jan 28 11:46:01 volumio volumio[15258]: info: Adding plugin metavolumio to MyMusic Plugins Jan 28 11:46:01 volumio volumio[15258]: info: Adding plugin cd_controller to MyMusic Plugins Jan 28 11:46:01 volumio volumio[15258]: info: Adding plugin qobuzconnect to MyMusic Plugins Jan 28 11:46:01 volumio volumio[15258]: info: Adding plugin smart_inputs to MyMusic Plugins Jan 28 11:46:01 volumio volumio[15258]: info: Adding plugin tidalconnect to MyMusic Plugins Jan 28 11:46:01 volumio volumio[15258]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Jan 28 11:46:02 volumio go-librespot[15611]: time="2026-01-28T11:46:02+07:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:4070, retrying with a different AP" error="dial tcp 104.199.241.202:4070: connect: connection refused" Jan 28 11:46:02 volumio go-librespot[15611]: time="2026-01-28T11:46:02+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Jan 28 11:46:02 volumio go-librespot[15611]: time="2026-01-28T11:46:02+07:00" level=debug msg="completed keyexchange" Jan 28 11:46:02 volumio go-librespot[15611]: time="2026-01-28T11:46:02+07:00" level=debug msg="completed challenge" Jan 28 11:46:02 volumio go-librespot[15611]: time="2026-01-28T11:46:02+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 11:46:02 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 11:46:02 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 11:46:03 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 11:46:03 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 11:46:03 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 11:46:03 volumio volumio[15258]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Jan 28 11:46:03 volumio volumio[15258]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Jan 28 11:46:03 volumio volumio[15258]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 11:46:03 volumio volumio[15258]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 11:46:03 volumio volumio[15258]: info: Starting MyVolumio Remote Streaming Endpoints Jan 28 11:46:03 volumio volumio[15258]: info: MyVolumio login type: Token Jan 28 11:46:04 volumio volumio[15258]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Jan 28 11:46:04 volumio volumio[15258]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Jan 28 11:46:05 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 11:46:05 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 11:46:05 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 11:46:05 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 28. Jan 28 11:46:05 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 11:46:05 volumio volumio[15258]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Jan 28 11:46:05 volumio volumio[15258]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Jan 28 11:46:05 volumio volumio[15258]: info: Streaming services startup Jan 28 11:46:05 volumio volumio[15258]: info: Starting Streaming Daemon Jan 28 11:46:05 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 11:46:05 volumio go-librespot[15632]: go-librespot daemon starting... Jan 28 11:46:05 volumio go-librespot[15635]: time="2026-01-28T11:46:05+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 11:46:05 volumio go-librespot[15635]: time="2026-01-28T11:46:05+07:00" level=debug msg="app state loaded" Jan 28 11:46:05 volumio volumio[15258]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Jan 28 11:46:05 volumio go-librespot[15635]: time="2026-01-28T11:46:05+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 11:46:05 volumio sudo[15640]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jan 28 11:46:05 volumio sudo[15640]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:46:05 volumio sudo[15640]: pam_unix(sudo:session): session closed for user root Jan 28 11:46:05 volumio volumio[15258]: info: Getting Spotify volume Jan 28 11:46:05 volumio volumio[15258]: info: Connection to go-librespot Websocket closed Jan 28 11:46:05 volumio volumio[15258]: error: Cannot start Volumio Streaming Daemon Jan 28 11:46:05 volumio volumio[15258]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Jan 28 11:46:05 volumio volumio[15258]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Jan 28 11:46:05 volumio volumio[15258]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Jan 28 11:46:06 volumio volumio[15258]: info: CoreCommandRouter::volumioGetState Jan 28 11:46:06 volumio volumio[15258]: info: CorePlayQueue::getTrack 0 Jan 28 11:46:06 volumio volumio[15258]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jan 28 11:46:06 volumio volumio[15258]: SPOTIFY: SPOTIFY VOLUME undefined Jan 28 11:46:06 volumio volumio[15258]: SPOTIFY: VOLUMIO VOLUME 100 Jan 28 11:46:06 volumio volumio[15258]: info: Aligning Spotify Volume to Volumio Volume Jan 28 11:46:06 volumio volumio[15258]: info: CoreCommandRouter::volumioGetState Jan 28 11:46:06 volumio volumio[15258]: info: CorePlayQueue::getTrack 0 Jan 28 11:46:06 volumio volumio[15258]: info: Setting Spotify Volume from Volumio: 100 Jan 28 11:46:06 volumio go-librespot[15635]: time="2026-01-28T11:46:06+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 11:46:06 volumio go-librespot[15635]: time="2026-01-28T11:46:06+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 28 11:46:06 volumio go-librespot[15635]: time="2026-01-28T11:46:06+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 28 11:46:06 volumio go-librespot[15635]: time="2026-01-28T11:46:06+07:00" level=info msg="zeroconf server listening on port 46235" Jan 28 11:46:06 volumio go-librespot[15635]: time="2026-01-28T11:46:06+07:00" level=debug msg="obtained new client token: AADkle1QupiPO2S6hsmxDzr2gEHjcT/n2i4hlccMezkNKlamS5p9Mddlg1yxqsHMGtB5LnD7ivQf1HpSR85i7dnNi24P3qId1AwCv5cVzluZOtUpZct+iy8t0+o9SNYLlPdZCdayr7N0i6hAcQ97HRYrnx70etc1jQ+yCf2oF9SXXUSr7o45MBQsgZke/GupNetS1CbftgoAcYD4ltwFyQB0c1LEiCvBALcgWDnR8nUuSekl+3MM3di/MAs=" Jan 28 11:46:06 volumio go-librespot[15635]: time="2026-01-28T11:46:06+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 11:46:06 volumio go-librespot[15635]: time="2026-01-28T11:46:06+07:00" level=debug msg="completed keyexchange" Jan 28 11:46:06 volumio go-librespot[15635]: time="2026-01-28T11:46:06+07:00" level=debug msg="completed challenge" Jan 28 11:46:06 volumio go-librespot[15635]: time="2026-01-28T11:46:06+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 11:46:06 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 11:46:06 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 11:46:06 volumio volumio[15258]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 28 11:46:06 volumio volumio[15258]: Error: socket hang up Jan 28 11:46:06 volumio volumio[15258]: at connResetException (node:internal/errors:720:14) Jan 28 11:46:06 volumio volumio[15258]: at Socket.socketOnEnd (node:_http_client:519:23) Jan 28 11:46:06 volumio volumio[15258]: at Socket.emit (node:events:526:35) Jan 28 11:46:06 volumio volumio[15258]: at endReadableNT (node:internal/streams/readable:1376:12) Jan 28 11:46:06 volumio volumio[15258]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Jan 28 11:46:06 volumio volumio[15258]: code: 'ECONNRESET', Jan 28 11:46:06 volumio volumio[15258]: response: undefined Jan 28 11:46:06 volumio volumio[15258]: } Jan 28 11:46:06 volumio volumio[15258]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 28 11:46:07 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 11:46:07 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 11:46:07 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 11:46:08 volumio sudo[15663]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-01-28 11:45' Jan 28 11:46:08 volumio sudo[15663]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:46:08 volumio sudo[15663]: pam_unix(sudo:session): session closed for user root Jan 28 11:46:09 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 11:46:09 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 11:46:09 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 11:46:09 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 29. Jan 28 11:46:09 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 11:46:09 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 11:46:09 volumio go-librespot[15671]: go-librespot daemon starting... Jan 28 11:46:09 volumio go-librespot[15672]: time="2026-01-28T11:46:09+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 11:46:09 volumio go-librespot[15672]: time="2026-01-28T11:46:09+07:00" level=debug msg="app state loaded" Jan 28 11:46:09 volumio go-librespot[15672]: time="2026-01-28T11:46:09+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 11:46:09 volumio volumio-remote-updater[628]: [2026-01-28 11:46:09] [error] handle_read_frame error: asio.system:104 (Connection reset by peer) Jan 28 11:46:09 volumio volumio-remote-updater[628]: [2026-01-28 11:46:09] [disconnect] Disconnect close local:[1006,Connection reset by peer] remote:[1006] Jan 28 11:46:09 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Jan 28 11:46:09 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Jan 28 11:46:09 volumio systemd[1]: volumio.service: Consumed 59.037s CPU time. Jan 28 11:46:10 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 28 11:46:10 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Jan 28 11:46:10 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 10065. Jan 28 11:46:10 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 28 11:46:10 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Jan 28 11:46:10 volumio systemd[1]: volumio.service: Consumed 59.037s CPU time. Jan 28 11:46:10 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Jan 28 11:46:10 volumio go-librespot[15672]: time="2026-01-28T11:46:10+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 11:46:10 volumio go-librespot[15672]: time="2026-01-28T11:46:10+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 28 11:46:10 volumio go-librespot[15672]: time="2026-01-28T11:46:10+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 28 11:46:10 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Jan 28 11:46:10 volumio go-librespot[15672]: time="2026-01-28T11:46:10+07:00" level=info msg="zeroconf server listening on port 43655" Jan 28 11:46:10 volumio go-librespot[15672]: time="2026-01-28T11:46:10+07:00" level=debug msg="obtained new client token: AADWQcNlhBa5jNe70WoZWf0tGHefvbNIZpNE4xls8WPnNyz3C5soZ+aIBd6/Ke17oT/fG0ku82p4vKcvmRFYWgRc0OBThqltBuZmnbS01C9HHGs078WsByvcXlv4s6dt5kIp5flLGV4ptnq42TUOZW29MBVAURNGSAlYvkMkwoParFvoT88RcFdzr/pF+olc2p/sg3H5bRwocxG9/pX6l+Sw+yBNFwcCYQ5vEiQLk5A6KO+XCZDFIPRfP1c=" Jan 28 11:46:10 volumio go-librespot[15672]: time="2026-01-28T11:46:10+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 11:46:10 volumio go-librespot[15672]: time="2026-01-28T11:46:10+07:00" level=debug msg="completed keyexchange" Jan 28 11:46:10 volumio go-librespot[15672]: time="2026-01-28T11:46:10+07:00" level=debug msg="completed challenge" Jan 28 11:46:10 volumio go-librespot[15672]: time="2026-01-28T11:46:10+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 11:46:10 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 11:46:10 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 11:46:11 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 11:46:11 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 11:46:11 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 11:46:13 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 11:46:13 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 11:46:13 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 11:46:13 volumio volumio[15692]: info: ------------------------------------------- Jan 28 11:46:13 volumio volumio[15692]: info: ----- Volumio3 ---- Jan 28 11:46:13 volumio volumio[15692]: info: ------------------------------------------- Jan 28 11:46:13 volumio volumio[15692]: info: ----- System startup ---- Jan 28 11:46:13 volumio volumio[15692]: info: ------------------------------------------- Jan 28 11:46:13 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 30. Jan 28 11:46:13 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 11:46:14 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 11:46:14 volumio go-librespot[15714]: go-librespot daemon starting... Jan 28 11:46:14 volumio go-librespot[15715]: time="2026-01-28T11:46:14+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 11:46:14 volumio go-librespot[15715]: time="2026-01-28T11:46:14+07:00" level=debug msg="app state loaded" Jan 28 11:46:14 volumio go-librespot[15715]: time="2026-01-28T11:46:14+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 11:46:14 volumio go-librespot[15715]: time="2026-01-28T11:46:14+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 28 11:46:14 volumio go-librespot[15715]: time="2026-01-28T11:46:14+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Jan 28 11:46:14 volumio go-librespot[15715]: time="2026-01-28T11:46:14+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Jan 28 11:46:14 volumio go-librespot[15715]: time="2026-01-28T11:46:14+07:00" level=info msg="zeroconf server listening on port 43991" Jan 28 11:46:14 volumio go-librespot[15715]: time="2026-01-28T11:46:14+07:00" level=debug msg="obtained new client token: AACJo1CSQUsy2LxcenDyrkwylTHj5gS7hsUJhGG0WlIhhcelkOJkWPHKWnw2G4UZV3NHKJEXVvyG2UanHfmwPIGkRcjPUsKRKSCxBzoe8HRNQ+mF5SrCzfTp+ZVvEvZZzGcHo4a0DKuFhzAo/Yh1S0mnvd0/0tfl7A1uMr1N/wpkz1zXiWk5FBEJtkv224KeOv4FxozPToxOE8kCfaxer7nAIfijnQPzLV15GNKG1AzUD45BvBjCbsReztA=" Jan 28 11:46:14 volumio volumio-remote-updater[628]: [2026-01-28 11:46:14] [connect] Successful connection Jan 28 11:46:14 volumio go-librespot[15715]: time="2026-01-28T11:46:14+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 11:46:15 volumio go-librespot[15715]: time="2026-01-28T11:46:15+07:00" level=debug msg="completed keyexchange" Jan 28 11:46:15 volumio go-librespot[15715]: time="2026-01-28T11:46:15+07:00" level=debug msg="completed challenge" Jan 28 11:46:15 volumio go-librespot[15715]: time="2026-01-28T11:46:15+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 11:46:15 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 11:46:15 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 11:46:15 volumio volumio[15692]: info: MYVOLUMIO Environment detected Jan 28 11:46:15 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 11:46:15 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 11:46:15 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 11:46:15 volumio volumio[15692]: info: Plugin folders cleanup Jan 28 11:46:15 volumio volumio[15692]: info: Scanning into folder /volumio/app/plugins/ Jan 28 11:46:15 volumio volumio[15692]: info: Scanning category audio_interface Jan 28 11:46:15 volumio volumio[15692]: info: Scanning category miscellanea Jan 28 11:46:15 volumio volumio[15692]: info: Scanning category music_service Jan 28 11:46:15 volumio volumio[15692]: info: Scanning category plugins.json Jan 28 11:46:15 volumio volumio[15692]: info: Scanning category system_controller Jan 28 11:46:15 volumio volumio[15692]: info: Scanning category user_interface Jan 28 11:46:15 volumio volumio[15692]: info: Scanning into folder /data/plugins/ Jan 28 11:46:15 volumio volumio[15692]: info: Scanning category music_service Jan 28 11:46:15 volumio volumio[15692]: info: Plugin folders cleanup completed Jan 28 11:46:15 volumio volumio[15692]: info: ------------------------------------------- Jan 28 11:46:15 volumio volumio[15692]: info: ----- Core plugins startup ---- Jan 28 11:46:15 volumio volumio[15692]: info: ------------------------------------------- Jan 28 11:46:15 volumio volumio[15692]: info: Loading plugins from folder /volumio/app/plugins/ Jan 28 11:46:15 volumio volumio[15692]: info: Adding plugin upnp to MyMusic Plugins Jan 28 11:46:15 volumio volumio[15692]: info: Adding plugin airplay_emulation to MyMusic Plugins Jan 28 11:46:15 volumio volumio[15692]: info: Adding plugin upnp_browser to MyMusic Plugins Jan 28 11:46:15 volumio volumio[15692]: info: Loading plugins from folder /data/plugins/ Jan 28 11:46:15 volumio volumio[15692]: info: Loading plugin "system"... Jan 28 11:46:15 volumio volumio[15692]: info: Loading plugin "appearance"... Jan 28 11:46:17 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 11:46:17 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 11:46:17 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 11:46:17 volumio volumio[15692]: info: Loading plugin "network"... Jan 28 11:46:17 volumio volumio[15692]: info: Refreshing Cached IP Addresses Jan 28 11:46:17 volumio sudo[15730]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 28 11:46:17 volumio sudo[15730]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:46:17 volumio volumio[15692]: info: Loading plugin "services"... Jan 28 11:46:17 volumio volumio[15692]: info: Loading plugin "alsa_controller"... Jan 28 11:46:17 volumio sudo[15730]: pam_unix(sudo:session): session closed for user root Jan 28 11:46:17 volumio sudo[15732]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 28 11:46:17 volumio sudo[15732]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:46:17 volumio sudo[15732]: pam_unix(sudo:session): session closed for user root Jan 28 11:46:17 volumio sudo[15743]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Jan 28 11:46:17 volumio sudo[15743]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:46:17 volumio volumio[15692]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 28 11:46:17 volumio volumio[15692]: info: Loading plugin "wizard"... Jan 28 11:46:17 volumio volumio[15692]: info: Loading plugin "networkfs"... Jan 28 11:46:17 volumio volumio[15692]: info: Starting Udev Watcher for removable devices Jan 28 11:46:17 volumio volumio[15692]: info: Ignoring mount for partition: boot Jan 28 11:46:17 volumio volumio[15692]: info: Ignoring mount for partition: volumio Jan 28 11:46:17 volumio volumio[15692]: info: Ignoring mount for partition: volumio_data Jan 28 11:46:17 volumio volumio[15692]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 28 11:46:17 volumio volumio[15692]: info: Loading plugin "volumio_command_line_client"... Jan 28 11:46:17 volumio volumio[15692]: info: Loading plugin "upnp"... Jan 28 11:46:17 volumio volumio[15692]: info: [1769575577896] Starting Upmpd Daemon Jan 28 11:46:17 volumio volumio[15692]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 28 11:46:17 volumio volumio[15692]: info: Loading plugin "my_music"... Jan 28 11:46:17 volumio volumio[15692]: info: Loading plugin "mpd"... Jan 28 11:46:18 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 31. Jan 28 11:46:18 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 11:46:18 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 11:46:18 volumio go-librespot[15763]: go-librespot daemon starting... Jan 28 11:46:18 volumio go-librespot[15764]: time="2026-01-28T11:46:18+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 11:46:18 volumio go-librespot[15764]: time="2026-01-28T11:46:18+07:00" level=debug msg="app state loaded" Jan 28 11:46:18 volumio go-librespot[15764]: time="2026-01-28T11:46:18+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 11:46:18 volumio volumio[15692]: info: Loading plugin "upnp_browser"... Jan 28 11:46:18 volumio go-librespot[15764]: time="2026-01-28T11:46:18+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 11:46:18 volumio go-librespot[15764]: time="2026-01-28T11:46:18+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 28 11:46:18 volumio go-librespot[15764]: time="2026-01-28T11:46:18+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 28 11:46:18 volumio go-librespot[15764]: time="2026-01-28T11:46:18+07:00" level=info msg="zeroconf server listening on port 39555" Jan 28 11:46:19 volumio go-librespot[15764]: time="2026-01-28T11:46:19+07:00" level=debug msg="obtained new client token: AACvtDgFoHKy2gnxYSsezZ/EnhKK9I4RRSj2xMaSdnnRld/gC5Nj2OtaY3LVUMxLklLhb4Jy54ffT9/MzaSPmrKoKeJHtjBLOB88d1p0c4N6I5Zxak4JhffYf16zmu7NaJh/gO6sRJbv6b3ND0ICTp/DojAG+iG0kop+6sHmRm0d4HbilgZghFaSBBLrtbGVeabe7/3RKSWsRG6BeqUmizg/7Onu8xvzvW6vpW436xodNO97yvmEaibs" Jan 28 11:46:19 volumio go-librespot[15764]: time="2026-01-28T11:46:19+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 11:46:19 volumio go-librespot[15764]: time="2026-01-28T11:46:19+07:00" level=debug msg="completed keyexchange" Jan 28 11:46:19 volumio go-librespot[15764]: time="2026-01-28T11:46:19+07:00" level=debug msg="completed challenge" Jan 28 11:46:19 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 11:46:19 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 11:46:19 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 11:46:19 volumio go-librespot[15764]: time="2026-01-28T11:46:19+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 11:46:19 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 11:46:19 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 11:46:20 volumio sudo[15743]: pam_unix(sudo:session): session closed for user root Jan 28 11:46:21 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 11:46:21 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 11:46:21 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 11:46:21 volumio volumio[15692]: info: Starting UPNP Browser Jan 28 11:46:21 volumio volumio[15692]: info: Loading plugin "alarm-clock"... Jan 28 11:46:21 volumio volumio[15692]: info: Loading plugin "airplay_emulation"... Jan 28 11:46:21 volumio volumio[15692]: info: Starting Shairport Sync Jan 28 11:46:21 volumio volumio[15692]: info: Loading plugin "last_100"... Jan 28 11:46:21 volumio volumio[15692]: info: Loading plugin "webradio"... Jan 28 11:46:22 volumio volumio[15692]: info: Loading plugin "i2s_dacs"... Jan 28 11:46:22 volumio volumio[15692]: info: Loading plugin "volumiodiscovery"... Jan 28 11:46:22 volumio volumio[15692]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 28 11:46:22 volumio node[15692]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 28 11:46:22 volumio volumio[15692]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 11:46:22 volumio volumio[15692]: *** WARNING *** For more information see Jan 28 11:46:22 volumio volumio[15692]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 28 11:46:22 volumio volumio[15692]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 11:46:22 volumio volumio[15692]: *** WARNING *** For more information see Jan 28 11:46:22 volumio node[15692]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 11:46:22 volumio node[15692]: *** WARNING *** For more information see Jan 28 11:46:22 volumio node[15692]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 28 11:46:22 volumio node[15692]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 11:46:22 volumio node[15692]: *** WARNING *** For more information see Jan 28 11:46:22 volumio volumio[15692]: info: Applying required configuration parameters for plugin volumiodiscovery Jan 28 11:46:22 volumio volumio[15692]: info: Discovery: Started advertising with name: Volumio Jan 28 11:46:22 volumio volumio[15692]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 28 11:46:22 volumio volumio[15692]: info: Loading plugin "spop"... Jan 28 11:46:22 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 32. Jan 28 11:46:22 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 11:46:22 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 11:46:22 volumio go-librespot[15774]: go-librespot daemon starting... Jan 28 11:46:22 volumio go-librespot[15775]: time="2026-01-28T11:46:22+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 11:46:22 volumio go-librespot[15775]: time="2026-01-28T11:46:22+07:00" level=debug msg="app state loaded" Jan 28 11:46:22 volumio go-librespot[15775]: time="2026-01-28T11:46:22+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 11:46:23 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 11:46:23 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 11:46:23 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 11:46:23 volumio go-librespot[15775]: time="2026-01-28T11:46:23+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 28 11:46:23 volumio go-librespot[15775]: time="2026-01-28T11:46: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 28 11:46:23 volumio go-librespot[15775]: time="2026-01-28T11:46: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 28 11:46:23 volumio go-librespot[15775]: time="2026-01-28T11:46:23+07:00" level=info msg="zeroconf server listening on port 35791" Jan 28 11:46:23 volumio go-librespot[15775]: time="2026-01-28T11:46:23+07:00" level=debug msg="obtained new client token: AACSGCzM/vjZiGpBGnaMXHR788H+KpzkEp/eJIr0RWULpPCNaIhqBB46iiRKuvo1QSrYHZE+2YbEvlKZmptOTFt7ta3rN5MTf1cRXBtSR8MZs5KR7cEaD5aHG6fpP0TeNHO2CM6CaFqPMs5d9YXD18IH2cvS4AFViBZRu169kxrJp+TFAUt2cgx7rg02KhDT9W/YLgXxLXF3nY8SLZcvI/PwGc+JFrGlENmw9RdX4w8qAzCeaF4PCQ+weS0=" Jan 28 11:46:23 volumio go-librespot[15775]: time="2026-01-28T11:46:23+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 11:46:23 volumio go-librespot[15775]: time="2026-01-28T11:46:23+07:00" level=debug msg="completed keyexchange" Jan 28 11:46:23 volumio go-librespot[15775]: time="2026-01-28T11:46:23+07:00" level=debug msg="completed challenge" Jan 28 11:46:23 volumio go-librespot[15775]: time="2026-01-28T11:46:23+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 11:46:24 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 11:46:24 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 11:46:24 volumio volumio[15692]: info: Loading plugin "ytcr"... Jan 28 11:46:25 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 11:46:25 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 11:46:25 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 11:46:26 volumio volumio[15692]: info: Loading plugin "ytmusic"... Jan 28 11:46:27 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 33. Jan 28 11:46:27 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 11:46:27 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 11:46:27 volumio go-librespot[15782]: go-librespot daemon starting... Jan 28 11:46:27 volumio go-librespot[15783]: time="2026-01-28T11:46:27+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 11:46:27 volumio go-librespot[15783]: time="2026-01-28T11:46:27+07:00" level=debug msg="app state loaded" Jan 28 11:46:27 volumio go-librespot[15783]: time="2026-01-28T11:46:27+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 11:46:27 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 11:46:27 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 11:46:27 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 11:46:27 volumio volumio-remote-updater[628]: [2026-01-28 11:46:27] [connect] Successful connection Jan 28 11:46:27 volumio go-librespot[15783]: time="2026-01-28T11:46:27+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 11:46:27 volumio go-librespot[15783]: time="2026-01-28T11:46:27+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 28 11:46:27 volumio go-librespot[15783]: time="2026-01-28T11:46:27+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 28 11:46:27 volumio go-librespot[15783]: time="2026-01-28T11:46:27+07:00" level=info msg="zeroconf server listening on port 35507" Jan 28 11:46:27 volumio volumio[15692]: info: Loading plugin "outputs"... Jan 28 11:46:27 volumio volumio[15692]: info: Loading plugin "albumart"... Jan 28 11:46:28 volumio volumio[15692]: info: Plugin example_plugin is not enabled Jan 28 11:46:28 volumio volumio[15692]: info: Loading plugin "inputs"... Jan 28 11:46:28 volumio volumio[15692]: info: Loading plugin "updater_comm"... Jan 28 11:46:28 volumio go-librespot[15783]: time="2026-01-28T11:46:28+07:00" level=debug msg="obtained new client token: AADpXTImIPcSreyuDRg5Q7Z3qezIKSKOeAEpH2fi8YvIethD5IxEPo08LqPH//9Kvy2VKWAkWcNOuhmuKbGqFsD5sh3dHZ3tINdv5mGwSELMwNAl2aJQjk3wiK4vGDpwQHBJofj3z3FDhDCc0j/X6pqeciUPO2dxbq+thBr4c3oox0oewdfxLxMVN0EpzMrPvDjiLSkNYcQmnX36SivsxkRB/DViALx7/mYwVFdMSSamirQydx9jENXN" Jan 28 11:46:28 volumio go-librespot[15783]: time="2026-01-28T11:46:28+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 11:46:28 volumio go-librespot[15783]: time="2026-01-28T11:46:28+07:00" level=debug msg="completed keyexchange" Jan 28 11:46:28 volumio go-librespot[15783]: time="2026-01-28T11:46:28+07:00" level=debug msg="completed challenge" Jan 28 11:46:28 volumio volumio[15692]: info: Plugin mpdemulation is not enabled Jan 28 11:46:28 volumio volumio[15692]: info: Loading plugin "rest_api"... Jan 28 11:46:28 volumio go-librespot[15783]: time="2026-01-28T11:46:28+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 11:46:28 volumio volumio[15692]: info: Loading plugin "websocket"... Jan 28 11:46:28 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 11:46:28 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 11:46:28 volumio volumio[15692]: info: Starting Socket.io Server version 1.7.4 Jan 28 11:46:28 volumio volumio[15692]: info: Loading plugin "RoonBridge"... Jan 28 11:46:28 volumio volumio[15692]: info: Applying required configuration parameters for plugin RoonBridge Jan 28 11:46:28 volumio volumio[15692]: info: Loading i18n strings for locale en Jan 28 11:46:28 volumio volumio[15692]: Updating browse sources language Jan 28 11:46:28 volumio volumio[15692]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 11:46:29 volumio volumio[15804]: Forking 3 albumart workers Jan 28 11:46:29 volumio volumio[15692]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 28 11:46:29 volumio volumio[15692]: info: CoreCommandRouter::initPlayerControls Jan 28 11:46:29 volumio volumio[15692]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:46:29 volumio volumio[15692]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:46:29 volumio volumio[15692]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:46:29 volumio volumio[15692]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:46:29 volumio volumio[15692]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:46:29 volumio volumio[15692]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:46:29 volumio volumio[15692]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:46:29 volumio volumio[15692]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:46:29 volumio volumio[15692]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 28 11:46:29 volumio volumio[15692]: Express server listening on port 3000 Jan 28 11:46:29 volumio volumio[15692]: [Metrics] WebUI: 16s 299.08ms Jan 28 11:46:29 volumio volumio[15692]: info: CoreStateMachine::resetVolumioState Jan 28 11:46:29 volumio volumio[15692]: info: CoreStateMachine::getcurrentVolume Jan 28 11:46:29 volumio volumio[15692]: info: CoreCommandRouter::volumioRetrievevolume Jan 28 11:46:29 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 11:46:29 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 11:46:29 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 11:46:29 volumio sudo[15848]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 28 11:46:29 volumio sudo[15848]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:46:29 volumio sudo[15850]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 28 11:46:29 volumio sudo[15850]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:46:29 volumio sudo[15848]: pam_unix(sudo:session): session closed for user root Jan 28 11:46:29 volumio sudo[15850]: pam_unix(sudo:session): session closed for user root Jan 28 11:46:29 volumio volumio[15692]: info: Volumio Network Manager: Network status updated: 1 Jan 28 11:46:29 volumio volumio[15692]: info: VolumeController:: Volume=100 Mute =false Jan 28 11:46:29 volumio volumio[15692]: info: CoreStateMachine::pushState Jan 28 11:46:29 volumio volumio[15692]: info: CorePlayQueue::getTrack 0 Jan 28 11:46:29 volumio volumio[15692]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 28 11:46:29 volumio volumio[15692]: info: CoreCommandRouter::volumioPushState Jan 28 11:46:29 volumio volumio[15692]: info: CoreStateMachine::updateTrackBlock Jan 28 11:46:29 volumio volumio[15692]: info: CorePlayQueue::getTrackBlock Jan 28 11:46:29 volumio volumio[15692]: info: CoreCommandRouter::volumioRetrievevolume Jan 28 11:46:29 volumio volumio-remote-updater[628]: [2026-01-28 11:46:29] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1769575587 101 Jan 28 11:46:29 volumio volumio[15692]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 1 Jan 28 11:46:30 volumio volumio[15692]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 11:46:30 volumio volumio[15692]: info: Reloading queue from file Jan 28 11:46:30 volumio volumio[15692]: info: CoreStateMachine::setRepeat null single undefined Jan 28 11:46:30 volumio volumio[15692]: info: CoreStateMachine::pushState Jan 28 11:46:30 volumio volumio[15692]: info: CorePlayQueue::getTrack 0 Jan 28 11:46:30 volumio volumio[15692]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 28 11:46:30 volumio volumio[15692]: info: CoreCommandRouter::volumioPushState Jan 28 11:46:30 volumio volumio[15692]: info: CoreStateMachine::setRandom null Jan 28 11:46:30 volumio volumio[15692]: info: CoreStateMachine::pushState Jan 28 11:46:30 volumio volumio[15692]: info: CorePlayQueue::getTrack 0 Jan 28 11:46:30 volumio volumio[15692]: info: CoreCommandRouter::volumioPushState Jan 28 11:46:30 volumio volumio[15692]: info: Setting Device type: Raspberry PI Jan 28 11:46:30 volumio volumio[15692]: info: Completed loading Core Plugins Jan 28 11:46:30 volumio volumio[15692]: info: Preparing to generate the ALSA configuration file Jan 28 11:46:30 volumio volumio[15692]: info: VolumeController:: Volume=100 Mute =false Jan 28 11:46:30 volumio volumio[15692]: info: CoreStateMachine::pushState Jan 28 11:46:30 volumio volumio[15692]: info: CorePlayQueue::getTrack 0 Jan 28 11:46:30 volumio volumio[15692]: info: CoreCommandRouter::volumioPushState Jan 28 11:46:30 volumio volumio[15692]: info: Asound.conf file unchanged, so no further update is needed Jan 28 11:46:30 volumio volumio[15692]: info: Output device has changed, restarting MPD Jan 28 11:46:30 volumio volumio[15692]: info: Output device has changed, restarting Shairport Sync Jan 28 11:46:30 volumio volumio[15692]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:46:30 volumio volumio[15692]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 11:46:30 volumio sudo[15865]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Jan 28 11:46:30 volumio sudo[15865]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:46:30 volumio sudo[15867]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 28 11:46:30 volumio sudo[15867]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:46:30 volumio volumio[15692]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 28 11:46:30 volumio volumio[15692]: info: ___________ START PLUGINS ___________ Jan 28 11:46:30 volumio sudo[15867]: pam_unix(sudo:session): session closed for user root Jan 28 11:46:30 volumio sudo[15869]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 28 11:46:30 volumio sudo[15869]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:46:30 volumio volumio[15692]: info: ControllerMpd::onStart: Initializing MPD Jan 28 11:46:30 volumio volumio[15692]: info: Creating MPD Configuration file Jan 28 11:46:30 volumio sudo[15865]: pam_unix(sudo:session): session closed for user root Jan 28 11:46:30 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Jan 28 11:46:30 volumio volumio[15692]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 28 11:46:30 volumio volumio[15692]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 11:46:30 volumio volumio[15692]: info: [1769575590636] CoreMusicLibrary::Adding element Media Servers Jan 28 11:46:30 volumio volumio[15692]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 11:46:30 volumio sudo[15878]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 28 11:46:30 volumio sudo[15878]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:46:30 volumio sudo[15878]: pam_unix(sudo:session): session closed for user root Jan 28 11:46:30 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 28 11:46:30 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 28 11:46:30 volumio systemd[1]: mpd.service: Consumed 7.289s CPU time. Jan 28 11:46:30 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 28 11:46:30 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 28 11:46:30 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 28 11:46:30 volumio volumio[15692]: info: UPNP Browser: Client initialized successfully Jan 28 11:46:30 volumio sudo[15880]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 28 11:46:30 volumio sudo[15880]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:46:30 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 28 11:46:30 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 28 11:46:30 volumio volumio[15692]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:46:30 volumio volumio[15692]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 11:46:30 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 28 11:46:30 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 28 11:46:30 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 28 11:46:30 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 28 11:46:30 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 28 11:46:30 volumio volumio[15692]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 28 11:46:30 volumio volumio[15692]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:46:30 volumio volumio[15692]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 11:46:31 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 28 11:46:31 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 28 11:46:31 volumio volumio[15692]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 28 11:46:31 volumio volumio[15692]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 11:46:31 volumio volumio[15692]: info: [1769575591074] CoreMusicLibrary::Adding element Last_100 Jan 28 11:46:31 volumio volumio[15692]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 11:46:31 volumio volumio[15692]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 11:46:31 volumio volumio[15692]: info: [1769575591092] CoreMusicLibrary::Adding element Webradio Jan 28 11:46:31 volumio volumio[15692]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 11:46:31 volumio volumio[15692]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 28 11:46:31 volumio volumio[15692]: info: Initializing BBC Radios Jan 28 11:46:31 volumio volumio[15692]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 28 11:46:31 volumio volumio[15692]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 11:46:31 volumio volumio[15692]: info: Creating Spotify config file Jan 28 11:46:31 volumio volumio[15692]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:46:31 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 11:46:31 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 11:46:31 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 11:46:31 volumio sudo[15894]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 28 11:46:31 volumio sudo[15894]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jan 28 11:46:31 volumio sudo[15894]: pam_unix(sudo:session): session closed for user root Jan 28 11:46:31 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 34. Jan 28 11:46:31 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 11:46:31 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 11:46:31 volumio go-librespot[15910]: go-librespot daemon starting... Jan 28 11:46:31 volumio go-librespot[15911]: time="2026-01-28T11:46:31+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 11:46:32 volumio volumio[15814]: Starting albumart workers Jan 28 11:46:32 volumio go-librespot[15911]: time="2026-01-28T11:46:32+07:00" level=info msg="zeroconf server listening on port 39549" Jan 28 11:46:32 volumio volumio[15816]: Starting albumart workers Jan 28 11:46:32 volumio volumio[15815]: Starting albumart workers Jan 28 11:46:32 volumio volumio[15692]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 11:46:32 volumio volumio[15692]: info: [1769575592773] CoreMusicLibrary::Adding element YouTube Music Jan 28 11:46:32 volumio volumio[15692]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 11:46:32 volumio volumio[15692]: Cannot find translation for source YouTube Music Jan 28 11:46:32 volumio volumio[15692]: info: Volumio Calling Home Jan 28 11:46:32 volumio sudo[15919]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Jan 28 11:46:32 volumio sudo[15919]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:46:33 volumio sudo[15919]: pam_unix(sudo:session): session closed for user root Jan 28 11:46:33 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 11:46:33 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 11:46:33 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 11:46:33 volumio volumio[15692]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Jan 28 11:46:33 volumio volumio[15692]: info: Discovery: Found device Volumio Jan 28 11:46:33 volumio volumio[15692]: info: CoreCommandRouter::volumioGetState Jan 28 11:46:33 volumio volumio[15692]: info: CorePlayQueue::getTrack 0 Jan 28 11:46:33 volumio volumio[15692]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Jan 28 11:46:33 volumio volumio[15692]: info: Discovery: Found device Volumio Jan 28 11:46:33 volumio volumio[15692]: info: CoreCommandRouter::volumioGetState Jan 28 11:46:33 volumio volumio[15692]: info: CorePlayQueue::getTrack 0 Jan 28 11:46:33 volumio volumio[15692]: info: MPD Permissions set Jan 28 11:46:33 volumio volumio[15692]: info: MPD Permissions set Jan 28 11:46:33 volumio volumio[15692]: info: Upmpdcli Daemon Started Jan 28 11:46:33 volumio volumio[15692]: info: Volumio called home Jan 28 11:46:33 volumio volumio[15692]: info: Spotify config file written Jan 28 11:46:33 volumio volumio[15692]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Jan 28 11:46:34 volumio volumio[15692]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:46:34 volumio volumio[15692]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:46:34 volumio volumio[15692]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:46:34 volumio volumio[15692]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:46:34 volumio volumio[15692]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:46:34 volumio volumio[15692]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:46:34 volumio volumio[15692]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:46:34 volumio volumio[15692]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:46:34 volumio sudo[15925]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jan 28 11:46:34 volumio sudo[15925]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:46:34 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Jan 28 11:46:34 volumio volumio[15692]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 11:46:34 volumio volumio[15692]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:46:34 volumio systemd[1]: go-librespot-daemon.service: Killing process 15916 (go-librespot) with signal SIGKILL. Jan 28 11:46:34 volumio volumio[15692]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:46:34 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Jan 28 11:46:34 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 11:46:34 volumio volumio[15692]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:46:34 volumio volumio[15692]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:46:34 volumio volumio[15692]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:46:34 volumio volumio[15692]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:46:34 volumio volumio[15692]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:46:34 volumio volumio[15692]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:46:34 volumio volumio[15692]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:46:34 volumio volumio[15692]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 11:46:34 volumio volumio[15692]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:46:34 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 11:46:34 volumio go-librespot[15935]: go-librespot daemon starting... Jan 28 11:46:34 volumio sudo[15925]: pam_unix(sudo:session): session closed for user root Jan 28 11:46:34 volumio volumio[15692]: info: No need to fix Spotify hosts Jan 28 11:46:34 volumio go-librespot[15940]: time="2026-01-28T11:46:34+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 11:46:34 volumio go-librespot[15940]: time="2026-01-28T11:46:34+07:00" level=debug msg="app state loaded" Jan 28 11:46:34 volumio go-librespot[15940]: time="2026-01-28T11:46:34+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 11:46:35 volumio go-librespot[15940]: time="2026-01-28T11:46:35+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 11:46:35 volumio go-librespot[15940]: time="2026-01-28T11:46:35+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 28 11:46:35 volumio go-librespot[15940]: time="2026-01-28T11:46:35+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 28 11:46:35 volumio go-librespot[15940]: time="2026-01-28T11:46:35+07:00" level=info msg="zeroconf server listening on port 37231" Jan 28 11:46:35 volumio go-librespot[15940]: time="2026-01-28T11:46:35+07:00" level=debug msg="obtained new client token: AADac7nWKaWzNJwNTPo8goE7n/pF+xKkkl9J8tpaClQ6oaFLj3D1wUp+GPwdMHlQEFdbiKNToFVTiGfqY94OJ84yq7p61oaR9XGHGjjpn6vGozhm435MoD6IjgeGWg5DL1tyNUrRf/8V8CkrpLRzfPN+FHwNhJzmpPRDD42H6e8CzGKuHVpMFhXoianJbGua5m/X5T7zUbEl1vzXj9CUorqA6pm9w+uC9wrOnaYnmDe73PqDbwovUJD2bOg=" Jan 28 11:46:35 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 11:46:35 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 11:46:35 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 11:46:35 volumio volumio[15692]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 28 11:46:35 volumio volumio[15692]: SPOTIFY: BQBKlTn3VY8sef4jyPl7Oir2u6KTQJ2CEM0WATRk-M9hq5u4dLtj8q8iEFbKetJRSq-KvYplu8NYBPuHxBVa4A44ZkJiG_W4ZRopAb8nukZonl4yEI-9lRpcj9GWDD4z_PS9IZtwRRjPax0DhqAAt7TW1i-IPITyX4qQ2rw2uNrCbQEPuLZP2_XosAMveuP7hBC6TJTCpVvH0ouXUS75OuQK0elAOaGg0F23j4FbCSit4nwAgREQyuWl1cXWa4WgHMsdrua_DIQiUmE20gkdwkJW3Mm41Z4N_8hwEsqQsf7RQ4B881FpH2vN Jan 28 11:46:35 volumio volumio[15692]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 28 11:46:35 volumio volumio[15692]: info: New Spotify access token = BQBKlTn3VY8sef4jyPl7Oir2u6KTQJ2CEM0WATRk-M9hq5u4dLtj8q8iEFbKetJRSq-KvYplu8NYBPuHxBVa4A44ZkJiG_W4ZRopAb8nukZonl4yEI-9lRpcj9GWDD4z_PS9IZtwRRjPax0DhqAAt7TW1i-IPITyX4qQ2rw2uNrCbQEPuLZP2_XosAMveuP7hBC6TJTCpVvH0ouXUS75OuQK0elAOaGg0F23j4FbCSit4nwAgREQyuWl1cXWa4WgHMsdrua_DIQiUmE20gkdwkJW3Mm41Z4N_8hwEsqQsf7RQ4B881FpH2vN Jan 28 11:46:35 volumio volumio[15692]: info: Spotify credentials grant success - running version from March 24, 2019 Jan 28 11:46:35 volumio go-librespot[15940]: time="2026-01-28T11:46:35+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 11:46:35 volumio volumio[15692]: info: Starting Shairport Sync Jan 28 11:46:35 volumio volumio[15692]: info: Starting Shairport Sync Jan 28 11:46:35 volumio go-librespot[15940]: time="2026-01-28T11:46:35+07:00" level=debug msg="completed keyexchange" Jan 28 11:46:35 volumio go-librespot[15940]: time="2026-01-28T11:46:35+07:00" level=debug msg="completed challenge" Jan 28 11:46:35 volumio volumio[15692]: info: Starting Shairport Sync Jan 28 11:46:35 volumio sudo[15965]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 28 11:46:35 volumio sudo[15965]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:46:35 volumio sudo[15967]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 28 11:46:35 volumio sudo[15967]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:46:35 volumio go-librespot[15940]: time="2026-01-28T11:46:35+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 11:46:35 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 11:46:35 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 11:46:35 volumio sudo[15971]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 28 11:46:35 volumio sudo[15971]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:46:35 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 28 11:46:35 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Jan 28 11:46:35 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 28 11:46:35 volumio systemd[1]: shairport-sync.service: Consumed 2.343s CPU time. Jan 28 11:46:35 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 28 11:46:35 volumio sudo[15965]: pam_unix(sudo:session): session closed for user root Jan 28 11:46:35 volumio sudo[15967]: pam_unix(sudo:session): session closed for user root Jan 28 11:46:36 volumio volumio[15692]: info: Shairport-Sync Started Jan 28 11:46:36 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 28 11:46:36 volumio volumio[15692]: Error adding Membership: Error: addMembership EINVAL Jan 28 11:46:36 volumio volumio[15692]: info: Shairport-Sync Started Jan 28 11:46:36 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Jan 28 11:46:36 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 28 11:46:36 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 28 11:46:36 volumio sudo[15971]: pam_unix(sudo:session): session closed for user root Jan 28 11:46:36 volumio volumio[15692]: info: Shairport-Sync Started Jan 28 11:46:36 volumio volumio[15692]: info: CoreCommandRouter::volumioGetState Jan 28 11:46:36 volumio volumio[15692]: info: CorePlayQueue::getTrack 0 Jan 28 11:46:36 volumio volumio[15692]: SPOTIFY: User informations: {"country":"PK","display_name":"215mmgea6kss3jxeqsqdquvji","email":"linh.ngotran@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/215mmgea6kss3jxeqsqdquvji"},"followers":{"href":null,"total":1},"href":"https://api.spotify.com/v1/users/215mmgea6kss3jxeqsqdquvji","id":"215mmgea6kss3jxeqsqdquvji","images":[],"product":"premium","type":"user","uri":"spotify:user:215mmgea6kss3jxeqsqdquvji"} Jan 28 11:46:36 volumio volumio[15692]: info: Spotify Successfully logged in Jan 28 11:46:36 volumio volumio[15692]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 11:46:36 volumio volumio[15692]: info: [1769575596446] CoreMusicLibrary::Adding element Spotify Jan 28 11:46:36 volumio volumio[15692]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 11:46:36 volumio volumio[15692]: Cannot find translation for source YouTube Music Jan 28 11:46:36 volumio volumio[15692]: Cannot find translation for source Spotify Jan 28 11:46:37 volumio volumio[15692]: info: [yt-cast-receiver] DIAL server listening on port 8098 Jan 28 11:46:37 volumio volumio[15692]: info: CoreCommandRouter::volumioRetrievevolume Jan 28 11:46:37 volumio volumio[15692]: info: VolumeController:: Volume=100 Mute =false Jan 28 11:46:37 volumio volumio[15692]: info: CoreCommandRouter::volumioGetState Jan 28 11:46:37 volumio volumio[15692]: info: CorePlayQueue::getTrack 0 Jan 28 11:46:37 volumio volumio[15692]: info: CoreStateMachine::pushState Jan 28 11:46:37 volumio volumio[15692]: info: CorePlayQueue::getTrack 0 Jan 28 11:46:37 volumio volumio[15692]: info: CoreCommandRouter::volumioPushState Jan 28 11:46:37 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 11:46:37 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 11:46:37 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 11:46:38 volumio volumio[15692]: info: go-librespot daemon successfully initialized Jan 28 11:46:38 volumio mpd[15909]: 2026-01-28T11:46:38 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 28 11:46:38 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Jan 28 11:46:38 volumio systemd[1]: Started mpd.service - Music Player Daemon. Jan 28 11:46:38 volumio sudo[15869]: pam_unix(sudo:session): session closed for user root Jan 28 11:46:38 volumio sudo[15880]: pam_unix(sudo:session): session closed for user root Jan 28 11:46:39 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 11:46:39 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 11:46:39 volumio go-librespot[16008]: go-librespot daemon starting... Jan 28 11:46:39 volumio go-librespot[16011]: time="2026-01-28T11:46:39+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 11:46:39 volumio go-librespot[16011]: time="2026-01-28T11:46:39+07:00" level=debug msg="app state loaded" Jan 28 11:46:39 volumio go-librespot[16011]: time="2026-01-28T11:46:39+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 11:46:39 volumio volumio[15692]: error: MPD error: The expression evaluated to a falsy value: Jan 28 11:46:39 volumio volumio[15692]: assert.ok(self.idling) Jan 28 11:46:39 volumio volumio[15692]: error: The expression evaluated to a falsy value: Jan 28 11:46:39 volumio volumio[15692]: assert.ok(self.idling) Jan 28 11:46:39 volumio volumio[15692]: error: updateQueue error: null Jan 28 11:46:39 volumio volumio[15692]: info: MPD running with PID15909 Jan 28 11:46:39 volumio volumio[15692]: ,establishing connection Jan 28 11:46:39 volumio volumio[15692]: info: Completed starting Core Plugins Jan 28 11:46:39 volumio volumio[15692]: info: ------------------------------------------- Jan 28 11:46:39 volumio volumio[15692]: info: ----- MyVolumio plugins startup ---- Jan 28 11:46:39 volumio volumio[15692]: info: ------------------------------------------- Jan 28 11:46:39 volumio volumio[15692]: info: [MyVolumio PluginManager] Fetching plans data.... Jan 28 11:46:39 volumio volumio[15692]: error: updateQueue error: null Jan 28 11:46:39 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 11:46:39 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 11:46:39 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 11:46:39 volumio go-librespot[16011]: time="2026-01-28T11:46:39+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 11:46:39 volumio go-librespot[16011]: time="2026-01-28T11:46:39+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 28 11:46:39 volumio go-librespot[16011]: time="2026-01-28T11:46:39+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 28 11:46:39 volumio go-librespot[16011]: time="2026-01-28T11:46:39+07:00" level=info msg="zeroconf server listening on port 33917" Jan 28 11:46:39 volumio go-librespot[16011]: time="2026-01-28T11:46:39+07:00" level=debug msg="obtained new client token: AADunbejnMBEB8J2Bxp/aoWk6xY+t8oCJAoSAJG4rKr0WzPB2ZKQkLk1A1jbZIHmNPs5ftlFLUwrU4GkPDZjO4Kq6LYqzHTnYZRGQ60L6xHHTwmrPACzZ2zjOmbgPV/RehjEC9ldWpzeYrpudK9RoySQc6vckh1Baq/zWePXN3EnfbNNwuJ6LnckTHsVJZLB/kosPfU3vf7jkhSPX07CsZnQSN2cqWnHUf9ETL7QTCmKd0wL52imvqJ/lhw=" Jan 28 11:46:40 volumio go-librespot[16011]: time="2026-01-28T11:46:40+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 11:46:40 volumio go-librespot[16011]: time="2026-01-28T11:46:40+07:00" level=debug msg="completed keyexchange" Jan 28 11:46:40 volumio go-librespot[16011]: time="2026-01-28T11:46:40+07:00" level=debug msg="completed challenge" Jan 28 11:46:40 volumio go-librespot[16011]: time="2026-01-28T11:46:40+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 11:46:40 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 11:46:40 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 11:46:41 volumio volumio[15692]: info: Initializing connection to go-librespot Websocket Jan 28 11:46:41 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 11:46:41 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 11:46:41 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 11:46:41 volumio volumio[15692]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 28 11:46:43 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 11:46:43 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 11:46:43 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 11:46:43 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Jan 28 11:46:43 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 11:46:43 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 11:46:43 volumio go-librespot[16019]: go-librespot daemon starting... Jan 28 11:46:43 volumio go-librespot[16020]: time="2026-01-28T11:46:43+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 11:46:43 volumio go-librespot[16020]: time="2026-01-28T11:46:43+07:00" level=debug msg="app state loaded" Jan 28 11:46:43 volumio go-librespot[16020]: time="2026-01-28T11:46:43+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 11:46:44 volumio go-librespot[16020]: time="2026-01-28T11:46:44+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 11:46:44 volumio go-librespot[16020]: time="2026-01-28T11:46:44+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 28 11:46:44 volumio go-librespot[16020]: time="2026-01-28T11:46:44+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 28 11:46:44 volumio go-librespot[16020]: time="2026-01-28T11:46:44+07:00" level=info msg="zeroconf server listening on port 42385" Jan 28 11:46:44 volumio volumio[15692]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Jan 28 11:46:44 volumio go-librespot[16020]: time="2026-01-28T11:46:44+07:00" level=debug msg="obtained new client token: AABojX10YbwtZL6eHiE2PHqDKo3HmssM2q+0yUXks4dEbSmvkMaGNykFzng1Z0yjgXTtLxHYZahkVElfCWJgLTtC0mkhbqLDRGp38H3UX8SkT+ZAAMOdQn7S4CQ7PiizIUnLolagrpAuTyp31z62MUFZEH73vmWuEoyxiSrZKx4Y6nJMCISEE45/WV9TihIeK/rRttOEWr0EV7I9N1rVoRpe7+B9zuhEno6qn7LFhBUU2q/s9Re/KbIh" Jan 28 11:46:44 volumio go-librespot[16020]: time="2026-01-28T11:46:44+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 11:46:44 volumio volumio[15692]: info: Initializing connection to go-librespot Websocket Jan 28 11:46:44 volumio go-librespot[16020]: time="2026-01-28T11:46:44+07:00" level=debug msg="new websocket client" Jan 28 11:46:44 volumio volumio[15692]: info: Connection to go-librespot Websocket established Jan 28 11:46:44 volumio go-librespot[16020]: time="2026-01-28T11:46:44+07:00" level=debug msg="completed keyexchange" Jan 28 11:46:44 volumio go-librespot[16020]: time="2026-01-28T11:46:44+07:00" level=debug msg="completed challenge" Jan 28 11:46:44 volumio go-librespot[16020]: time="2026-01-28T11:46:44+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 11:46:44 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 11:46:44 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 11:46:44 volumio volumio[15692]: info: Connection to go-librespot Websocket closed Jan 28 11:46:45 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 11:46:45 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 11:46:45 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 11:46:47 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 11:46:47 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 11:46:47 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 11:46:47 volumio volumio[15692]: info: Getting Spotify volume Jan 28 11:46:47 volumio volumio[15692]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 28 11:46:47 volumio volumio[15692]: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 28 11:46:47 volumio volumio[15692]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Jan 28 11:46:47 volumio volumio[15692]: errno: -111, Jan 28 11:46:47 volumio volumio[15692]: code: 'ECONNREFUSED', Jan 28 11:46:47 volumio volumio[15692]: syscall: 'connect', Jan 28 11:46:47 volumio volumio[15692]: address: '127.0.0.1', Jan 28 11:46:47 volumio volumio[15692]: port: 9879, Jan 28 11:46:47 volumio volumio[15692]: response: undefined Jan 28 11:46:47 volumio volumio[15692]: } Jan 28 11:46:47 volumio volumio[15692]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 28 11:46:47 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Jan 28 11:46:47 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 11:46:47 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 11:46:47 volumio go-librespot[16039]: go-librespot daemon starting... Jan 28 11:46:47 volumio go-librespot[16040]: time="2026-01-28T11:46:47+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 11:46:47 volumio go-librespot[16040]: time="2026-01-28T11:46:47+07:00" level=debug msg="app state loaded" Jan 28 11:46:47 volumio go-librespot[16040]: time="2026-01-28T11:46:47+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 11:46:48 volumio go-librespot[16040]: time="2026-01-28T11:46:48+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 11:46:48 volumio go-librespot[16040]: time="2026-01-28T11:46:48+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 28 11:46:48 volumio go-librespot[16040]: time="2026-01-28T11:46:48+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 28 11:46:48 volumio go-librespot[16040]: time="2026-01-28T11:46:48+07:00" level=info msg="zeroconf server listening on port 43185" Jan 28 11:46:48 volumio go-librespot[16040]: time="2026-01-28T11:46:48+07:00" level=debug msg="obtained new client token: AADs1nQcjWlATelzOv3tusdt4GYvoT2KrXpbKNN8zXGQkYcnS1pbZU1xBSlBSaTh/88rJvv0Fj7SQgGAGdnjGqPXiPf5AA+Id/axjElxpnDttfZzWRo19+bsYEmtQPsiHK+V/8SCWBJmNU+ItTU7ZGimZ0W0mLDvlJvVafE/mhdCOipbEddiBYrafJCeio7eR4gLX6RKZo0BwoaJIl3W3iFHLY+FtRDsQCpIQZ48Xz74RkDFCm2cUGa5c8Y=" Jan 28 11:46:48 volumio go-librespot[16040]: time="2026-01-28T11:46:48+07:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:4070, retrying with a different AP" error="dial tcp 104.199.241.202:4070: connect: connection refused" Jan 28 11:46:48 volumio go-librespot[16040]: time="2026-01-28T11:46:48+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Jan 28 11:46:48 volumio go-librespot[16040]: time="2026-01-28T11:46:48+07:00" level=debug msg="completed keyexchange" Jan 28 11:46:48 volumio go-librespot[16040]: time="2026-01-28T11:46:48+07:00" level=debug msg="completed challenge" Jan 28 11:46:48 volumio go-librespot[16040]: time="2026-01-28T11:46:48+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 11:46:48 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 11:46:48 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 11:46:49 volumio sudo[16064]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-01-28 11:45' Jan 28 11:46:49 volumio sudo[16064]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:46:49 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 11:46:49 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 11:46:49 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 PRETTY_NAME="Raspbian GNU/Linux 12 (bookworm)" NAME="Raspbian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="b05a530ca81d05eb9a84d0acf82089f0a60b8ee6" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="4ad85e2147d972f0b838d33c21382d2d813b2ae8" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu Dec 25 09:13:19 UTC 2025" VOLUMIO_VERSION="4.084" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="792f09af7488531aecd1aadcaa9b175e"