Feb 08 03:44:00 volumio go-librespot[19069]: time="2026-02-08T03:44:00+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]" Feb 08 03:44:00 volumio go-librespot[19069]: time="2026-02-08T03:44:00+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]" Feb 08 03:44:00 volumio go-librespot[19069]: time="2026-02-08T03:44:00+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]" Feb 08 03:44:00 volumio volumio[18976]: info: Loading plugin "outputs"... Feb 08 03:44:00 volumio go-librespot[19069]: time="2026-02-08T03:44:00+07:00" level=info msg="zeroconf server listening on port 42503" Feb 08 03:44:00 volumio volumio[18976]: info: Loading plugin "albumart"... Feb 08 03:44:00 volumio volumio[18976]: info: Plugin example_plugin is not enabled Feb 08 03:44:00 volumio volumio[18976]: info: Loading plugin "inputs"... Feb 08 03:44:00 volumio volumio[18976]: info: Loading plugin "updater_comm"... Feb 08 03:44:00 volumio go-librespot[19069]: time="2026-02-08T03:44:00+07:00" level=debug msg="obtained new client token: AAAegYdwZJyYx4WEgPeUb8/n41nBT76e48NTVxdG7EmlBSVLgMMWhjl3Pth+KTs8MT+SwgBv/5Oh9bkF4ZQ5ctpKDatOhwQ9RuKh2Vl1DG3NKyrvfx8ZZhZQpXIhnRlJHt1ggRLsTjRznzyybNuEfi9lfyMp+DiWPkrHsAmhsfJLAB+pdGMDpTO6V1v/nNQdB5na+Yrl/AunBzFL03s8XhUd9+aCR4ScM/sE9CrxxS4nBI2Hge0lNFsqvw==" Feb 08 03:44:00 volumio go-librespot[19069]: time="2026-02-08T03:44:00+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 08 03:44:00 volumio volumio[18976]: info: Plugin mpdemulation is not enabled Feb 08 03:44:00 volumio volumio[18976]: info: Loading plugin "rest_api"... Feb 08 03:44:00 volumio go-librespot[19069]: time="2026-02-08T03:44:00+07:00" level=debug msg="completed keyexchange" Feb 08 03:44:00 volumio go-librespot[19069]: time="2026-02-08T03:44:00+07:00" level=debug msg="completed challenge" Feb 08 03:44:00 volumio volumio[18976]: info: Loading plugin "websocket"... Feb 08 03:44:00 volumio go-librespot[19069]: time="2026-02-08T03:44:00+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 08 03:44:00 volumio volumio[18976]: info: Starting Socket.io Server version 1.7.4 Feb 08 03:44:00 volumio volumio[18976]: info: Loading plugin "RoonBridge"... Feb 08 03:44:00 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 08 03:44:00 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 08 03:44:01 volumio volumio[18976]: info: Applying required configuration parameters for plugin RoonBridge Feb 08 03:44:01 volumio volumio[18976]: info: Loading i18n strings for locale en Feb 08 03:44:01 volumio volumio[18976]: Updating browse sources language Feb 08 03:44:01 volumio volumio[18976]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 08 03:44:01 volumio volumio[19091]: Forking 3 albumart workers Feb 08 03:44:01 volumio volumio[18976]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 08 03:44:01 volumio volumio[18976]: info: CoreCommandRouter::initPlayerControls Feb 08 03:44:01 volumio volumio[18976]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 03:44:01 volumio volumio[18976]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 03:44:01 volumio volumio[18976]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 03:44:01 volumio volumio[18976]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 03:44:01 volumio volumio[18976]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 03:44:01 volumio volumio[18976]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 03:44:01 volumio volumio[18976]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 03:44:01 volumio volumio[18976]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 03:44:01 volumio volumio[18976]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 08 03:44:01 volumio volumio[18976]: Express server listening on port 3000 Feb 08 03:44:01 volumio volumio[18976]: [Metrics] WebUI: 16s 164.53ms Feb 08 03:44:01 volumio volumio[18976]: info: CoreStateMachine::resetVolumioState Feb 08 03:44:01 volumio volumio[18976]: info: CoreStateMachine::getcurrentVolume Feb 08 03:44:01 volumio volumio[18976]: info: CoreCommandRouter::volumioRetrievevolume Feb 08 03:44:01 volumio sudo[19134]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 08 03:44:01 volumio sudo[19134]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 03:44:01 volumio volumio[18976]: info: Volumio Network Manager: Network status updated: 1 Feb 08 03:44:01 volumio sudo[19136]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 08 03:44:01 volumio sudo[19136]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 03:44:01 volumio sudo[19134]: pam_unix(sudo:session): session closed for user root Feb 08 03:44:01 volumio sudo[19136]: pam_unix(sudo:session): session closed for user root Feb 08 03:44:02 volumio volumio[18976]: info: VolumeController:: Volume=100 Mute =false Feb 08 03:44:02 volumio volumio[18976]: info: CoreStateMachine::pushState Feb 08 03:44:02 volumio volumio[18976]: info: CorePlayQueue::getTrack 0 Feb 08 03:44:02 volumio volumio[18976]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 08 03:44:02 volumio volumio[18976]: info: CoreCommandRouter::volumioPushState Feb 08 03:44:02 volumio volumio[18976]: info: CoreStateMachine::updateTrackBlock Feb 08 03:44:02 volumio volumio[18976]: info: CorePlayQueue::getTrackBlock Feb 08 03:44:02 volumio volumio[18976]: info: CoreCommandRouter::volumioRetrievevolume Feb 08 03:44:02 volumio volumio-remote-updater[643]: [2026-02-08 03:44:02] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1770497039 101 Feb 08 03:44:02 volumio volumio[18976]: 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 Feb 08 03:44:02 volumio volumio[18976]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 08 03:44:02 volumio volumio[18976]: info: Reloading queue from file Feb 08 03:44:02 volumio volumio[18976]: info: CoreStateMachine::setRepeat null single undefined Feb 08 03:44:02 volumio volumio[18976]: info: CoreStateMachine::pushState Feb 08 03:44:02 volumio volumio[18976]: info: CorePlayQueue::getTrack 0 Feb 08 03:44:02 volumio volumio[18976]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 08 03:44:02 volumio volumio[18976]: info: CoreCommandRouter::volumioPushState Feb 08 03:44:02 volumio volumio[18976]: info: CoreStateMachine::setRandom null Feb 08 03:44:02 volumio volumio[18976]: info: CoreStateMachine::pushState Feb 08 03:44:02 volumio volumio[18976]: info: CorePlayQueue::getTrack 0 Feb 08 03:44:02 volumio volumio[18976]: info: CoreCommandRouter::volumioPushState Feb 08 03:44:02 volumio volumio[18976]: info: Setting Device type: Raspberry PI Feb 08 03:44:02 volumio volumio[18976]: info: Completed loading Core Plugins Feb 08 03:44:02 volumio volumio[18976]: info: Preparing to generate the ALSA configuration file Feb 08 03:44:02 volumio volumio[18976]: info: VolumeController:: Volume=100 Mute =false Feb 08 03:44:02 volumio volumio[18976]: info: CoreStateMachine::pushState Feb 08 03:44:02 volumio volumio[18976]: info: CorePlayQueue::getTrack 0 Feb 08 03:44:02 volumio volumio[18976]: info: CoreCommandRouter::volumioPushState Feb 08 03:44:02 volumio volumio[18976]: info: Asound.conf file unchanged, so no further update is needed Feb 08 03:44:02 volumio volumio[18976]: info: Output device has changed, restarting MPD Feb 08 03:44:02 volumio volumio[18976]: info: Output device has changed, restarting Shairport Sync Feb 08 03:44:02 volumio volumio[18976]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 03:44:02 volumio volumio[18976]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 08 03:44:02 volumio sudo[19151]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 08 03:44:02 volumio sudo[19151]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 03:44:02 volumio volumio[18976]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 08 03:44:02 volumio sudo[19153]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 08 03:44:02 volumio sudo[19153]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 03:44:02 volumio volumio[18976]: info: ___________ START PLUGINS ___________ Feb 08 03:44:02 volumio sudo[19153]: pam_unix(sudo:session): session closed for user root Feb 08 03:44:02 volumio sudo[19155]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 08 03:44:02 volumio volumio[18976]: info: ControllerMpd::onStart: Initializing MPD Feb 08 03:44:02 volumio volumio[18976]: info: Creating MPD Configuration file Feb 08 03:44:02 volumio sudo[19155]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 03:44:02 volumio volumio[18976]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 08 03:44:02 volumio volumio[18976]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 08 03:44:02 volumio volumio[18976]: info: [1770497042815] CoreMusicLibrary::Adding element Media Servers Feb 08 03:44:02 volumio volumio[18976]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 08 03:44:02 volumio sudo[19165]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 08 03:44:02 volumio sudo[19165]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 03:44:02 volumio sudo[19151]: pam_unix(sudo:session): session closed for user root Feb 08 03:44:02 volumio sudo[19165]: pam_unix(sudo:session): session closed for user root Feb 08 03:44:02 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 08 03:44:02 volumio volumio[18976]: info: UPNP Browser: Client initialized successfully Feb 08 03:44:02 volumio sudo[19166]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 08 03:44:02 volumio sudo[19166]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 03:44:02 volumio volumio[18976]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 03:44:02 volumio volumio[18976]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 08 03:44:03 volumio volumio[18976]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 08 03:44:03 volumio volumio[18976]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 03:44:03 volumio volumio[18976]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 08 03:44:03 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 08 03:44:03 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 08 03:44:03 volumio systemd[1]: mpd.service: Consumed 7.093s CPU time. Feb 08 03:44:03 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 08 03:44:03 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 08 03:44:03 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 08 03:44:03 volumio volumio[18976]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 08 03:44:03 volumio volumio[18976]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 08 03:44:03 volumio volumio[18976]: info: [1770497043118] CoreMusicLibrary::Adding element Last_100 Feb 08 03:44:03 volumio volumio[18976]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 08 03:44:03 volumio volumio[18976]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 08 03:44:03 volumio volumio[18976]: info: [1770497043139] CoreMusicLibrary::Adding element Webradio Feb 08 03:44:03 volumio volumio[18976]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 08 03:44:03 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 08 03:44:03 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 08 03:44:03 volumio volumio[18976]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 08 03:44:03 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 08 03:44:03 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 08 03:44:03 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 08 03:44:03 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 08 03:44:03 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 08 03:44:03 volumio volumio[18976]: info: Initializing BBC Radios Feb 08 03:44:03 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 08 03:44:03 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 08 03:44:03 volumio volumio[18976]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 08 03:44:03 volumio volumio[18976]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 08 03:44:03 volumio volumio[18976]: info: Creating Spotify config file Feb 08 03:44:03 volumio volumio[18976]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 03:44:03 volumio sudo[19188]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 08 03:44:03 volumio sudo[19188]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 08 03:44:03 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 22. Feb 08 03:44:03 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 08 03:44:03 volumio sudo[19188]: pam_unix(sudo:session): session closed for user root Feb 08 03:44:03 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 08 03:44:03 volumio go-librespot[19195]: go-librespot daemon starting... Feb 08 03:44:03 volumio go-librespot[19196]: time="2026-02-08T03:44:03+07:00" level=info msg="running go-librespot 0.4.0" Feb 08 03:44:04 volumio volumio[19101]: Starting albumart workers Feb 08 03:44:04 volumio volumio[18976]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 08 03:44:04 volumio volumio[18976]: info: [1770497044587] CoreMusicLibrary::Adding element YouTube Music Feb 08 03:44:04 volumio volumio[18976]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 08 03:44:04 volumio volumio[18976]: Cannot find translation for source YouTube Music Feb 08 03:44:04 volumio volumio[18976]: info: Volumio Calling Home Feb 08 03:44:04 volumio go-librespot[19196]: time="2026-02-08T03:44:04+07:00" level=info msg="zeroconf server listening on port 33369" Feb 08 03:44:04 volumio sudo[19206]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Feb 08 03:44:04 volumio sudo[19206]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 03:44:04 volumio sudo[19206]: pam_unix(sudo:session): session closed for user root Feb 08 03:44:05 volumio volumio[19103]: Starting albumart workers Feb 08 03:44:05 volumio volumio[18976]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Feb 08 03:44:05 volumio volumio[18976]: info: Discovery: Found device Volumio Feb 08 03:44:05 volumio volumio[18976]: info: CoreCommandRouter::volumioGetState Feb 08 03:44:05 volumio volumio[18976]: info: CorePlayQueue::getTrack 0 Feb 08 03:44:05 volumio volumio[18976]: info: MPD Permissions set Feb 08 03:44:05 volumio volumio[18976]: info: MPD Permissions set Feb 08 03:44:05 volumio volumio[18976]: info: Upmpdcli Daemon Started Feb 08 03:44:05 volumio volumio[18976]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Feb 08 03:44:05 volumio volumio[18976]: info: Discovery: Found device Volumio Feb 08 03:44:05 volumio volumio[18976]: info: CoreCommandRouter::volumioGetState Feb 08 03:44:05 volumio volumio[18976]: info: CorePlayQueue::getTrack 0 Feb 08 03:44:05 volumio volumio[18976]: info: Volumio called home Feb 08 03:44:05 volumio volumio[18976]: info: Spotify config file written Feb 08 03:44:05 volumio volumio[18976]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Feb 08 03:44:05 volumio volumio[18976]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 03:44:05 volumio volumio[18976]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 03:44:05 volumio volumio[18976]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 03:44:05 volumio volumio[18976]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 03:44:05 volumio volumio[18976]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 03:44:05 volumio volumio[18976]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 03:44:05 volumio volumio[18976]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 03:44:05 volumio volumio[18976]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 03:44:05 volumio sudo[19213]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 08 03:44:05 volumio sudo[19213]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 03:44:05 volumio volumio[18976]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 08 03:44:05 volumio volumio[18976]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 03:44:05 volumio volumio[18976]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 03:44:05 volumio volumio[18976]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 03:44:05 volumio volumio[18976]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 03:44:05 volumio volumio[18976]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 03:44:05 volumio volumio[18976]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 03:44:05 volumio volumio[18976]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 03:44:05 volumio volumio[18976]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 03:44:05 volumio volumio[18976]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 03:44:05 volumio volumio[18976]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 08 03:44:05 volumio volumio[18976]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 03:44:05 volumio volumio[18976]: info: No need to fix Spotify hosts Feb 08 03:44:05 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Feb 08 03:44:05 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Feb 08 03:44:05 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 08 03:44:05 volumio volumio[19102]: Starting albumart workers Feb 08 03:44:05 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 08 03:44:05 volumio go-librespot[19225]: go-librespot daemon starting... Feb 08 03:44:05 volumio sudo[19213]: pam_unix(sudo:session): session closed for user root Feb 08 03:44:06 volumio go-librespot[19226]: time="2026-02-08T03:44:06+07:00" level=info msg="running go-librespot 0.4.0" Feb 08 03:44:06 volumio go-librespot[19226]: time="2026-02-08T03:44:06+07:00" level=debug msg="app state loaded" Feb 08 03:44:06 volumio go-librespot[19226]: time="2026-02-08T03:44:06+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 08 03:44:06 volumio go-librespot[19226]: time="2026-02-08T03:44:06+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 08 03:44:06 volumio go-librespot[19226]: time="2026-02-08T03:44:06+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 08 03:44:06 volumio go-librespot[19226]: time="2026-02-08T03:44:06+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 08 03:44:06 volumio go-librespot[19226]: time="2026-02-08T03:44:06+07:00" level=info msg="zeroconf server listening on port 34065" Feb 08 03:44:07 volumio go-librespot[19226]: time="2026-02-08T03:44:07+07:00" level=debug msg="obtained new client token: AACP9eb2WrfDII5VGK9XvWDYoOboYcx14484yki55EmPvP2Tbv4zQ8/SugOTR5G3fOiPkBZ6DkFjU24KXTNdTaKnSYVFyEOwJd2mpSH2N8vztL3Hx+jm2lPACI9hnBzkpJw/TIJJ7ao781lGnBiB/g0sd37WoFC9XdlWmYblE/y1/BdmHqXogryREKqLvPMgnucpi7z9H9lsz3TOyXhqOIR6bFuCtuzCHcwgDIhv9mMAM9a+UKVbIOk=" Feb 08 03:44:07 volumio go-librespot[19226]: time="2026-02-08T03:44:07+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 08 03:44:07 volumio volumio[18976]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 08 03:44:07 volumio volumio[18976]: SPOTIFY: BQDWvBV8o_abN1qbRsbWtCxZc_dVbArTQWQ5cT6dVmkq2Z5-6SAZcsBHakQdoLBodXyDzFfK4djLomnIicj5CrRAGUsWsrWC0ubB2YLB0lj-IenVB6eAAk_5owvoFx2uxwMc50PniQgRsNqZFjqWoQFU--m5ZgDLztPn_QAUM0NbeXpslrw8uh9BcjNqfnHpL4gjG1cJEt1m49KDiVg9tCkX0odpmFqp7uVHT4OfmJu91Z8OaPlr7EPx-PIsVWNlq7Cs6JxlYjs7Ix8IE6nnQVJ9f7MtF76fM0-euMcqB-PJIQQJhhjFoisT Feb 08 03:44:07 volumio volumio[18976]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 08 03:44:07 volumio volumio[18976]: info: New Spotify access token = BQDWvBV8o_abN1qbRsbWtCxZc_dVbArTQWQ5cT6dVmkq2Z5-6SAZcsBHakQdoLBodXyDzFfK4djLomnIicj5CrRAGUsWsrWC0ubB2YLB0lj-IenVB6eAAk_5owvoFx2uxwMc50PniQgRsNqZFjqWoQFU--m5ZgDLztPn_QAUM0NbeXpslrw8uh9BcjNqfnHpL4gjG1cJEt1m49KDiVg9tCkX0odpmFqp7uVHT4OfmJu91Z8OaPlr7EPx-PIsVWNlq7Cs6JxlYjs7Ix8IE6nnQVJ9f7MtF76fM0-euMcqB-PJIQQJhhjFoisT Feb 08 03:44:07 volumio volumio[18976]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 08 03:44:07 volumio go-librespot[19226]: time="2026-02-08T03:44:07+07:00" level=debug msg="completed keyexchange" Feb 08 03:44:07 volumio go-librespot[19226]: time="2026-02-08T03:44:07+07:00" level=debug msg="completed challenge" Feb 08 03:44:07 volumio volumio[18976]: info: Starting Shairport Sync Feb 08 03:44:07 volumio volumio[18976]: info: Starting Shairport Sync Feb 08 03:44:07 volumio volumio[18976]: info: Starting Shairport Sync Feb 08 03:44:07 volumio go-librespot[19226]: time="2026-02-08T03:44:07+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 08 03:44:07 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 08 03:44:07 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 08 03:44:07 volumio sudo[19242]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 08 03:44:07 volumio sudo[19242]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 03:44:07 volumio sudo[19247]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 08 03:44:07 volumio sudo[19247]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 03:44:07 volumio sudo[19244]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 08 03:44:07 volumio sudo[19244]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 03:44:07 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 08 03:44:07 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 08 03:44:07 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 08 03:44:07 volumio systemd[1]: shairport-sync.service: Consumed 2.293s CPU time. Feb 08 03:44:07 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 08 03:44:07 volumio sudo[19247]: pam_unix(sudo:session): session closed for user root Feb 08 03:44:07 volumio sudo[19244]: pam_unix(sudo:session): session closed for user root Feb 08 03:44:07 volumio sudo[19242]: pam_unix(sudo:session): session closed for user root Feb 08 03:44:07 volumio volumio[18976]: info: CoreCommandRouter::volumioGetState Feb 08 03:44:07 volumio volumio[18976]: info: CorePlayQueue::getTrack 0 Feb 08 03:44:07 volumio volumio[18976]: info: Shairport-Sync Started Feb 08 03:44:08 volumio volumio[18976]: Error adding Membership: Error: addMembership EINVAL Feb 08 03:44:08 volumio volumio[18976]: info: Shairport-Sync Started Feb 08 03:44:08 volumio volumio[18976]: info: Shairport-Sync Started Feb 08 03:44:08 volumio volumio[18976]: 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"} Feb 08 03:44:08 volumio volumio[18976]: info: Spotify Successfully logged in Feb 08 03:44:08 volumio volumio[18976]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 08 03:44:08 volumio volumio[18976]: info: [1770497048433] CoreMusicLibrary::Adding element Spotify Feb 08 03:44:08 volumio volumio[18976]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 08 03:44:08 volumio volumio[18976]: Cannot find translation for source YouTube Music Feb 08 03:44:08 volumio volumio[18976]: Cannot find translation for source Spotify Feb 08 03:44:09 volumio volumio[18976]: info: [yt-cast-receiver] DIAL server listening on port 8098 Feb 08 03:44:09 volumio volumio[18976]: info: CoreCommandRouter::volumioRetrievevolume Feb 08 03:44:09 volumio volumio[18976]: info: VolumeController:: Volume=100 Mute =false Feb 08 03:44:09 volumio volumio[18976]: info: CoreCommandRouter::volumioGetState Feb 08 03:44:09 volumio volumio[18976]: info: CorePlayQueue::getTrack 0 Feb 08 03:44:09 volumio volumio[18976]: info: CoreStateMachine::pushState Feb 08 03:44:09 volumio volumio[18976]: info: CorePlayQueue::getTrack 0 Feb 08 03:44:09 volumio volumio[18976]: info: CoreCommandRouter::volumioPushState Feb 08 03:44:10 volumio volumio[18976]: info: go-librespot daemon successfully initialized Feb 08 03:44:10 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Feb 08 03:44:10 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 08 03:44:10 volumio go-librespot[19293]: go-librespot daemon starting... Feb 08 03:44:10 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 08 03:44:10 volumio go-librespot[19294]: time="2026-02-08T03:44:10+07:00" level=info msg="running go-librespot 0.4.0" Feb 08 03:44:10 volumio go-librespot[19294]: time="2026-02-08T03:44:10+07:00" level=debug msg="app state loaded" Feb 08 03:44:10 volumio go-librespot[19294]: time="2026-02-08T03:44:10+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 08 03:44:10 volumio mpd[19202]: 2026-02-08T03:44:10 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 08 03:44:10 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 08 03:44:11 volumio sudo[19155]: pam_unix(sudo:session): session closed for user root Feb 08 03:44:11 volumio sudo[19166]: pam_unix(sudo:session): session closed for user root Feb 08 03:44:11 volumio go-librespot[19294]: time="2026-02-08T03:44:11+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 08 03:44:11 volumio go-librespot[19294]: time="2026-02-08T03:44:11+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 08 03:44:11 volumio go-librespot[19294]: time="2026-02-08T03:44:11+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 08 03:44:11 volumio volumio[18976]: error: MPD error: The expression evaluated to a falsy value: Feb 08 03:44:11 volumio volumio[18976]: assert.ok(self.idling) Feb 08 03:44:11 volumio volumio[18976]: error: The expression evaluated to a falsy value: Feb 08 03:44:11 volumio volumio[18976]: assert.ok(self.idling) Feb 08 03:44:11 volumio volumio[18976]: error: updateQueue error: null Feb 08 03:44:11 volumio volumio[18976]: info: MPD running with PID19202 Feb 08 03:44:11 volumio volumio[18976]: ,establishing connection Feb 08 03:44:11 volumio go-librespot[19294]: time="2026-02-08T03:44:11+07:00" level=info msg="zeroconf server listening on port 42891" Feb 08 03:44:11 volumio volumio[18976]: info: Completed starting Core Plugins Feb 08 03:44:11 volumio volumio[18976]: info: ------------------------------------------- Feb 08 03:44:11 volumio volumio[18976]: info: ----- MyVolumio plugins startup ---- Feb 08 03:44:11 volumio volumio[18976]: info: ------------------------------------------- Feb 08 03:44:11 volumio volumio[18976]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 08 03:44:11 volumio volumio[18976]: error: updateQueue error: null Feb 08 03:44:11 volumio go-librespot[19294]: time="2026-02-08T03:44:11+07:00" level=debug msg="obtained new client token: AAD+1katNnvInTKZ0caXnERAXSmAPELar+PnIyptyGOzhnB3ZHPxNMUIlfOlkx4YANUbZaacmdLgNmiuT+anu5lO0hSoS69BDtBRqx6zNaT9X7HegR8Rixan6N+gtYGAzmJIWqzaQBYxkhqEzsPpBSc6gDTyFzLSP90kKA/o4n4hU9Kh8aPweI53Cuw2unFVXnUn4N+3323r0pYcX5FnPcDM4mfUa0Pj/yomcZ6B1lQHFxfCcGdQCI5wIA==" Feb 08 03:44:11 volumio go-librespot[19294]: time="2026-02-08T03:44:11+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 08 03:44:11 volumio go-librespot[19294]: time="2026-02-08T03:44:11+07:00" level=debug msg="completed keyexchange" Feb 08 03:44:11 volumio go-librespot[19294]: time="2026-02-08T03:44:11+07:00" level=debug msg="completed challenge" Feb 08 03:44:11 volumio go-librespot[19294]: time="2026-02-08T03:44:11+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 08 03:44:11 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 08 03:44:11 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 08 03:44:13 volumio volumio[18976]: info: Initializing connection to go-librespot Websocket Feb 08 03:44:13 volumio volumio[18976]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 08 03:44:14 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Feb 08 03:44:14 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 08 03:44:14 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 08 03:44:14 volumio go-librespot[19307]: go-librespot daemon starting... Feb 08 03:44:14 volumio go-librespot[19308]: time="2026-02-08T03:44:14+07:00" level=info msg="running go-librespot 0.4.0" Feb 08 03:44:14 volumio go-librespot[19308]: time="2026-02-08T03:44:14+07:00" level=debug msg="app state loaded" Feb 08 03:44:14 volumio go-librespot[19308]: time="2026-02-08T03:44:14+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 08 03:44:15 volumio go-librespot[19308]: time="2026-02-08T03:44:15+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 08 03:44:15 volumio go-librespot[19308]: time="2026-02-08T03:44:15+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 08 03:44:15 volumio go-librespot[19308]: time="2026-02-08T03:44:15+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 08 03:44:15 volumio go-librespot[19308]: time="2026-02-08T03:44:15+07:00" level=info msg="zeroconf server listening on port 34099" Feb 08 03:44:15 volumio go-librespot[19308]: time="2026-02-08T03:44:15+07:00" level=debug msg="obtained new client token: AABCRFg+N9y4pVgblC6UsWkFZSIrrd2ASknVnemU5QsBHTyhuGggJO6Chg6uEewtayL5DkTIsNR5mJumUND+HMOt13lg2QCF1Uumqw9FTvgZBS33PH35Vyz53r2OTsYqTgcIMiGHakFIZuUcSgWRxU3coLRrdhIGncQuYRnc7+uWsJ5QoGHp/2JMKPNgXXs6cim37shStn3xv4MDoSBstsqnhvbtLwMGlfygMBVUgai6+zPQW1ukUKBQcQ==" Feb 08 03:44:15 volumio go-librespot[19308]: time="2026-02-08T03:44:15+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 08 03:44:15 volumio go-librespot[19308]: time="2026-02-08T03:44:15+07:00" level=debug msg="completed keyexchange" Feb 08 03:44:15 volumio go-librespot[19308]: time="2026-02-08T03:44:15+07:00" level=debug msg="completed challenge" Feb 08 03:44:15 volumio go-librespot[19308]: time="2026-02-08T03:44: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 " Feb 08 03:44:15 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 08 03:44:15 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 08 03:44:16 volumio volumio[18976]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 08 03:44:16 volumio volumio[18976]: info: Initializing connection to go-librespot Websocket Feb 08 03:44:16 volumio volumio[18976]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 08 03:44:19 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Feb 08 03:44:19 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 08 03:44:19 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 08 03:44:19 volumio go-librespot[19315]: go-librespot daemon starting... Feb 08 03:44:19 volumio go-librespot[19316]: time="2026-02-08T03:44:19+07:00" level=info msg="running go-librespot 0.4.0" Feb 08 03:44:19 volumio go-librespot[19316]: time="2026-02-08T03:44:19+07:00" level=debug msg="app state loaded" Feb 08 03:44:19 volumio go-librespot[19316]: time="2026-02-08T03:44:19+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 08 03:44:19 volumio volumio[18976]: info: Initializing connection to go-librespot Websocket Feb 08 03:44:19 volumio go-librespot[19316]: time="2026-02-08T03:44:19+07:00" level=debug msg="new websocket client" Feb 08 03:44:19 volumio volumio[18976]: info: Connection to go-librespot Websocket established Feb 08 03:44:19 volumio go-librespot[19316]: time="2026-02-08T03:44:19+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 08 03:44:19 volumio go-librespot[19316]: time="2026-02-08T03:44:19+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]" Feb 08 03:44:19 volumio go-librespot[19316]: time="2026-02-08T03:44:19+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]" Feb 08 03:44:19 volumio go-librespot[19316]: time="2026-02-08T03:44:19+07:00" level=info msg="zeroconf server listening on port 46437" Feb 08 03:44:19 volumio go-librespot[19316]: time="2026-02-08T03:44:19+07:00" level=debug msg="obtained new client token: AAA9Xjl6Sl6oGIdOTVdvL+yeGY/+cyKWye7s1N/iIU7TlDXMWnv7NUMNh2ubuLVGVyxIw+KSsLbFga6I4ShP1U7ZxVEOTyO42j6A9MC5hjiPdCKS7ZqKUTAnGe+n0r1k1pDrVlE8zSseNI0/Nu3keLLzIgSJbiBppuk3adDrc1a/jykbCojp2q3q+YQIymk82io4YDwawcCMGxR69arqRD6SV3VKEPGe5h7Txkuuj/YnHasU7FRG/9ddQQ==" Feb 08 03:44:19 volumio volumio[18976]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 08 03:44:19 volumio volumio[18976]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 08 03:44:19 volumio volumio[18976]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 08 03:44:19 volumio volumio[18976]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 08 03:44:19 volumio volumio[18976]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 08 03:44:19 volumio volumio[18976]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 08 03:44:19 volumio volumio[18976]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 08 03:44:19 volumio volumio[18976]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 08 03:44:19 volumio volumio[18976]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 08 03:44:19 volumio volumio[18976]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 08 03:44:19 volumio volumio[18976]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 08 03:44:19 volumio volumio[18976]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 08 03:44:19 volumio volumio[18976]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 08 03:44:19 volumio volumio[18976]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 08 03:44:19 volumio volumio[18976]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 08 03:44:19 volumio volumio[18976]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 08 03:44:19 volumio volumio[18976]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 08 03:44:19 volumio volumio[18976]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 08 03:44:19 volumio volumio[18976]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 08 03:44:19 volumio volumio[18976]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 08 03:44:19 volumio volumio[18976]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 08 03:44:19 volumio volumio[18976]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 08 03:44:19 volumio volumio[18976]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 08 03:44:19 volumio volumio[18976]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 08 03:44:19 volumio volumio[18976]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 08 03:44:19 volumio volumio[18976]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 08 03:44:19 volumio volumio[18976]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 08 03:44:19 volumio volumio[18976]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 08 03:44:20 volumio volumio[18976]: info: Adding plugin bluetooth to MyMusic Plugins Feb 08 03:44:20 volumio volumio[18976]: info: Adding plugin multiroom to MyMusic Plugins Feb 08 03:44:20 volumio volumio[18976]: info: Adding plugin metavolumio to MyMusic Plugins Feb 08 03:44:20 volumio volumio[18976]: info: Adding plugin cd_controller to MyMusic Plugins Feb 08 03:44:20 volumio volumio[18976]: info: Adding plugin qobuzconnect to MyMusic Plugins Feb 08 03:44:20 volumio volumio[18976]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 08 03:44:20 volumio volumio[18976]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 08 03:44:20 volumio volumio[18976]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 08 03:44:20 volumio go-librespot[19316]: time="2026-02-08T03:44:20+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 08 03:44:20 volumio go-librespot[19316]: time="2026-02-08T03:44:20+07:00" level=debug msg="completed keyexchange" Feb 08 03:44:20 volumio go-librespot[19316]: time="2026-02-08T03:44:20+07:00" level=debug msg="completed challenge" Feb 08 03:44:20 volumio go-librespot[19316]: time="2026-02-08T03:44:20+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 08 03:44:20 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 08 03:44:20 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 08 03:44:21 volumio volumio[18976]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 08 03:44:21 volumio volumio[18976]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 08 03:44:21 volumio volumio[18976]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 08 03:44:21 volumio volumio[18976]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 08 03:44:21 volumio volumio[18976]: info: Starting MyVolumio Remote Streaming Endpoints Feb 08 03:44:21 volumio volumio[18976]: info: MyVolumio login type: Token Feb 08 03:44:21 volumio volumio[18976]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 08 03:44:21 volumio volumio[18976]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 08 03:44:23 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Feb 08 03:44:23 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 08 03:44:23 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 08 03:44:23 volumio go-librespot[19337]: go-librespot daemon starting... Feb 08 03:44:23 volumio go-librespot[19338]: time="2026-02-08T03:44:23+07:00" level=info msg="running go-librespot 0.4.0" Feb 08 03:44:23 volumio go-librespot[19338]: time="2026-02-08T03:44:23+07:00" level=debug msg="app state loaded" Feb 08 03:44:23 volumio go-librespot[19338]: time="2026-02-08T03:44:23+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 08 03:44:23 volumio volumio[18976]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 08 03:44:23 volumio volumio[18976]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 08 03:44:23 volumio volumio[18976]: info: Streaming services startup Feb 08 03:44:23 volumio volumio[18976]: info: Starting Streaming Daemon Feb 08 03:44:23 volumio sudo[19346]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 08 03:44:23 volumio sudo[19346]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 03:44:23 volumio volumio[18976]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 08 03:44:23 volumio sudo[19346]: pam_unix(sudo:session): session closed for user root Feb 08 03:44:23 volumio volumio[18976]: info: Getting Spotify volume Feb 08 03:44:23 volumio volumio[18976]: info: Connection to go-librespot Websocket closed Feb 08 03:44:23 volumio volumio[18976]: error: Cannot start Volumio Streaming Daemon Feb 08 03:44:23 volumio volumio[18976]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 08 03:44:23 volumio volumio[18976]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 08 03:44:23 volumio volumio[18976]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Feb 08 03:44:24 volumio go-librespot[19338]: time="2026-02-08T03:44:24+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 08 03:44:24 volumio go-librespot[19338]: time="2026-02-08T03:44:24+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 08 03:44:24 volumio go-librespot[19338]: time="2026-02-08T03:44:24+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 08 03:44:24 volumio go-librespot[19338]: time="2026-02-08T03:44:24+07:00" level=info msg="zeroconf server listening on port 37475" Feb 08 03:44:24 volumio volumio[18976]: info: CoreCommandRouter::volumioGetState Feb 08 03:44:24 volumio volumio[18976]: info: CorePlayQueue::getTrack 0 Feb 08 03:44:24 volumio volumio[18976]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Feb 08 03:44:24 volumio volumio[18976]: SPOTIFY: SPOTIFY VOLUME undefined Feb 08 03:44:24 volumio volumio[18976]: SPOTIFY: VOLUMIO VOLUME 100 Feb 08 03:44:24 volumio volumio[18976]: info: Aligning Spotify Volume to Volumio Volume Feb 08 03:44:24 volumio volumio[18976]: info: CoreCommandRouter::volumioGetState Feb 08 03:44:24 volumio volumio[18976]: info: CorePlayQueue::getTrack 0 Feb 08 03:44:24 volumio volumio[18976]: info: Setting Spotify Volume from Volumio: 100 Feb 08 03:44:24 volumio go-librespot[19338]: time="2026-02-08T03:44:24+07:00" level=debug msg="obtained new client token: AADD8WXLMvm8dEDd7ozF4mSshmolx/YCwuqV0+At1Lp0uOq7KesXrIdO3TPj/IZhoDcLj776XXG9MdYWPtSQtcyxOwXUjgoOBQTbJWXhEmV2qPdtcPtA0C/BjSok+/kwSDOGRvWwRM/rIoppwShGN28uPTbn6lEMQk5R3CTzXBGlYCGj73LGtDUrB55xKGocaYK7UK/lgMD/lBNgqW1Ec/Nd4Dj+rBodw8hgYxO80Ulq98rY0n51ufQ=" Feb 08 03:44:24 volumio go-librespot[19338]: time="2026-02-08T03:44:24+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 08 03:44:24 volumio go-librespot[19338]: time="2026-02-08T03:44:24+07:00" level=debug msg="completed keyexchange" Feb 08 03:44:24 volumio go-librespot[19338]: time="2026-02-08T03:44:24+07:00" level=debug msg="completed challenge" Feb 08 03:44:24 volumio go-librespot[19338]: time="2026-02-08T03:44:24+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 08 03:44:24 volumio volumio[18976]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 08 03:44:24 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 08 03:44:24 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 08 03:44:24 volumio volumio[18976]: Error: socket hang up Feb 08 03:44:24 volumio volumio[18976]: at connResetException (node:internal/errors:720:14) Feb 08 03:44:24 volumio volumio[18976]: at Socket.socketOnEnd (node:_http_client:519:23) Feb 08 03:44:24 volumio volumio[18976]: at Socket.emit (node:events:526:35) Feb 08 03:44:24 volumio volumio[18976]: at endReadableNT (node:internal/streams/readable:1376:12) Feb 08 03:44:24 volumio volumio[18976]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Feb 08 03:44:24 volumio volumio[18976]: code: 'ECONNRESET', Feb 08 03:44:24 volumio volumio[18976]: response: undefined Feb 08 03:44:24 volumio volumio[18976]: } Feb 08 03:44:24 volumio volumio[18976]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 08 03:44:26 volumio sudo[19368]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-08 03:43' Feb 08 03:44:26 volumio sudo[19368]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 03:44:26 volumio sudo[19368]: pam_unix(sudo:session): session closed for user root Feb 08 03:44:26 volumio volumio-remote-updater[643]: [2026-02-08 03:44:26] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Feb 08 03:44:26 volumio volumio-remote-updater[643]: [2026-02-08 03:44:26] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Feb 08 03:44:26 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Feb 08 03:44:26 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Feb 08 03:44:26 volumio systemd[1]: volumio.service: Consumed 55.732s CPU time. Feb 08 03:44:26 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 08 03:44:26 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 08 03:44:26 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 6731. Feb 08 03:44:26 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 08 03:44:26 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Feb 08 03:44:26 volumio systemd[1]: volumio.service: Consumed 55.732s CPU time. Feb 08 03:44:26 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Feb 08 03:44:26 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 08 03:44:27 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Feb 08 03:44:27 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 08 03:44:27 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 08 03:44:27 volumio go-librespot[19395]: go-librespot daemon starting... Feb 08 03:44:27 volumio go-librespot[19396]: time="2026-02-08T03:44:27+07:00" level=info msg="running go-librespot 0.4.0" Feb 08 03:44:27 volumio go-librespot[19396]: time="2026-02-08T03:44:27+07:00" level=debug msg="app state loaded" Feb 08 03:44:27 volumio go-librespot[19396]: time="2026-02-08T03:44:27+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 08 03:44:28 volumio go-librespot[19396]: time="2026-02-08T03:44:28+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 08 03:44:28 volumio go-librespot[19396]: time="2026-02-08T03:44:28+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]" Feb 08 03:44:28 volumio go-librespot[19396]: time="2026-02-08T03:44:28+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]" Feb 08 03:44:28 volumio go-librespot[19396]: time="2026-02-08T03:44:28+07:00" level=info msg="zeroconf server listening on port 41289" Feb 08 03:44:28 volumio go-librespot[19396]: time="2026-02-08T03:44:28+07:00" level=debug msg="obtained new client token: AACxTwtZfcvoHzt2i/UymCCaV+BLkJbKI8dOJH2YsJCIB5CX9oY5jXx8HHmVnywWCQ71i+5Gvr5rJrSiGBJ13gFqwJPo/HZUvJWDTk8RNpwn9ZYUPupaskGb0y4F0LB1z5UTzeqE79Ig6PnnMJNuNsZvibOXkn4trr7XANsg5DdcEY2V0CmHiit/KGyjwbHOfUk4aIeFBKF03gunk024d9zvLVTt9CpeAl1o4zPTINeKyjTsxKVZZVFsXg==" Feb 08 03:44:28 volumio go-librespot[19396]: time="2026-02-08T03:44:28+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 08 03:44:28 volumio go-librespot[19396]: time="2026-02-08T03:44:28+07:00" level=debug msg="completed keyexchange" Feb 08 03:44:28 volumio go-librespot[19396]: time="2026-02-08T03:44:28+07:00" level=debug msg="completed challenge" Feb 08 03:44:29 volumio go-librespot[19396]: time="2026-02-08T03:44:29+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 08 03:44:29 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 08 03:44:29 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 08 03:44:30 volumio volumio[19380]: info: ------------------------------------------- Feb 08 03:44:30 volumio volumio[19380]: info: ----- Volumio3 ---- Feb 08 03:44:30 volumio volumio[19380]: info: ------------------------------------------- Feb 08 03:44:30 volumio volumio[19380]: info: ----- System startup ---- Feb 08 03:44:30 volumio volumio[19380]: info: ------------------------------------------- Feb 08 03:44:31 volumio volumio-remote-updater[643]: [2026-02-08 03:44:31] [connect] Successful connection Feb 08 03:44:31 volumio volumio[19380]: info: MYVOLUMIO Environment detected Feb 08 03:44:31 volumio volumio[19380]: info: Plugin folders cleanup Feb 08 03:44:31 volumio volumio[19380]: info: Scanning into folder /volumio/app/plugins/ Feb 08 03:44:31 volumio volumio[19380]: info: Scanning category audio_interface Feb 08 03:44:31 volumio volumio[19380]: info: Scanning category miscellanea Feb 08 03:44:31 volumio volumio[19380]: info: Scanning category music_service Feb 08 03:44:31 volumio volumio[19380]: info: Scanning category plugins.json Feb 08 03:44:31 volumio volumio[19380]: info: Scanning category system_controller Feb 08 03:44:31 volumio volumio[19380]: info: Scanning category user_interface Feb 08 03:44:31 volumio volumio[19380]: info: Scanning into folder /data/plugins/ Feb 08 03:44:31 volumio volumio[19380]: info: Scanning category music_service Feb 08 03:44:31 volumio volumio[19380]: info: Plugin folders cleanup completed Feb 08 03:44:31 volumio volumio[19380]: info: ------------------------------------------- Feb 08 03:44:31 volumio volumio[19380]: info: ----- Core plugins startup ---- Feb 08 03:44:31 volumio volumio[19380]: info: ------------------------------------------- Feb 08 03:44:31 volumio volumio[19380]: info: Loading plugins from folder /volumio/app/plugins/ Feb 08 03:44:31 volumio volumio[19380]: info: Adding plugin upnp to MyMusic Plugins Feb 08 03:44:31 volumio volumio[19380]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 08 03:44:31 volumio volumio[19380]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 08 03:44:31 volumio volumio[19380]: info: Loading plugins from folder /data/plugins/ Feb 08 03:44:31 volumio volumio[19380]: info: Loading plugin "system"... Feb 08 03:44:32 volumio volumio[19380]: info: Loading plugin "appearance"... Feb 08 03:44:32 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Feb 08 03:44:32 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 08 03:44:32 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 08 03:44:32 volumio go-librespot[19415]: go-librespot daemon starting... Feb 08 03:44:32 volumio go-librespot[19416]: time="2026-02-08T03:44:32+07:00" level=info msg="running go-librespot 0.4.0" Feb 08 03:44:32 volumio go-librespot[19416]: time="2026-02-08T03:44:32+07:00" level=debug msg="app state loaded" Feb 08 03:44:32 volumio go-librespot[19416]: time="2026-02-08T03:44:32+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 08 03:44:32 volumio go-librespot[19416]: time="2026-02-08T03:44:32+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 08 03:44:32 volumio go-librespot[19416]: time="2026-02-08T03:44:32+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 08 03:44:32 volumio go-librespot[19416]: time="2026-02-08T03:44:32+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 08 03:44:32 volumio go-librespot[19416]: time="2026-02-08T03:44:32+07:00" level=info msg="zeroconf server listening on port 42027" Feb 08 03:44:32 volumio go-librespot[19416]: time="2026-02-08T03:44:32+07:00" level=debug msg="obtained new client token: AADI/93NKhTa2H7OXRG3bxi/7piX2JYDcwb3l5VTa7IDri2n86avQKdTHVBduYPKtg6UepBcgZNLlN0ALpKbcUAkGl4Kg0of+QlpLX2AYPyRPph1iPcJOmPH3UjaDGfTYxskc6OebaXuhMrWMa1pZbsuWwMrHS7h7DJOkIrhAu5CUl7wkUntAirbxT6oCCYYUgN1a7vC2+cq7vhKMtOWW71rzqGxQepGsAouDcp1pur71uQHsgaftovAoQ==" Feb 08 03:44:33 volumio go-librespot[19416]: time="2026-02-08T03:44:33+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 08 03:44:33 volumio go-librespot[19416]: time="2026-02-08T03:44:33+07:00" level=debug msg="completed keyexchange" Feb 08 03:44:33 volumio go-librespot[19416]: time="2026-02-08T03:44:33+07:00" level=debug msg="completed challenge" Feb 08 03:44:33 volumio go-librespot[19416]: time="2026-02-08T03:44:33+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 08 03:44:33 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 08 03:44:33 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 08 03:44:33 volumio volumio[19380]: info: Loading plugin "network"... Feb 08 03:44:33 volumio volumio[19380]: info: Refreshing Cached IP Addresses Feb 08 03:44:34 volumio sudo[19428]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 08 03:44:34 volumio sudo[19428]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 03:44:34 volumio sudo[19430]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 08 03:44:34 volumio sudo[19430]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 03:44:34 volumio sudo[19428]: pam_unix(sudo:session): session closed for user root Feb 08 03:44:34 volumio volumio[19380]: info: Loading plugin "services"... Feb 08 03:44:34 volumio sudo[19430]: pam_unix(sudo:session): session closed for user root Feb 08 03:44:34 volumio volumio[19380]: info: Loading plugin "alsa_controller"... Feb 08 03:44:34 volumio sudo[19438]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 08 03:44:34 volumio sudo[19438]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 03:44:34 volumio volumio[19380]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 08 03:44:34 volumio volumio[19380]: info: Loading plugin "wizard"... Feb 08 03:44:34 volumio volumio[19380]: info: Loading plugin "networkfs"... Feb 08 03:44:34 volumio volumio[19380]: info: Starting Udev Watcher for removable devices Feb 08 03:44:34 volumio volumio[19380]: info: Ignoring mount for partition: boot Feb 08 03:44:34 volumio volumio[19380]: info: Ignoring mount for partition: volumio Feb 08 03:44:34 volumio volumio[19380]: info: Ignoring mount for partition: volumio_data Feb 08 03:44:34 volumio volumio[19380]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 08 03:44:34 volumio volumio[19380]: info: Loading plugin "volumio_command_line_client"... Feb 08 03:44:34 volumio volumio[19380]: info: Loading plugin "upnp"... Feb 08 03:44:34 volumio volumio[19380]: info: [1770497074356] Starting Upmpd Daemon Feb 08 03:44:34 volumio volumio[19380]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 08 03:44:34 volumio volumio[19380]: info: Loading plugin "my_music"... Feb 08 03:44:34 volumio volumio[19380]: info: Loading plugin "mpd"... Feb 08 03:44:35 volumio volumio[19380]: info: Loading plugin "upnp_browser"... Feb 08 03:44:36 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Feb 08 03:44:36 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 08 03:44:36 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 08 03:44:36 volumio go-librespot[19461]: go-librespot daemon starting... Feb 08 03:44:36 volumio go-librespot[19462]: time="2026-02-08T03:44:36+07:00" level=info msg="running go-librespot 0.4.0" Feb 08 03:44:36 volumio go-librespot[19462]: time="2026-02-08T03:44:36+07:00" level=debug msg="app state loaded" Feb 08 03:44:36 volumio go-librespot[19462]: time="2026-02-08T03:44:36+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 08 03:44:36 volumio sudo[19438]: pam_unix(sudo:session): session closed for user root Feb 08 03:44:36 volumio go-librespot[19462]: time="2026-02-08T03:44:36+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 08 03:44:36 volumio go-librespot[19462]: time="2026-02-08T03:44:36+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]" Feb 08 03:44:36 volumio go-librespot[19462]: time="2026-02-08T03:44:36+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]" Feb 08 03:44:36 volumio go-librespot[19462]: time="2026-02-08T03:44:36+07:00" level=info msg="zeroconf server listening on port 44775" Feb 08 03:44:37 volumio go-librespot[19462]: time="2026-02-08T03:44:37+07:00" level=debug msg="obtained new client token: AABAw0psgQh61MTWA6ARAtLw8z2m2Ko54biocXuUlxbL373QCoUuaMi0jR02hSpW1hQBNXJbzJO+CHUnyUL7oloC55RmaaYnhdaqSwqQWz9EsIe+9soGfo5NkqFps6Jw5xX9qPTrI+SotyMAgN9H7qsuf6+2LoYrRhRbJv1mhraWWnBpFSYW/j4qkCgrqa4RyZGaTSEsWuM+xXG6RM5K38ANLJ/FfIJuE88+av4bRqtxRTMWQ+gEiwM=" Feb 08 03:44:37 volumio go-librespot[19462]: time="2026-02-08T03:44:37+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 08 03:44:37 volumio go-librespot[19462]: time="2026-02-08T03:44:37+07:00" level=debug msg="completed keyexchange" Feb 08 03:44:37 volumio go-librespot[19462]: time="2026-02-08T03:44:37+07:00" level=debug msg="completed challenge" Feb 08 03:44:37 volumio go-librespot[19462]: time="2026-02-08T03:44:37+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 08 03:44:37 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 08 03:44:37 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 08 03:44:37 volumio volumio[19380]: info: Starting UPNP Browser Feb 08 03:44:37 volumio volumio[19380]: info: Loading plugin "alarm-clock"... Feb 08 03:44:38 volumio volumio[19380]: info: Loading plugin "airplay_emulation"... Feb 08 03:44:38 volumio volumio[19380]: info: Starting Shairport Sync Feb 08 03:44:38 volumio volumio[19380]: info: Loading plugin "last_100"... Feb 08 03:44:38 volumio volumio[19380]: info: Loading plugin "webradio"... Feb 08 03:44:38 volumio volumio[19380]: info: Loading plugin "i2s_dacs"... Feb 08 03:44:38 volumio volumio[19380]: info: Loading plugin "volumiodiscovery"... Feb 08 03:44:38 volumio volumio[19380]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 08 03:44:38 volumio volumio[19380]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 08 03:44:38 volumio volumio[19380]: *** WARNING *** For more information see Feb 08 03:44:38 volumio volumio[19380]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 08 03:44:38 volumio volumio[19380]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 08 03:44:38 volumio volumio[19380]: *** WARNING *** For more information see Feb 08 03:44:38 volumio node[19380]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 08 03:44:38 volumio node[19380]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 08 03:44:38 volumio node[19380]: *** WARNING *** For more information see Feb 08 03:44:38 volumio node[19380]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 08 03:44:38 volumio node[19380]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 08 03:44:38 volumio node[19380]: *** WARNING *** For more information see Feb 08 03:44:38 volumio volumio[19380]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 08 03:44:38 volumio volumio[19380]: info: Discovery: Started advertising with name: Volumio Feb 08 03:44:38 volumio volumio[19380]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 08 03:44:38 volumio volumio[19380]: info: Loading plugin "spop"... Feb 08 03:44:40 volumio volumio[19380]: info: Loading plugin "ytcr"... Feb 08 03:44:40 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Feb 08 03:44:40 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 08 03:44:40 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 08 03:44:40 volumio go-librespot[19471]: go-librespot daemon starting... Feb 08 03:44:40 volumio go-librespot[19472]: time="2026-02-08T03:44:40+07:00" level=info msg="running go-librespot 0.4.0" Feb 08 03:44:40 volumio go-librespot[19472]: time="2026-02-08T03:44:40+07:00" level=debug msg="app state loaded" Feb 08 03:44:40 volumio go-librespot[19472]: time="2026-02-08T03:44:40+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 08 03:44:41 volumio go-librespot[19472]: time="2026-02-08T03:44:41+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 08 03:44:41 volumio go-librespot[19472]: time="2026-02-08T03:44:41+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]" Feb 08 03:44:41 volumio go-librespot[19472]: time="2026-02-08T03:44:41+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]" Feb 08 03:44:41 volumio go-librespot[19472]: time="2026-02-08T03:44:41+07:00" level=info msg="zeroconf server listening on port 35649" Feb 08 03:44:41 volumio go-librespot[19472]: time="2026-02-08T03:44:41+07:00" level=debug msg="obtained new client token: AAAN6AzL2R52U1pDPKGdbNonEUX+qUbrkV6ezXoydgQvbGJx6b07Nb6CjCXFNiuw5OUv/XtDG+MuAbX0ivG5Dw4mec/qKqfES9QDdK72WU5O6BCWNeF51bwXoE04EyUWVc8CA62oU1aLW3h7kNk2VIJwU970pe6+tPjc4cY3Ps44pfVAA3pH2HM8apSVUp/nXWtGUfRCia5NqJT0UN0nCd3L3SklisjVsCYjbmspVCe14JvIdSyPlBAjmw==" Feb 08 03:44:41 volumio go-librespot[19472]: time="2026-02-08T03:44:41+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 08 03:44:41 volumio go-librespot[19472]: time="2026-02-08T03:44:41+07:00" level=debug msg="completed keyexchange" Feb 08 03:44:41 volumio go-librespot[19472]: time="2026-02-08T03:44:41+07:00" level=debug msg="completed challenge" Feb 08 03:44:41 volumio go-librespot[19472]: time="2026-02-08T03:44: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 " Feb 08 03:44:41 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 08 03:44:41 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 08 03:44:43 volumio volumio[19380]: info: Loading plugin "ytmusic"... Feb 08 03:44:44 volumio volumio-remote-updater[643]: [2026-02-08 03:44:44] [connect] Successful connection Feb 08 03:44:44 volumio volumio[19380]: info: Loading plugin "outputs"... Feb 08 03:44:44 volumio volumio[19380]: info: Loading plugin "albumart"... Feb 08 03:44:44 volumio volumio[19380]: info: Plugin example_plugin is not enabled Feb 08 03:44:44 volumio volumio[19380]: info: Loading plugin "inputs"... Feb 08 03:44:44 volumio volumio[19380]: info: Loading plugin "updater_comm"... Feb 08 03:44:44 volumio volumio[19380]: info: Plugin mpdemulation is not enabled Feb 08 03:44:44 volumio volumio[19380]: info: Loading plugin "rest_api"... Feb 08 03:44:44 volumio volumio[19380]: info: Loading plugin "websocket"... Feb 08 03:44:44 volumio volumio[19380]: info: Starting Socket.io Server version 1.7.4 Feb 08 03:44:44 volumio volumio[19380]: info: Loading plugin "RoonBridge"... Feb 08 03:44:44 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Feb 08 03:44:44 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 08 03:44:44 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 08 03:44:44 volumio go-librespot[19505]: go-librespot daemon starting... Feb 08 03:44:44 volumio go-librespot[19506]: time="2026-02-08T03:44:44+07:00" level=info msg="running go-librespot 0.4.0" Feb 08 03:44:44 volumio go-librespot[19506]: time="2026-02-08T03:44:44+07:00" level=debug msg="app state loaded" Feb 08 03:44:44 volumio go-librespot[19506]: time="2026-02-08T03:44:44+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 08 03:44:45 volumio volumio[19380]: info: Applying required configuration parameters for plugin RoonBridge Feb 08 03:44:45 volumio volumio[19380]: info: Loading i18n strings for locale en Feb 08 03:44:45 volumio volumio[19380]: Updating browse sources language Feb 08 03:44:45 volumio volumio[19380]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 08 03:44:45 volumio volumio[19494]: Forking 3 albumart workers Feb 08 03:44:45 volumio volumio[19380]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 08 03:44:45 volumio volumio[19380]: info: CoreCommandRouter::initPlayerControls Feb 08 03:44:45 volumio volumio[19380]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 03:44:45 volumio volumio[19380]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 03:44:45 volumio volumio[19380]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 03:44:45 volumio volumio[19380]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 03:44:45 volumio volumio[19380]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 03:44:45 volumio volumio[19380]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 03:44:45 volumio volumio[19380]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 03:44:45 volumio volumio[19380]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 03:44:45 volumio volumio[19380]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 08 03:44:45 volumio volumio[19380]: Express server listening on port 3000 Feb 08 03:44:45 volumio volumio[19380]: [Metrics] WebUI: 16s 5.74ms Feb 08 03:44:45 volumio volumio[19380]: info: CoreStateMachine::resetVolumioState Feb 08 03:44:45 volumio volumio[19380]: info: CoreStateMachine::getcurrentVolume Feb 08 03:44:45 volumio volumio[19380]: info: CoreCommandRouter::volumioRetrievevolume Feb 08 03:44:45 volumio go-librespot[19506]: time="2026-02-08T03:44:45+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 08 03:44:45 volumio go-librespot[19506]: time="2026-02-08T03:44:45+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]" Feb 08 03:44:45 volumio go-librespot[19506]: time="2026-02-08T03:44:45+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]" Feb 08 03:44:45 volumio go-librespot[19506]: time="2026-02-08T03:44:45+07:00" level=info msg="zeroconf server listening on port 35423" Feb 08 03:44:45 volumio sudo[19547]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 08 03:44:45 volumio sudo[19547]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 03:44:45 volumio sudo[19547]: pam_unix(sudo:session): session closed for user root Feb 08 03:44:45 volumio sudo[19551]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 08 03:44:45 volumio sudo[19551]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 03:44:45 volumio sudo[19551]: pam_unix(sudo:session): session closed for user root Feb 08 03:44:45 volumio volumio[19380]: info: Volumio Network Manager: Network status updated: 1 Feb 08 03:44:45 volumio go-librespot[19506]: time="2026-02-08T03:44:45+07:00" level=debug msg="obtained new client token: AABWDB0H4V7pqFLHaF0vmkk3V4U2bbP6wnXZ8j1Uq906gBDt6tekQk/GbiXTKcyZT0P/R7UUbGRiCjXSVHxkNxTWVN/gM0ATtL5fcJg2a+H3ct1cgSkpbEMDoKBaeKGGgNpxc2deGUWl5l2zDxp1GKB95pDcParjykB1hKeHTuXQY8ykKgv9F3lrIEUEerwf9dB58WQT7MszaVe2qmXskosOUUwLr+x913jfifR9TrlYIXJPLufAuTFJ/A==" Feb 08 03:44:46 volumio go-librespot[19506]: time="2026-02-08T03:44:46+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 08 03:44:46 volumio go-librespot[19506]: time="2026-02-08T03:44:46+07:00" level=debug msg="completed keyexchange" Feb 08 03:44:46 volumio go-librespot[19506]: time="2026-02-08T03:44:46+07:00" level=debug msg="completed challenge" Feb 08 03:44:46 volumio volumio-remote-updater[643]: [2026-02-08 03:44:46] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1770497084 101 Feb 08 03:44:46 volumio volumio[19380]: 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 Feb 08 03:44:46 volumio volumio[19380]: info: VolumeController:: Volume=100 Mute =false Feb 08 03:44:46 volumio volumio[19380]: info: CoreStateMachine::pushState Feb 08 03:44:46 volumio volumio[19380]: info: CorePlayQueue::getTrack 0 Feb 08 03:44:46 volumio volumio[19380]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 08 03:44:46 volumio volumio[19380]: info: CoreCommandRouter::volumioPushState Feb 08 03:44:46 volumio volumio[19380]: info: CoreStateMachine::updateTrackBlock Feb 08 03:44:46 volumio volumio[19380]: info: CorePlayQueue::getTrackBlock Feb 08 03:44:46 volumio volumio[19380]: info: CoreCommandRouter::volumioRetrievevolume Feb 08 03:44:46 volumio go-librespot[19506]: time="2026-02-08T03:44:46+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 08 03:44:46 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 08 03:44:46 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 08 03:44:46 volumio volumio[19380]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 08 03:44:46 volumio volumio[19380]: info: Reloading queue from file Feb 08 03:44:46 volumio volumio[19380]: info: CoreStateMachine::setRepeat null single undefined Feb 08 03:44:46 volumio volumio[19380]: info: CoreStateMachine::pushState Feb 08 03:44:46 volumio volumio[19380]: info: CorePlayQueue::getTrack 0 Feb 08 03:44:46 volumio volumio[19380]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 08 03:44:46 volumio volumio[19380]: info: CoreCommandRouter::volumioPushState Feb 08 03:44:46 volumio volumio[19380]: info: CoreStateMachine::setRandom null Feb 08 03:44:46 volumio volumio[19380]: info: CoreStateMachine::pushState Feb 08 03:44:46 volumio volumio[19380]: info: CorePlayQueue::getTrack 0 Feb 08 03:44:46 volumio volumio[19380]: info: CoreCommandRouter::volumioPushState Feb 08 03:44:46 volumio volumio[19380]: info: Setting Device type: Raspberry PI Feb 08 03:44:46 volumio volumio[19380]: info: Completed loading Core Plugins Feb 08 03:44:46 volumio volumio[19380]: info: Preparing to generate the ALSA configuration file Feb 08 03:44:46 volumio volumio[19380]: info: VolumeController:: Volume=100 Mute =false Feb 08 03:44:46 volumio volumio[19380]: info: CoreStateMachine::pushState Feb 08 03:44:46 volumio volumio[19380]: info: CorePlayQueue::getTrack 0 Feb 08 03:44:46 volumio volumio[19380]: info: CoreCommandRouter::volumioPushState Feb 08 03:44:46 volumio volumio[19380]: info: Asound.conf file unchanged, so no further update is needed Feb 08 03:44:46 volumio volumio[19380]: info: Output device has changed, restarting MPD Feb 08 03:44:46 volumio volumio[19380]: info: Output device has changed, restarting Shairport Sync Feb 08 03:44:46 volumio sudo[19564]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 08 03:44:46 volumio volumio[19380]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 03:44:46 volumio volumio[19380]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 08 03:44:46 volumio sudo[19564]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 03:44:46 volumio sudo[19566]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 08 03:44:46 volumio sudo[19566]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 03:44:46 volumio volumio[19380]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 08 03:44:46 volumio sudo[19566]: pam_unix(sudo:session): session closed for user root Feb 08 03:44:46 volumio volumio[19380]: info: ___________ START PLUGINS ___________ Feb 08 03:44:46 volumio sudo[19568]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 08 03:44:46 volumio sudo[19568]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 03:44:46 volumio sudo[19564]: pam_unix(sudo:session): session closed for user root Feb 08 03:44:46 volumio volumio[19380]: info: ControllerMpd::onStart: Initializing MPD Feb 08 03:44:46 volumio volumio[19380]: info: Creating MPD Configuration file Feb 08 03:44:46 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 08 03:44:46 volumio sudo[19577]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 08 03:44:46 volumio volumio[19380]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 08 03:44:46 volumio sudo[19577]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 03:44:46 volumio volumio[19380]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 08 03:44:46 volumio volumio[19380]: info: [1770497086989] CoreMusicLibrary::Adding element Media Servers Feb 08 03:44:46 volumio volumio[19380]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 08 03:44:46 volumio sudo[19577]: pam_unix(sudo:session): session closed for user root Feb 08 03:44:47 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 08 03:44:47 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 08 03:44:47 volumio systemd[1]: mpd.service: Consumed 7.194s CPU time. Feb 08 03:44:47 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 08 03:44:47 volumio volumio[19380]: info: UPNP Browser: Client initialized successfully Feb 08 03:44:47 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 08 03:44:47 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 08 03:44:47 volumio sudo[19579]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 08 03:44:47 volumio sudo[19579]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 03:44:47 volumio volumio[19380]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 03:44:47 volumio volumio[19380]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 08 03:44:47 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 08 03:44:47 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 08 03:44:47 volumio volumio[19380]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 08 03:44:47 volumio volumio[19380]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 03:44:47 volumio volumio[19380]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 08 03:44:47 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 08 03:44:47 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 08 03:44:47 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 08 03:44:47 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 08 03:44:47 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 08 03:44:47 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 08 03:44:47 volumio volumio[19380]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 08 03:44:47 volumio volumio[19380]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 08 03:44:47 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 08 03:44:47 volumio volumio[19380]: info: [1770497087333] CoreMusicLibrary::Adding element Last_100 Feb 08 03:44:47 volumio volumio[19380]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 08 03:44:47 volumio volumio[19380]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 08 03:44:47 volumio volumio[19380]: info: [1770497087352] CoreMusicLibrary::Adding element Webradio Feb 08 03:44:47 volumio volumio[19380]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 08 03:44:47 volumio volumio[19380]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 08 03:44:47 volumio volumio[19380]: info: Initializing BBC Radios Feb 08 03:44:47 volumio volumio[19380]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 08 03:44:47 volumio volumio[19380]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 08 03:44:47 volumio volumio[19380]: info: Creating Spotify config file Feb 08 03:44:47 volumio volumio[19380]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 03:44:47 volumio sudo[19593]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 08 03:44:47 volumio sudo[19593]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 08 03:44:47 volumio sudo[19593]: pam_unix(sudo:session): session closed for user root Feb 08 03:44:48 volumio volumio[19516]: Starting albumart workers Feb 08 03:44:48 volumio volumio[19513]: Starting albumart workers Feb 08 03:44:48 volumio volumio[19380]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 08 03:44:48 volumio volumio[19380]: info: [1770497088685] CoreMusicLibrary::Adding element YouTube Music Feb 08 03:44:48 volumio volumio[19380]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 08 03:44:48 volumio volumio[19380]: Cannot find translation for source YouTube Music Feb 08 03:44:48 volumio volumio[19380]: info: Volumio Calling Home Feb 08 03:44:48 volumio sudo[19610]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Feb 08 03:44:48 volumio sudo[19610]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 03:44:48 volumio sudo[19610]: pam_unix(sudo:session): session closed for user root Feb 08 03:44:49 volumio volumio[19515]: Starting albumart workers Feb 08 03:44:49 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Feb 08 03:44:49 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 08 03:44:49 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 08 03:44:49 volumio go-librespot[19615]: go-librespot daemon starting... Feb 08 03:44:49 volumio go-librespot[19616]: time="2026-02-08T03:44:49+07:00" level=info msg="running go-librespot 0.4.0" Feb 08 03:44:49 volumio volumio[19380]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Feb 08 03:44:49 volumio volumio[19380]: info: Discovery: Found device Volumio Feb 08 03:44:49 volumio volumio[19380]: info: CoreCommandRouter::volumioGetState Feb 08 03:44:49 volumio volumio[19380]: info: CorePlayQueue::getTrack 0 Feb 08 03:44:49 volumio volumio[19380]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Feb 08 03:44:49 volumio volumio[19380]: info: Discovery: Found device Volumio Feb 08 03:44:49 volumio volumio[19380]: info: CoreCommandRouter::volumioGetState Feb 08 03:44:49 volumio volumio[19380]: info: CorePlayQueue::getTrack 0 Feb 08 03:44:49 volumio volumio[19380]: info: MPD Permissions set Feb 08 03:44:49 volumio volumio[19380]: info: MPD Permissions set Feb 08 03:44:49 volumio volumio[19380]: info: Upmpdcli Daemon Started Feb 08 03:44:49 volumio volumio[19380]: info: Volumio called home Feb 08 03:44:49 volumio volumio[19380]: info: Spotify config file written Feb 08 03:44:50 volumio sudo[19623]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 08 03:44:50 volumio sudo[19623]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 03:44:50 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Feb 08 03:44:50 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Feb 08 03:44:50 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 08 03:44:50 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 08 03:44:50 volumio go-librespot[19627]: go-librespot daemon starting... Feb 08 03:44:50 volumio sudo[19623]: pam_unix(sudo:session): session closed for user root Feb 08 03:44:50 volumio go-librespot[19628]: time="2026-02-08T03:44:50+07:00" level=info msg="running go-librespot 0.4.0" Feb 08 03:44:50 volumio go-librespot[19628]: time="2026-02-08T03:44:50+07:00" level=debug msg="app state loaded" Feb 08 03:44:50 volumio volumio[19380]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Feb 08 03:44:50 volumio go-librespot[19628]: time="2026-02-08T03:44:50+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 08 03:44:50 volumio volumio[19380]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 03:44:50 volumio volumio[19380]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 03:44:50 volumio volumio[19380]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 03:44:50 volumio volumio[19380]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 03:44:50 volumio volumio[19380]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 03:44:50 volumio volumio[19380]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 03:44:50 volumio volumio[19380]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 03:44:50 volumio volumio[19380]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 03:44:50 volumio volumio[19380]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 08 03:44:50 volumio volumio[19380]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 03:44:50 volumio volumio[19380]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 03:44:50 volumio volumio[19380]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 03:44:50 volumio volumio[19380]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 03:44:50 volumio volumio[19380]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 03:44:50 volumio volumio[19380]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 03:44:50 volumio volumio[19380]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 03:44:50 volumio volumio[19380]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 03:44:50 volumio volumio[19380]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 03:44:50 volumio volumio[19380]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 08 03:44:50 volumio volumio[19380]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 03:44:50 volumio volumio[19380]: info: No need to fix Spotify hosts Feb 08 03:44:51 volumio go-librespot[19628]: time="2026-02-08T03:44:51+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]" Feb 08 03:44:51 volumio go-librespot[19628]: time="2026-02-08T03:44:51+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]" Feb 08 03:44:51 volumio go-librespot[19628]: time="2026-02-08T03:44:51+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]" Feb 08 03:44:51 volumio go-librespot[19628]: time="2026-02-08T03:44:51+07:00" level=info msg="zeroconf server listening on port 38213" Feb 08 03:44:51 volumio go-librespot[19628]: time="2026-02-08T03:44:51+07:00" level=debug msg="obtained new client token: AACeVCUaj79GVm6kzRBqcq1FVBAX5qx+jY/iZBa4JtWoh0fzpm0emNbB272SmjYM2xZPOlcImtggpazAUrL3FgTIaT/lvhmkruu9ApARx9GYyLHHx/fd/eBb04rV6eOi82RibTYqY5qQUh3JMA5TT6tICDXNGkDVUcpNzQ8Aoqfwgz4XEt7ncUv+5viSmsAZ6qqVgv/XlUEFR5opBLd/GenSr96iRVJD7v9ygiyF8Bf6DgMfO/lVJwQBTQ==" Feb 08 03:44:51 volumio go-librespot[19628]: time="2026-02-08T03:44:51+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 08 03:44:51 volumio volumio[19380]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 08 03:44:51 volumio volumio[19380]: SPOTIFY: BQBVijfx-7uRAu10o_UyiafCeremlBB-9g70jXKTlNzdPP3iMhbh5Umg7TxexdwMJO3EywZYVzh56q4zhhRoQwwCrNcE81tTiIOW3r_OYsc1LUiHDL1joBNorzYgrZwlBqRJwMuNHJC5WjJ12LZU-h0yeHy2zls_XDl5lvEatVE9ZPQdWWT3IVKv64QHUb2-XJbVcTZl4YamHGQ7c6aNb8xSnT2NsDHaOcbMC37t9xLpPsYLGJ7InHfepbTj37dTw5RyfMLclH3jwmTQH8yiozNUZZJ8B9KoJiw5YF76p5VfSChCly5rwdYD Feb 08 03:44:51 volumio volumio[19380]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 08 03:44:51 volumio volumio[19380]: info: New Spotify access token = BQBVijfx-7uRAu10o_UyiafCeremlBB-9g70jXKTlNzdPP3iMhbh5Umg7TxexdwMJO3EywZYVzh56q4zhhRoQwwCrNcE81tTiIOW3r_OYsc1LUiHDL1joBNorzYgrZwlBqRJwMuNHJC5WjJ12LZU-h0yeHy2zls_XDl5lvEatVE9ZPQdWWT3IVKv64QHUb2-XJbVcTZl4YamHGQ7c6aNb8xSnT2NsDHaOcbMC37t9xLpPsYLGJ7InHfepbTj37dTw5RyfMLclH3jwmTQH8yiozNUZZJ8B9KoJiw5YF76p5VfSChCly5rwdYD Feb 08 03:44:51 volumio volumio[19380]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 08 03:44:51 volumio volumio[19380]: info: Starting Shairport Sync Feb 08 03:44:51 volumio volumio[19380]: info: Starting Shairport Sync Feb 08 03:44:51 volumio go-librespot[19628]: time="2026-02-08T03:44:51+07:00" level=debug msg="completed keyexchange" Feb 08 03:44:51 volumio go-librespot[19628]: time="2026-02-08T03:44:51+07:00" level=debug msg="completed challenge" Feb 08 03:44:51 volumio volumio[19380]: info: Starting Shairport Sync Feb 08 03:44:51 volumio sudo[19664]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 08 03:44:51 volumio sudo[19664]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 03:44:51 volumio sudo[19666]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 08 03:44:51 volumio sudo[19666]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 03:44:51 volumio go-librespot[19628]: time="2026-02-08T03:44:51+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 08 03:44:51 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 08 03:44:51 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 08 03:44:51 volumio sudo[19669]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 08 03:44:51 volumio sudo[19669]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 03:44:52 volumio volumio[19380]: info: CoreCommandRouter::volumioGetState Feb 08 03:44:52 volumio volumio[19380]: info: CorePlayQueue::getTrack 0 Feb 08 03:44:52 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 08 03:44:52 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 08 03:44:52 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 08 03:44:52 volumio systemd[1]: shairport-sync.service: Consumed 2.304s CPU time. Feb 08 03:44:52 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 08 03:44:52 volumio sudo[19666]: pam_unix(sudo:session): session closed for user root Feb 08 03:44:52 volumio sudo[19664]: pam_unix(sudo:session): session closed for user root Feb 08 03:44:52 volumio sudo[19669]: pam_unix(sudo:session): session closed for user root Feb 08 03:44:52 volumio volumio[19380]: info: Shairport-Sync Started Feb 08 03:44:52 volumio volumio[19380]: Error adding Membership: Error: addMembership EINVAL Feb 08 03:44:52 volumio volumio[19380]: info: Shairport-Sync Started Feb 08 03:44:52 volumio volumio[19380]: info: Shairport-Sync Started Feb 08 03:44:52 volumio volumio[19380]: 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"} Feb 08 03:44:52 volumio volumio[19380]: info: Spotify Successfully logged in Feb 08 03:44:52 volumio volumio[19380]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 08 03:44:52 volumio volumio[19380]: info: [1770497092463] CoreMusicLibrary::Adding element Spotify Feb 08 03:44:52 volumio volumio[19380]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 08 03:44:52 volumio volumio[19380]: Cannot find translation for source YouTube Music Feb 08 03:44:52 volumio volumio[19380]: Cannot find translation for source Spotify Feb 08 03:44:53 volumio volumio[19380]: info: [yt-cast-receiver] DIAL server listening on port 8098 Feb 08 03:44:53 volumio volumio[19380]: info: CoreCommandRouter::volumioRetrievevolume Feb 08 03:44:53 volumio volumio[19380]: info: VolumeController:: Volume=100 Mute =false Feb 08 03:44:53 volumio volumio[19380]: info: CoreCommandRouter::volumioGetState Feb 08 03:44:53 volumio volumio[19380]: info: CorePlayQueue::getTrack 0 Feb 08 03:44:53 volumio volumio[19380]: info: CoreStateMachine::pushState Feb 08 03:44:53 volumio volumio[19380]: info: CorePlayQueue::getTrack 0 Feb 08 03:44:53 volumio volumio[19380]: info: CoreCommandRouter::volumioPushState Feb 08 03:44:54 volumio volumio[19380]: info: go-librespot daemon successfully initialized Feb 08 03:44:54 volumio mpd[19608]: 2026-02-08T03:44:54 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 08 03:44:54 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Feb 08 03:44:54 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 08 03:44:54 volumio sudo[19568]: pam_unix(sudo:session): session closed for user root Feb 08 03:44:54 volumio sudo[19579]: pam_unix(sudo:session): session closed for user root Feb 08 03:44:54 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 08 03:44:55 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 08 03:44:55 volumio go-librespot[19706]: go-librespot daemon starting... Feb 08 03:44:55 volumio go-librespot[19709]: time="2026-02-08T03:44:55+07:00" level=info msg="running go-librespot 0.4.0" Feb 08 03:44:55 volumio go-librespot[19709]: time="2026-02-08T03:44:55+07:00" level=debug msg="app state loaded" Feb 08 03:44:55 volumio go-librespot[19709]: time="2026-02-08T03:44:55+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 08 03:44:55 volumio volumio[19380]: error: MPD error: The expression evaluated to a falsy value: Feb 08 03:44:55 volumio volumio[19380]: assert.ok(self.idling) Feb 08 03:44:55 volumio volumio[19380]: error: The expression evaluated to a falsy value: Feb 08 03:44:55 volumio volumio[19380]: assert.ok(self.idling) Feb 08 03:44:55 volumio volumio[19380]: error: updateQueue error: null Feb 08 03:44:55 volumio volumio[19380]: info: MPD running with PID19608 Feb 08 03:44:55 volumio volumio[19380]: ,establishing connection Feb 08 03:44:55 volumio volumio[19380]: info: Completed starting Core Plugins Feb 08 03:44:55 volumio volumio[19380]: info: ------------------------------------------- Feb 08 03:44:55 volumio volumio[19380]: info: ----- MyVolumio plugins startup ---- Feb 08 03:44:55 volumio volumio[19380]: info: ------------------------------------------- Feb 08 03:44:55 volumio volumio[19380]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 08 03:44:55 volumio volumio[19380]: error: updateQueue error: null Feb 08 03:44:55 volumio go-librespot[19709]: time="2026-02-08T03:44:55+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 08 03:44:55 volumio go-librespot[19709]: time="2026-02-08T03:44:55+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]" Feb 08 03:44:55 volumio go-librespot[19709]: time="2026-02-08T03:44:55+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]" Feb 08 03:44:55 volumio go-librespot[19709]: time="2026-02-08T03:44:55+07:00" level=info msg="zeroconf server listening on port 45661" Feb 08 03:44:55 volumio go-librespot[19709]: time="2026-02-08T03:44:55+07:00" level=debug msg="obtained new client token: AADo9BiUBdgoVoUCMwJfOUFejFStdPDyzDFL5Qb/VB0nE0NXA9BZQ7/m7KXJibrMNJFB/sAiG6vYjzoXDrIohnhchhC54qbaLxSUCBpIJds9FANgGzTF5F/Fr31milFnDsbVIqoizM5eg8+96/I9iByCdtkwocWGLIci2NlAD2OP6pfryOIcLVUhtVzFCMwmdQI0HVsbNuha847DYXjGWuj+FcTxR97cySw3LSdiGnWlVTWqr22eq+pA4A==" Feb 08 03:44:55 volumio go-librespot[19709]: time="2026-02-08T03:44:55+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 08 03:44:55 volumio go-librespot[19709]: time="2026-02-08T03:44:55+07:00" level=debug msg="completed keyexchange" Feb 08 03:44:55 volumio go-librespot[19709]: time="2026-02-08T03:44:55+07:00" level=debug msg="completed challenge" Feb 08 03:44:56 volumio go-librespot[19709]: time="2026-02-08T03:44:56+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 " Feb 08 03:44:56 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 08 03:44:56 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 08 03:44:57 volumio volumio[19380]: info: Initializing connection to go-librespot Websocket Feb 08 03:44:57 volumio volumio[19380]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 08 03:44:59 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Feb 08 03:44:59 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 08 03:44:59 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 08 03:44:59 volumio go-librespot[19716]: go-librespot daemon starting... Feb 08 03:44:59 volumio go-librespot[19717]: time="2026-02-08T03:44:59+07:00" level=info msg="running go-librespot 0.4.0" Feb 08 03:44:59 volumio go-librespot[19717]: time="2026-02-08T03:44:59+07:00" level=debug msg="app state loaded" Feb 08 03:44:59 volumio go-librespot[19717]: time="2026-02-08T03:44:59+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 08 03:44:59 volumio go-librespot[19717]: time="2026-02-08T03:44:59+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 08 03:44:59 volumio go-librespot[19717]: time="2026-02-08T03:44:59+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]" Feb 08 03:44:59 volumio go-librespot[19717]: time="2026-02-08T03:44:59+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]" Feb 08 03:44:59 volumio go-librespot[19717]: time="2026-02-08T03:44:59+07:00" level=info msg="zeroconf server listening on port 33259" Feb 08 03:45:00 volumio volumio[19380]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 08 03:45:00 volumio go-librespot[19717]: time="2026-02-08T03:45:00+07:00" level=debug msg="obtained new client token: AABbtGOBgw7HmZObuAlUPS/mSx2Eb0mMunyUKkzdMuMx5/QFsbGiu0vWdnxJ6DRiQ0II8Zk3RZXOQCuJIJdeDXe+FxOB4s0KdZALMciG868OvTifgV4kbRKoOJoLXz+G4VsIXzCV7ctYGt9fqGUAiX0mwZDcBwGiTM2NNARd1fm+MzBD0GDCUk32Fv6mT3iZBZhgTZ8LMQeGNzX2Zuag5uOmm+SLSQNR2lx8w1MQPkjBQanKFBrVI+U=" Feb 08 03:45:00 volumio go-librespot[19717]: time="2026-02-08T03:45:00+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 08 03:45:00 volumio go-librespot[19717]: time="2026-02-08T03:45:00+07:00" level=debug msg="completed keyexchange" Feb 08 03:45:00 volumio go-librespot[19717]: time="2026-02-08T03:45:00+07:00" level=debug msg="completed challenge" Feb 08 03:45:00 volumio go-librespot[19717]: time="2026-02-08T03:45:00+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 08 03:45:00 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 08 03:45:00 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 08 03:45:00 volumio volumio[19380]: info: Initializing connection to go-librespot Websocket Feb 08 03:45:00 volumio volumio[19380]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 08 03:45:03 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Feb 08 03:45:03 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 08 03:45:03 volumio volumio[19380]: info: Initializing connection to go-librespot Websocket Feb 08 03:45:03 volumio volumio[19380]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 08 03:45:03 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 08 03:45:03 volumio go-librespot[19726]: go-librespot daemon starting... Feb 08 03:45:03 volumio go-librespot[19727]: time="2026-02-08T03:45:03+07:00" level=info msg="running go-librespot 0.4.0" Feb 08 03:45:03 volumio go-librespot[19727]: time="2026-02-08T03:45:03+07:00" level=debug msg="app state loaded" Feb 08 03:45:03 volumio go-librespot[19727]: time="2026-02-08T03:45:03+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 08 03:45:04 volumio volumio[19380]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 08 03:45:04 volumio volumio[19380]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 08 03:45:04 volumio volumio[19380]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 08 03:45:04 volumio volumio[19380]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 08 03:45:04 volumio volumio[19380]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 08 03:45:04 volumio volumio[19380]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 08 03:45:04 volumio volumio[19380]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 08 03:45:04 volumio volumio[19380]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 08 03:45:04 volumio volumio[19380]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 08 03:45:04 volumio volumio[19380]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 08 03:45:04 volumio volumio[19380]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 08 03:45:04 volumio volumio[19380]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 08 03:45:04 volumio volumio[19380]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 08 03:45:04 volumio volumio[19380]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 08 03:45:04 volumio volumio[19380]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 08 03:45:04 volumio volumio[19380]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 08 03:45:04 volumio volumio[19380]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 08 03:45:04 volumio volumio[19380]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 08 03:45:04 volumio volumio[19380]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 08 03:45:04 volumio volumio[19380]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 08 03:45:04 volumio volumio[19380]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 08 03:45:04 volumio volumio[19380]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 08 03:45:04 volumio volumio[19380]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 08 03:45:04 volumio volumio[19380]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 08 03:45:04 volumio volumio[19380]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 08 03:45:04 volumio volumio[19380]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 08 03:45:04 volumio volumio[19380]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 08 03:45:04 volumio volumio[19380]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 08 03:45:04 volumio volumio[19380]: info: Adding plugin bluetooth to MyMusic Plugins Feb 08 03:45:04 volumio volumio[19380]: info: Adding plugin multiroom to MyMusic Plugins Feb 08 03:45:04 volumio volumio[19380]: info: Adding plugin metavolumio to MyMusic Plugins Feb 08 03:45:04 volumio volumio[19380]: info: Adding plugin cd_controller to MyMusic Plugins Feb 08 03:45:04 volumio volumio[19380]: info: Adding plugin qobuzconnect to MyMusic Plugins Feb 08 03:45:04 volumio volumio[19380]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 08 03:45:04 volumio volumio[19380]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 08 03:45:04 volumio volumio[19380]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 08 03:45:04 volumio go-librespot[19727]: time="2026-02-08T03:45:04+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 08 03:45:04 volumio go-librespot[19727]: time="2026-02-08T03:45:04+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]" Feb 08 03:45:04 volumio go-librespot[19727]: time="2026-02-08T03:45:04+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]" Feb 08 03:45:04 volumio go-librespot[19727]: time="2026-02-08T03:45:04+07:00" level=info msg="zeroconf server listening on port 40969" Feb 08 03:45:04 volumio go-librespot[19727]: time="2026-02-08T03:45:04+07:00" level=debug msg="obtained new client token: AACp+YbD85N0aS3pYE+cO+mv/i0sg9AYkNRpTFVkSlFQ/jdyVFsgtF7F8x7z7s83kpTmtiakbXVCSM5gjQA3KPnCsKFwCwyvItq2bTm/Lxv3OOahSg1LK+YJjC1AkWVANFIi+aJb0c2gA5VsgjlpOUs20qsLJRFTrhBhaPKqnHKyRuFlvnl52xs6X6J5RBwHHyKqkpnc8A0XMHf7/ZFacLraa3JqOjXr5W/9PmHFKWcv3NU+VxYAkUyihg==" Feb 08 03:45:04 volumio go-librespot[19727]: time="2026-02-08T03:45:04+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 08 03:45:04 volumio go-librespot[19727]: time="2026-02-08T03:45:04+07:00" level=debug msg="completed keyexchange" Feb 08 03:45:04 volumio go-librespot[19727]: time="2026-02-08T03:45:04+07:00" level=debug msg="completed challenge" Feb 08 03:45:04 volumio go-librespot[19727]: time="2026-02-08T03:45:04+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 " Feb 08 03:45:04 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 08 03:45:04 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 08 03:45:05 volumio volumio[19380]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 08 03:45:05 volumio volumio[19380]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 08 03:45:05 volumio volumio[19380]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 08 03:45:05 volumio volumio[19380]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 08 03:45:05 volumio volumio[19380]: info: Starting MyVolumio Remote Streaming Endpoints Feb 08 03:45:05 volumio volumio[19380]: info: MyVolumio login type: Token Feb 08 03:45:05 volumio volumio[19380]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 08 03:45:05 volumio volumio[19380]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 08 03:45:07 volumio volumio[19380]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 08 03:45:07 volumio volumio[19380]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 08 03:45:07 volumio volumio[19380]: info: Streaming services startup Feb 08 03:45:07 volumio volumio[19380]: info: Starting Streaming Daemon Feb 08 03:45:07 volumio sudo[19750]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 08 03:45:07 volumio sudo[19750]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 03:45:07 volumio volumio[19380]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 08 03:45:07 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Feb 08 03:45:07 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 08 03:45:07 volumio volumio[19380]: info: Initializing connection to go-librespot Websocket Feb 08 03:45:07 volumio volumio[19380]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 08 03:45:07 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 08 03:45:07 volumio go-librespot[19756]: go-librespot daemon starting... Feb 08 03:45:07 volumio sudo[19750]: pam_unix(sudo:session): session closed for user root Feb 08 03:45:07 volumio volumio[19380]: error: Cannot start Volumio Streaming Daemon Feb 08 03:45:07 volumio volumio[19380]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 08 03:45:07 volumio volumio[19380]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 08 03:45:07 volumio go-librespot[19758]: time="2026-02-08T03:45:07+07:00" level=info msg="running go-librespot 0.4.0" Feb 08 03:45:07 volumio go-librespot[19758]: time="2026-02-08T03:45:07+07:00" level=debug msg="app state loaded" Feb 08 03:45:07 volumio go-librespot[19758]: time="2026-02-08T03:45:07+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 08 03:45:08 volumio go-librespot[19758]: time="2026-02-08T03:45:08+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]" Feb 08 03:45:08 volumio go-librespot[19758]: time="2026-02-08T03:45:08+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]" Feb 08 03:45:08 volumio go-librespot[19758]: time="2026-02-08T03:45:08+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]" Feb 08 03:45:08 volumio go-librespot[19758]: time="2026-02-08T03:45:08+07:00" level=info msg="zeroconf server listening on port 36631" Feb 08 03:45:08 volumio go-librespot[19758]: time="2026-02-08T03:45:08+07:00" level=debug msg="obtained new client token: AAA8edVBEEMIKsv1icTkDzlpd3uTp9QHWMFb0K9ACfTYk+xIqZLyBO8x9xpUZ0/oS4uq5wYqFuA2ADxecJKsUmpAK0eVBOA2QmGqbSX27QFwmXVdC7/CY6lYXsRMVEvIMHcqw/u8kW5xR+HvtsbJR6EixD04OyP9+OUxeY8EMTaFu+hniJ02kHfeVkbzke1F+vPk1886zljT8l4SgcNJPg2C3AGPG/ka2Cen7AYg1Mv+QoqbC+mjE+rBPQ==" Feb 08 03:45:08 volumio go-librespot[19758]: time="2026-02-08T03:45:08+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 08 03:45:08 volumio volumio[19380]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Feb 08 03:45:08 volumio go-librespot[19758]: time="2026-02-08T03:45:08+07:00" level=debug msg="completed keyexchange" Feb 08 03:45:08 volumio go-librespot[19758]: time="2026-02-08T03:45:08+07:00" level=debug msg="completed challenge" Feb 08 03:45:08 volumio go-librespot[19758]: time="2026-02-08T03:45:08+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 08 03:45:08 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 08 03:45:08 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 08 03:45:09 volumio volumio[19380]: info: MyVolumio token set successfully Feb 08 03:45:09 volumio volumio[19380]: info: MYVOLUMIO: Adding device Feb 08 03:45:09 volumio volumio[19380]: info: MYVOLUMIO: Evaluating Server Feb 08 03:45:10 volumio volumio[19380]: info: MyVolumio status changed Feb 08 03:45:10 volumio volumio[19380]: info: Streaming services startup Feb 08 03:45:10 volumio volumio[19380]: info: Starting Streaming Daemon Feb 08 03:45:10 volumio volumio[19380]: info: Removing browser output: myVolumio user plan is not superstar Feb 08 03:45:10 volumio volumio[19380]: info: Removing audio output: Feb 08 03:45:10 volumio volumio[19380]: info: Stoppping Tunnel 1 Feb 08 03:45:10 volumio sudo[19786]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 08 03:45:10 volumio sudo[19786]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 03:45:10 volumio sudo[19786]: pam_unix(sudo:session): session closed for user root Feb 08 03:45:10 volumio sudo[19789]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Feb 08 03:45:10 volumio sudo[19789]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 03:45:10 volumio volumio[19380]: error: Cannot start Volumio Streaming Daemon Feb 08 03:45:10 volumio volumio[19380]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 08 03:45:10 volumio volumio[19380]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 08 03:45:10 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 08 03:45:10 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 08 03:45:10 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 08 03:45:10 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 08 03:45:10 volumio volumio[19380]: info: Setting Geolocation for MyVolumio to as1 Feb 08 03:45:10 volumio volumio[19380]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 08 03:45:10 volumio volumio[19380]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 08 03:45:10 volumio volumio[19380]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 08 03:45:10 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 08 03:45:10 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 08 03:45:10 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 08 03:45:10 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 08 03:45:10 volumio sudo[19789]: pam_unix(sudo:session): session closed for user root Feb 08 03:45:10 volumio volumio[19380]: info: Remote SSH Stopped Feb 08 03:45:10 volumio volumio[19380]: info: Initializing connection to go-librespot Websocket Feb 08 03:45:10 volumio volumio[19380]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 08 03:45:10 volumio volumio[19380]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Feb 08 03:45:11 volumio volumio[19380]: info: Updating MyVolumio device info Feb 08 03:45:11 volumio volumio[19380]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 08 03:45:11 volumio volumio[19380]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 08 03:45:11 volumio volumio[19380]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 08 03:45:11 volumio volumio[19380]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Feb 08 03:45:12 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Feb 08 03:45:12 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 08 03:45:12 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 08 03:45:12 volumio go-librespot[19791]: go-librespot daemon starting... Feb 08 03:45:12 volumio go-librespot[19792]: time="2026-02-08T03:45:12+07:00" level=info msg="running go-librespot 0.4.0" Feb 08 03:45:12 volumio go-librespot[19792]: time="2026-02-08T03:45:12+07:00" level=debug msg="app state loaded" Feb 08 03:45:12 volumio go-librespot[19792]: time="2026-02-08T03:45:12+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 08 03:45:12 volumio go-librespot[19792]: time="2026-02-08T03:45:12+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]" Feb 08 03:45:12 volumio go-librespot[19792]: time="2026-02-08T03:45:12+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]" Feb 08 03:45:12 volumio go-librespot[19792]: time="2026-02-08T03:45:12+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]" Feb 08 03:45:12 volumio go-librespot[19792]: time="2026-02-08T03:45:12+07:00" level=info msg="zeroconf server listening on port 34071" Feb 08 03:45:12 volumio go-librespot[19792]: time="2026-02-08T03:45:12+07:00" level=debug msg="obtained new client token: AACxk/jfuWe1X/TxKkNqQr0umq86VWBXXF5U2nxYSBKhlAsX6iNeKfqhwd54XxlvY5MVt3Dvzgv7UbBdKA8oi7VVKzwA2km/qBTpLpjf1Q/LReObtEoZV1/Azh4uWeBD7t/DM35iT7Vj2yxSrxz11WJu7+Fo4betP35k+Z7WE0MFhb6RjwSBwXzlzmK8ln4IHlnAgabhVOl2XI16w7eNr/oqJbyiq0Ydy1Jw8hLeXGWHY5j8HqYI2jlBBw==" Feb 08 03:45:12 volumio go-librespot[19792]: time="2026-02-08T03:45:12+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 08 03:45:13 volumio go-librespot[19792]: time="2026-02-08T03:45:13+07:00" level=debug msg="completed keyexchange" Feb 08 03:45:13 volumio go-librespot[19792]: time="2026-02-08T03:45:13+07:00" level=debug msg="completed challenge" Feb 08 03:45:13 volumio go-librespot[19792]: time="2026-02-08T03:45:13+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 " Feb 08 03:45:13 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 08 03:45:13 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 08 03:45:13 volumio volumio[19380]: info: Initializing connection to go-librespot Websocket Feb 08 03:45:13 volumio volumio[19380]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 08 03:45:14 volumio volumio[19380]: info: MYVOLUMIO: Adding device Feb 08 03:45:14 volumio volumio[19380]: info: MYVOLUMIO: Evaluating Server Feb 08 03:45:15 volumio volumio[19380]: info: Setting Geolocation for MyVolumio to as1 Feb 08 03:45:15 volumio volumio[19380]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 08 03:45:15 volumio volumio[19380]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 08 03:45:15 volumio volumio[19380]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 08 03:45:16 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Feb 08 03:45:16 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 08 03:45:16 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 08 03:45:16 volumio go-librespot[19831]: go-librespot daemon starting... Feb 08 03:45:16 volumio go-librespot[19832]: time="2026-02-08T03:45:16+07:00" level=info msg="running go-librespot 0.4.0" Feb 08 03:45:16 volumio go-librespot[19832]: time="2026-02-08T03:45:16+07:00" level=debug msg="app state loaded" Feb 08 03:45:16 volumio go-librespot[19832]: time="2026-02-08T03:45:16+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 08 03:45:16 volumio volumio[19380]: info: Updating MyVolumio device info Feb 08 03:45:16 volumio volumio[19380]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 08 03:45:16 volumio volumio[19380]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 08 03:45:16 volumio volumio[19380]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 08 03:45:16 volumio go-librespot[19832]: time="2026-02-08T03:45:16+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 08 03:45:16 volumio go-librespot[19832]: time="2026-02-08T03:45:16+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 08 03:45:16 volumio go-librespot[19832]: time="2026-02-08T03:45:16+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 08 03:45:16 volumio go-librespot[19832]: time="2026-02-08T03:45:16+07:00" level=info msg="zeroconf server listening on port 39241" Feb 08 03:45:16 volumio volumio[19380]: info: Initializing connection to go-librespot Websocket Feb 08 03:45:16 volumio go-librespot[19832]: time="2026-02-08T03:45:16+07:00" level=debug msg="new websocket client" Feb 08 03:45:16 volumio volumio[19380]: info: Connection to go-librespot Websocket established Feb 08 03:45:17 volumio go-librespot[19832]: time="2026-02-08T03:45:17+07:00" level=debug msg="obtained new client token: AAABln0vA6tD7dtVdv0trc8WponIcx3wi6Rh56G5KUaKgdmLOC6+aewuH3hBh2xMS356IklkQ4X2MEMk9Mu/xO1vcGY/uvzxSWyHFcz7sedQpl5iagZztxm9SxGrAzYXT4mnc7dnjex8Prw0nPnyH7+knzlHMjSI2DPimuQzeB4ODUPxWQUUPeQovzvQVw2J+WklT1fMp2+4YS4H//2H/RPZEXydTvJv7bcYO31D8RnGYsVJTP28Y98=" Feb 08 03:45:17 volumio go-librespot[19832]: time="2026-02-08T03:45:17+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 08 03:45:17 volumio volumio[19380]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Feb 08 03:45:17 volumio go-librespot[19832]: time="2026-02-08T03:45:17+07:00" level=debug msg="completed keyexchange" Feb 08 03:45:17 volumio go-librespot[19832]: time="2026-02-08T03:45:17+07:00" level=debug msg="completed challenge" Feb 08 03:45:17 volumio go-librespot[19832]: time="2026-02-08T03:45:17+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 " Feb 08 03:45:17 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 08 03:45:17 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 08 03:45:17 volumio volumio[19380]: info: Connection to go-librespot Websocket closed Feb 08 03:45:17 volumio volumio[19380]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Feb 08 03:45:18 volumio volumio[19380]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 08 03:45:18 volumio volumio[19380]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 08 03:45:18 volumio volumio[19380]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Feb 08 03:45:19 volumio volumio-remote-updater[643]: Test mode disabled Feb 08 03:45:19 volumio volumio-remote-updater[643]: Alpha mode disabled Feb 08 03:45:19 volumio volumio-remote-updater[643]: Alpha legacy test mode disabled Feb 08 03:45:19 volumio volumio[19380]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled Feb 08 03:45:19 volumio volumio[19380]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Feb 08 03:45:19 volumio volumio[19380]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Feb 08 03:45:19 volumio volumio[19380]: info: Getting Spotify volume Feb 08 03:45:19 volumio volumio[19380]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 08 03:45:20 volumio volumio[19380]: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 08 03:45:20 volumio volumio[19380]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Feb 08 03:45:20 volumio volumio[19380]: errno: -111, Feb 08 03:45:20 volumio volumio[19380]: code: 'ECONNREFUSED', Feb 08 03:45:20 volumio volumio[19380]: syscall: 'connect', Feb 08 03:45:20 volumio volumio[19380]: address: '127.0.0.1', Feb 08 03:45:20 volumio volumio[19380]: port: 9879, Feb 08 03:45:20 volumio volumio[19380]: response: undefined Feb 08 03:45:20 volumio volumio[19380]: } Feb 08 03:45:20 volumio volumio[19380]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 08 03:45:20 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Feb 08 03:45:20 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 08 03:45:20 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 08 03:45:20 volumio go-librespot[19855]: go-librespot daemon starting... Feb 08 03:45:20 volumio go-librespot[19856]: time="2026-02-08T03:45:20+07:00" level=info msg="running go-librespot 0.4.0" Feb 08 03:45:20 volumio go-librespot[19856]: time="2026-02-08T03:45:20+07:00" level=debug msg="app state loaded" Feb 08 03:45:20 volumio go-librespot[19856]: time="2026-02-08T03:45:20+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 08 03:45:21 volumio go-librespot[19856]: time="2026-02-08T03:45:21+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 08 03:45:21 volumio go-librespot[19856]: time="2026-02-08T03:45:21+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 08 03:45:21 volumio go-librespot[19856]: time="2026-02-08T03:45:21+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 08 03:45:21 volumio go-librespot[19856]: time="2026-02-08T03:45:21+07:00" level=info msg="zeroconf server listening on port 41583" Feb 08 03:45:21 volumio go-librespot[19856]: time="2026-02-08T03:45:21+07:00" level=debug msg="obtained new client token: AADz8UyVXHkfrbfka6RYPIh702T+DzbJ0mXDEdh6vGrznrq8gtIPmV2E3rKZwZaFQ4oDowqDmhJQ8MP6X93MUg2Qp9hnMcAr3VAG2cTNHM2GnW+RbKDwJzWvjNadL3//gb8i33snPYtVBHBmrN90/GwTRc1mDastgLFug8YIYZvKsxnmuTt/3632ps6pU4cC+3/mdd75dnbUqnMyNk2NJtIEsLljv4pqpos8g9/ud8SaNw6iMK31d3vkZA==" Feb 08 03:45:21 volumio go-librespot[19856]: time="2026-02-08T03:45:21+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 08 03:45:21 volumio sudo[19865]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-08 03:44' Feb 08 03:45:21 volumio sudo[19865]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 03:45:21 volumio go-librespot[19856]: time="2026-02-08T03:45:21+07:00" level=debug msg="completed keyexchange" Feb 08 03:45:21 volumio go-librespot[19856]: time="2026-02-08T03:45:21+07:00" level=debug msg="completed challenge" Feb 08 03:45:21 volumio go-librespot[19856]: time="2026-02-08T03:45:21+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 08 03:45:21 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 08 03:45:21 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. 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"