Feb 10 16:17:00 volumio volumio[6503]: info: Starting UPNP Browser Feb 10 16:17:00 volumio volumio[6503]: info: Loading plugin "alarm-clock"... Feb 10 16:17:00 volumio volumio[6503]: info: Loading plugin "airplay_emulation"... Feb 10 16:17:00 volumio volumio[6503]: info: Starting Shairport Sync Feb 10 16:17:00 volumio volumio[6503]: info: Loading plugin "last_100"... Feb 10 16:17:00 volumio volumio[6503]: info: Loading plugin "webradio"... Feb 10 16:17:00 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 46. Feb 10 16:17:00 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 16:17:00 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 16:17:00 volumio go-librespot[6582]: go-librespot daemon starting... Feb 10 16:17:00 volumio go-librespot[6583]: time="2026-02-10T16:17:00+07:00" level=info msg="running go-librespot 0.4.0" Feb 10 16:17:00 volumio go-librespot[6583]: time="2026-02-10T16:17:00+07:00" level=debug msg="app state loaded" Feb 10 16:17:00 volumio go-librespot[6583]: time="2026-02-10T16:17:00+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 16:17:00 volumio volumio[6503]: info: Loading plugin "i2s_dacs"... Feb 10 16:17:00 volumio volumio[6503]: info: Loading plugin "volumiodiscovery"... Feb 10 16:17:00 volumio volumio[6503]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 10 16:17:00 volumio volumio[6503]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 10 16:17:00 volumio volumio[6503]: *** WARNING *** For more information see Feb 10 16:17:00 volumio volumio[6503]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 10 16:17:00 volumio volumio[6503]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 10 16:17:00 volumio volumio[6503]: *** WARNING *** For more information see Feb 10 16:17:00 volumio node[6503]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 10 16:17:00 volumio node[6503]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 10 16:17:00 volumio node[6503]: *** WARNING *** For more information see Feb 10 16:17:00 volumio node[6503]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 10 16:17:00 volumio node[6503]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 10 16:17:00 volumio node[6503]: *** WARNING *** For more information see Feb 10 16:17:00 volumio volumio[6503]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 10 16:17:00 volumio volumio[6503]: info: Discovery: Started advertising with name: Volumio Feb 10 16:17:00 volumio volumio[6503]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 10 16:17:00 volumio volumio[6503]: info: Loading plugin "spop"... Feb 10 16:17:01 volumio go-librespot[6583]: time="2026-02-10T16:17:01+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 10 16:17:01 volumio go-librespot[6583]: time="2026-02-10T16:17:01+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 10 16:17:01 volumio go-librespot[6583]: time="2026-02-10T16:17:01+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 10 16:17:01 volumio go-librespot[6583]: time="2026-02-10T16:17:01+07:00" level=info msg="zeroconf server listening on port 36251" Feb 10 16:17:01 volumio go-librespot[6583]: time="2026-02-10T16:17:01+07:00" level=debug msg="obtained new client token: AAD6RPwrQ52T11jw681k5iLnYNlf7WsLsarFuPJOjt6y06qQej9LoCF11f6NY/06KYzTzYGpPg7cNxGuaQwfHzKzgm3HCqY58nLEWHaDcbUCpJmwo3t29Tse8HwpvX9hc++stwbIGqzgHpIUmNYdZAY+Mf0HvfWwoGjhWLzMGpw0lRrRiI5Df2tV3avJOEmJ/+5ndG3yFKWH+v2sm5WmKkhvdA3DeZ+cwwAlrsv0qh+Co2Hl71r/RUqHXw==" Feb 10 16:17:01 volumio go-librespot[6583]: time="2026-02-10T16:17:01+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 10 16:17:01 volumio go-librespot[6583]: time="2026-02-10T16:17:01+07:00" level=debug msg="completed keyexchange" Feb 10 16:17:01 volumio go-librespot[6583]: time="2026-02-10T16:17:01+07:00" level=debug msg="completed challenge" Feb 10 16:17:01 volumio go-librespot[6583]: time="2026-02-10T16:17:01+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 10 16:17:01 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 16:17:01 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 16:17:02 volumio volumio[6503]: info: Loading plugin "ytcr"... Feb 10 16:17:04 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 47. Feb 10 16:17:04 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 16:17:04 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 16:17:04 volumio go-librespot[6593]: go-librespot daemon starting... Feb 10 16:17:04 volumio go-librespot[6594]: time="2026-02-10T16:17:04+07:00" level=info msg="running go-librespot 0.4.0" Feb 10 16:17:04 volumio go-librespot[6594]: time="2026-02-10T16:17:04+07:00" level=debug msg="app state loaded" Feb 10 16:17:04 volumio go-librespot[6594]: time="2026-02-10T16:17:04+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 16:17:05 volumio volumio[6503]: info: Loading plugin "ytmusic"... Feb 10 16:17:05 volumio go-librespot[6594]: time="2026-02-10T16:17:05+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 10 16:17:05 volumio go-librespot[6594]: time="2026-02-10T16:17:05+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 10 16:17:05 volumio go-librespot[6594]: time="2026-02-10T16:17:05+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 10 16:17:05 volumio go-librespot[6594]: time="2026-02-10T16:17:05+07:00" level=info msg="zeroconf server listening on port 38103" Feb 10 16:17:05 volumio go-librespot[6594]: time="2026-02-10T16:17:05+07:00" level=debug msg="obtained new client token: AAA5E3Dqr/hsjML+Zy5PsmZ0EDJkpxp/okuALFSOjEfw0d9XAPWa0Fljp8cusbnN0F8B8XyMj1+jiwYs4IdJsU5LArW/H9NUUcu+TWUHqOgFzh6sXmR3iEHFz9pU9Ma5eL4785pR/dkL/pEAu/yhgiS6/KbtHon+UcHzKajdyD0V3/SJj4aqG4SGpOoDT9YqoAO5BBn2PWDfk6sJSYcKpTfAFq0kbwsnTKnyXWJMt6hKzCeweM/8PWpqRQ==" Feb 10 16:17:05 volumio go-librespot[6594]: time="2026-02-10T16:17:05+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 10 16:17:05 volumio go-librespot[6594]: time="2026-02-10T16:17:05+07:00" level=debug msg="completed keyexchange" Feb 10 16:17:05 volumio go-librespot[6594]: time="2026-02-10T16:17:05+07:00" level=debug msg="completed challenge" Feb 10 16:17:06 volumio go-librespot[6594]: time="2026-02-10T16:17:06+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 10 16:17:06 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 16:17:06 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 16:17:06 volumio volumio-remote-updater[643]: [2026-02-10 16:17:06] [connect] Successful connection Feb 10 16:17:06 volumio volumio[6503]: info: Loading plugin "outputs"... Feb 10 16:17:06 volumio volumio[6503]: info: Loading plugin "albumart"... Feb 10 16:17:06 volumio volumio[6503]: info: Plugin example_plugin is not enabled Feb 10 16:17:06 volumio volumio[6503]: info: Loading plugin "inputs"... Feb 10 16:17:06 volumio volumio[6503]: info: Loading plugin "updater_comm"... Feb 10 16:17:06 volumio volumio[6503]: info: Plugin mpdemulation is not enabled Feb 10 16:17:06 volumio volumio[6503]: info: Loading plugin "rest_api"... Feb 10 16:17:06 volumio volumio[6503]: info: Loading plugin "websocket"... Feb 10 16:17:06 volumio volumio[6503]: info: Starting Socket.io Server version 1.7.4 Feb 10 16:17:06 volumio volumio[6503]: info: Loading plugin "RoonBridge"... Feb 10 16:17:07 volumio volumio[6503]: info: Applying required configuration parameters for plugin RoonBridge Feb 10 16:17:07 volumio volumio[6503]: info: Loading i18n strings for locale en Feb 10 16:17:07 volumio volumio[6503]: Updating browse sources language Feb 10 16:17:07 volumio volumio[6503]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 10 16:17:07 volumio volumio[6615]: Forking 3 albumart workers Feb 10 16:17:07 volumio volumio[6503]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 10 16:17:07 volumio volumio[6503]: info: CoreCommandRouter::initPlayerControls Feb 10 16:17:07 volumio volumio[6503]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 16:17:07 volumio volumio[6503]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 16:17:07 volumio volumio[6503]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 16:17:07 volumio volumio[6503]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 16:17:07 volumio volumio[6503]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 16:17:07 volumio volumio[6503]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 16:17:07 volumio volumio[6503]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 16:17:07 volumio volumio[6503]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 16:17:07 volumio volumio[6503]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 10 16:17:07 volumio volumio[6503]: Express server listening on port 3000 Feb 10 16:17:07 volumio volumio[6503]: [Metrics] WebUI: 16s 259.40ms Feb 10 16:17:07 volumio volumio[6503]: info: CoreStateMachine::resetVolumioState Feb 10 16:17:07 volumio volumio[6503]: info: CoreStateMachine::getcurrentVolume Feb 10 16:17:07 volumio volumio[6503]: info: CoreCommandRouter::volumioRetrievevolume Feb 10 16:17:07 volumio sudo[6657]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 10 16:17:07 volumio sudo[6657]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 16:17:07 volumio sudo[6657]: pam_unix(sudo:session): session closed for user root Feb 10 16:17:07 volumio sudo[6661]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 10 16:17:07 volumio sudo[6661]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 16:17:08 volumio sudo[6661]: pam_unix(sudo:session): session closed for user root Feb 10 16:17:08 volumio volumio[6503]: info: Volumio Network Manager: Network status updated: 1 Feb 10 16:17:08 volumio volumio-remote-updater[643]: [2026-02-10 16:17:08] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1770715026 101 Feb 10 16:17:08 volumio volumio[6503]: 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 10 16:17:08 volumio volumio[6503]: info: VolumeController:: Volume=100 Mute =false Feb 10 16:17:08 volumio volumio[6503]: info: CoreStateMachine::pushState Feb 10 16:17:08 volumio volumio[6503]: info: CorePlayQueue::getTrack 0 Feb 10 16:17:08 volumio volumio[6503]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 10 16:17:08 volumio volumio[6503]: info: CoreCommandRouter::volumioPushState Feb 10 16:17:08 volumio volumio[6503]: info: CoreStateMachine::updateTrackBlock Feb 10 16:17:08 volumio volumio[6503]: info: CorePlayQueue::getTrackBlock Feb 10 16:17:08 volumio volumio[6503]: info: CoreCommandRouter::volumioRetrievevolume Feb 10 16:17:08 volumio volumio[6503]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 16:17:08 volumio volumio[6503]: info: Reloading queue from file Feb 10 16:17:08 volumio volumio[6503]: info: CoreStateMachine::setRepeat null single undefined Feb 10 16:17:08 volumio volumio[6503]: info: CoreStateMachine::pushState Feb 10 16:17:08 volumio volumio[6503]: info: CorePlayQueue::getTrack 0 Feb 10 16:17:08 volumio volumio[6503]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 10 16:17:08 volumio volumio[6503]: info: CoreCommandRouter::volumioPushState Feb 10 16:17:08 volumio volumio[6503]: info: CoreStateMachine::setRandom null Feb 10 16:17:08 volumio volumio[6503]: info: CoreStateMachine::pushState Feb 10 16:17:08 volumio volumio[6503]: info: CorePlayQueue::getTrack 0 Feb 10 16:17:08 volumio volumio[6503]: info: CoreCommandRouter::volumioPushState Feb 10 16:17:08 volumio volumio[6503]: info: Setting Device type: Raspberry PI Feb 10 16:17:08 volumio volumio[6503]: info: Completed loading Core Plugins Feb 10 16:17:08 volumio volumio[6503]: info: Preparing to generate the ALSA configuration file Feb 10 16:17:08 volumio volumio[6503]: info: VolumeController:: Volume=100 Mute =false Feb 10 16:17:08 volumio volumio[6503]: info: CoreStateMachine::pushState Feb 10 16:17:08 volumio volumio[6503]: info: CorePlayQueue::getTrack 0 Feb 10 16:17:08 volumio volumio[6503]: info: CoreCommandRouter::volumioPushState Feb 10 16:17:08 volumio volumio[6503]: info: Asound.conf file unchanged, so no further update is needed Feb 10 16:17:08 volumio volumio[6503]: info: Output device has changed, restarting MPD Feb 10 16:17:08 volumio volumio[6503]: info: Output device has changed, restarting Shairport Sync Feb 10 16:17:08 volumio volumio[6503]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 16:17:08 volumio volumio[6503]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 16:17:08 volumio sudo[6676]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 10 16:17:08 volumio sudo[6676]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 16:17:08 volumio sudo[6678]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 10 16:17:08 volumio sudo[6680]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 10 16:17:08 volumio sudo[6680]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 16:17:08 volumio volumio[6503]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 10 16:17:08 volumio sudo[6678]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 16:17:08 volumio volumio[6503]: info: ___________ START PLUGINS ___________ Feb 10 16:17:08 volumio volumio[6503]: info: ControllerMpd::onStart: Initializing MPD Feb 10 16:17:08 volumio volumio[6503]: info: Creating MPD Configuration file Feb 10 16:17:08 volumio sudo[6678]: pam_unix(sudo:session): session closed for user root Feb 10 16:17:09 volumio volumio[6503]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 10 16:17:09 volumio volumio[6503]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 10 16:17:09 volumio volumio[6503]: info: [1770715029043] CoreMusicLibrary::Adding element Media Servers Feb 10 16:17:09 volumio volumio[6503]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 10 16:17:09 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 48. Feb 10 16:17:09 volumio volumio[6503]: info: UPNP Browser: Client initialized successfully Feb 10 16:17:09 volumio sudo[6689]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 10 16:17:09 volumio sudo[6689]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 16:17:09 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 16:17:09 volumio sudo[6689]: pam_unix(sudo:session): session closed for user root Feb 10 16:17:09 volumio sudo[6691]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 10 16:17:09 volumio sudo[6691]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 16:17:09 volumio volumio[6503]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 16:17:09 volumio volumio[6503]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 16:17:09 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 16:17:09 volumio go-librespot[6693]: go-librespot daemon starting... Feb 10 16:17:09 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 10 16:17:09 volumio sudo[6676]: pam_unix(sudo:session): session closed for user root Feb 10 16:17:09 volumio volumio[6503]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 10 16:17:09 volumio volumio[6503]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 16:17:09 volumio volumio[6503]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 16:17:09 volumio go-librespot[6699]: time="2026-02-10T16:17:09+07:00" level=info msg="running go-librespot 0.4.0" Feb 10 16:17:09 volumio go-librespot[6699]: time="2026-02-10T16:17:09+07:00" level=debug msg="app state loaded" Feb 10 16:17:09 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 10 16:17:09 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 10 16:17:09 volumio systemd[1]: mpd.service: Consumed 7.273s CPU time. Feb 10 16:17:09 volumio go-librespot[6699]: time="2026-02-10T16:17:09+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 16:17:09 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 10 16:17:09 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 10 16:17:09 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 10 16:17:09 volumio volumio[6503]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 10 16:17:09 volumio volumio[6503]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 10 16:17:09 volumio volumio[6503]: info: [1770715029410] CoreMusicLibrary::Adding element Last_100 Feb 10 16:17:09 volumio volumio[6503]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 10 16:17:09 volumio volumio[6503]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 10 16:17:09 volumio volumio[6503]: info: [1770715029429] CoreMusicLibrary::Adding element Webradio Feb 10 16:17:09 volumio volumio[6503]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 10 16:17:09 volumio volumio[6503]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 10 16:17:09 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 10 16:17:09 volumio volumio[6503]: info: Initializing BBC Radios Feb 10 16:17:09 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 10 16:17:09 volumio volumio[6503]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 10 16:17:09 volumio volumio[6503]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 16:17:09 volumio volumio[6503]: info: Creating Spotify config file Feb 10 16:17:09 volumio volumio[6503]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 16:17:10 volumio sudo[6710]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 10 16:17:10 volumio sudo[6710]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 10 16:17:10 volumio sudo[6710]: pam_unix(sudo:session): session closed for user root Feb 10 16:17:10 volumio go-librespot[6699]: time="2026-02-10T16:17:10+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 10 16:17:10 volumio go-librespot[6699]: time="2026-02-10T16:17:10+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 10 16:17:10 volumio go-librespot[6699]: time="2026-02-10T16:17:10+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 10 16:17:10 volumio go-librespot[6699]: time="2026-02-10T16:17:10+07:00" level=info msg="zeroconf server listening on port 33289" Feb 10 16:17:10 volumio go-librespot[6699]: time="2026-02-10T16:17:10+07:00" level=debug msg="obtained new client token: AAD+whsGnarzudIMHHSF8Y7+PNafFHoaTmxKsX0aDHaxBvj3Q2kyAZY4uQvlnjqOy7S96/LRbh0pmb17+w+n0gMl7hwhjJGf5Qx68FSld3J4nW/6Nsa9YUU73bXb/ta04XGvvwppi71Gf/itwpzE5V7tJSXuTwzdtQGcnpaDREe7oq657h3uqhMGOl5D6nGrftYxD26KC7MoVJ40pzhRRd/89EWlWSNrQ1QcTKfdeAzR2NGd6lfLrJuV3Q==" Feb 10 16:17:10 volumio go-librespot[6699]: time="2026-02-10T16:17:10+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 10 16:17:10 volumio go-librespot[6699]: time="2026-02-10T16:17:10+07:00" level=debug msg="completed keyexchange" Feb 10 16:17:10 volumio go-librespot[6699]: time="2026-02-10T16:17:10+07:00" level=debug msg="completed challenge" Feb 10 16:17:10 volumio go-librespot[6699]: time="2026-02-10T16:17:10+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 10 16:17:10 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 16:17:10 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 16:17:10 volumio volumio[6625]: Starting albumart workers Feb 10 16:17:11 volumio volumio[6626]: Starting albumart workers Feb 10 16:17:11 volumio volumio[6627]: Starting albumart workers Feb 10 16:17:11 volumio volumio[6503]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 10 16:17:11 volumio volumio[6503]: info: [1770715031384] CoreMusicLibrary::Adding element YouTube Music Feb 10 16:17:11 volumio volumio[6503]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 10 16:17:11 volumio volumio[6503]: Cannot find translation for source YouTube Music Feb 10 16:17:11 volumio volumio[6503]: info: Volumio Calling Home Feb 10 16:17:11 volumio sudo[6728]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Feb 10 16:17:11 volumio sudo[6728]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 16:17:11 volumio sudo[6728]: pam_unix(sudo:session): session closed for user root Feb 10 16:17:12 volumio volumio[6503]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Feb 10 16:17:12 volumio volumio[6503]: info: Discovery: Found device Volumio Feb 10 16:17:12 volumio volumio[6503]: info: CoreCommandRouter::volumioGetState Feb 10 16:17:12 volumio volumio[6503]: info: CorePlayQueue::getTrack 0 Feb 10 16:17:12 volumio volumio[6503]: info: MPD Permissions set Feb 10 16:17:12 volumio volumio[6503]: info: MPD Permissions set Feb 10 16:17:12 volumio volumio[6503]: info: Upmpdcli Daemon Started Feb 10 16:17:12 volumio volumio[6503]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Feb 10 16:17:12 volumio volumio[6503]: info: Discovery: Found device Volumio Feb 10 16:17:12 volumio volumio[6503]: info: CoreCommandRouter::volumioGetState Feb 10 16:17:12 volumio volumio[6503]: info: CorePlayQueue::getTrack 0 Feb 10 16:17:12 volumio volumio[6503]: info: Volumio called home Feb 10 16:17:12 volumio volumio[6503]: info: Spotify config file written Feb 10 16:17:12 volumio volumio[6503]: 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 10 16:17:12 volumio volumio[6503]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 16:17:12 volumio volumio[6503]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 16:17:12 volumio volumio[6503]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 16:17:12 volumio volumio[6503]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 16:17:12 volumio volumio[6503]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 16:17:12 volumio volumio[6503]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 16:17:12 volumio volumio[6503]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 16:17:12 volumio sudo[6745]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 10 16:17:12 volumio sudo[6745]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 16:17:12 volumio volumio[6503]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 16:17:12 volumio volumio[6503]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 16:17:12 volumio volumio[6503]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 16:17:12 volumio volumio[6503]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 16:17:12 volumio volumio[6503]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 16:17:12 volumio volumio[6503]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 16:17:12 volumio volumio[6503]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 16:17:12 volumio volumio[6503]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 16:17:12 volumio volumio[6503]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 16:17:12 volumio volumio[6503]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 16:17:12 volumio volumio[6503]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 16:17:12 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 16:17:12 volumio volumio[6503]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 16:17:12 volumio volumio[6503]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 16:17:12 volumio volumio[6503]: info: No need to fix Spotify hosts Feb 10 16:17:12 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 16:17:12 volumio go-librespot[6760]: go-librespot daemon starting... Feb 10 16:17:13 volumio sudo[6745]: pam_unix(sudo:session): session closed for user root Feb 10 16:17:13 volumio go-librespot[6761]: time="2026-02-10T16:17:13+07:00" level=info msg="running go-librespot 0.4.0" Feb 10 16:17:13 volumio go-librespot[6761]: time="2026-02-10T16:17:13+07:00" level=debug msg="app state loaded" Feb 10 16:17:13 volumio go-librespot[6761]: time="2026-02-10T16:17:13+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 16:17:13 volumio go-librespot[6761]: time="2026-02-10T16:17:13+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 10 16:17:13 volumio go-librespot[6761]: time="2026-02-10T16:17:13+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 10 16:17:13 volumio go-librespot[6761]: time="2026-02-10T16:17:13+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 10 16:17:13 volumio go-librespot[6761]: time="2026-02-10T16:17:13+07:00" level=info msg="zeroconf server listening on port 37267" Feb 10 16:17:13 volumio volumio[6503]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 10 16:17:13 volumio volumio[6503]: SPOTIFY: BQCrYmxZpRmo0ihE8QCYthOpeBhTYaCEnM71XjYxjR2IVhwIywdax50zltFGmWRTlOC4FByelv3VKa_SnwoSkYA067ckj5JpPRooRpqoanU2Wvo89eM2EAcwK3IEPONi_E2xMHEchWAGUfzBQalLeA4Yl5xmnv8SRslqWFjzAq0_G0rjjt6TtY5Ph5xpY5E_Bg2pMfvJoCbX2DwqQzeju4hXasGidEyELyW-aNabNIiqJ4gYj4s6rgoOtFTjySBIPtWmU74aCeIA1ScL4QpvQmSQTZ_VrK5iGUqiiFGUG25K-b_yLw1AAI34 Feb 10 16:17:13 volumio volumio[6503]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 10 16:17:13 volumio volumio[6503]: info: New Spotify access token = BQCrYmxZpRmo0ihE8QCYthOpeBhTYaCEnM71XjYxjR2IVhwIywdax50zltFGmWRTlOC4FByelv3VKa_SnwoSkYA067ckj5JpPRooRpqoanU2Wvo89eM2EAcwK3IEPONi_E2xMHEchWAGUfzBQalLeA4Yl5xmnv8SRslqWFjzAq0_G0rjjt6TtY5Ph5xpY5E_Bg2pMfvJoCbX2DwqQzeju4hXasGidEyELyW-aNabNIiqJ4gYj4s6rgoOtFTjySBIPtWmU74aCeIA1ScL4QpvQmSQTZ_VrK5iGUqiiFGUG25K-b_yLw1AAI34 Feb 10 16:17:13 volumio volumio[6503]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 10 16:17:13 volumio go-librespot[6761]: time="2026-02-10T16:17:13+07:00" level=debug msg="obtained new client token: AAA6qmHBFEeuZ+TeM38U8H4Y8/rlMeskEP2zEDRFecs7nZlJw8Xaq1NDSibj2pQgqJGJtqzQffFr1qPDWxr+9wKQYcG2KF71Q/fwuZAj4Rn78aFM2Nth+99x3bnqExA8I1+vuoeIt5ZXbKdWGeJvyLsIeFo6I75DC7rO32+S8Ucq+010IT3OizyIXs54f2LsS2W1gDmfTcZ80j+hCP4woBcg0RO11zkWPVlPNn1dPr3nLCeeQ/dWnl+/dw==" Feb 10 16:17:13 volumio volumio[6503]: info: Starting Shairport Sync Feb 10 16:17:13 volumio volumio[6503]: info: Starting Shairport Sync Feb 10 16:17:13 volumio volumio[6503]: info: Starting Shairport Sync Feb 10 16:17:13 volumio sudo[6776]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 10 16:17:13 volumio go-librespot[6761]: time="2026-02-10T16:17:13+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 10 16:17:13 volumio sudo[6776]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 16:17:14 volumio sudo[6778]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 10 16:17:14 volumio sudo[6778]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 16:17:14 volumio sudo[6780]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 10 16:17:14 volumio sudo[6780]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 16:17:14 volumio go-librespot[6761]: time="2026-02-10T16:17:14+07:00" level=debug msg="completed keyexchange" Feb 10 16:17:14 volumio go-librespot[6761]: time="2026-02-10T16:17:14+07:00" level=debug msg="completed challenge" Feb 10 16:17:14 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 10 16:17:14 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 10 16:17:14 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 10 16:17:14 volumio systemd[1]: shairport-sync.service: Consumed 2.353s CPU time. Feb 10 16:17:14 volumio go-librespot[6761]: time="2026-02-10T16:17:14+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 10 16:17:14 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 10 16:17:14 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 16:17:14 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 16:17:14 volumio sudo[6776]: pam_unix(sudo:session): session closed for user root Feb 10 16:17:14 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 10 16:17:14 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 10 16:17:14 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 10 16:17:14 volumio volumio[6503]: info: Shairport-Sync Started Feb 10 16:17:14 volumio volumio[6503]: Error adding Membership: Error: addMembership EINVAL Feb 10 16:17:14 volumio volumio[6503]: info: CoreCommandRouter::volumioGetState Feb 10 16:17:14 volumio volumio[6503]: info: CorePlayQueue::getTrack 0 Feb 10 16:17:14 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 10 16:17:14 volumio sudo[6780]: pam_unix(sudo:session): session closed for user root Feb 10 16:17:14 volumio sudo[6778]: pam_unix(sudo:session): session closed for user root Feb 10 16:17:14 volumio volumio[6503]: info: Shairport-Sync Started Feb 10 16:17:14 volumio volumio[6503]: info: Shairport-Sync Started Feb 10 16:17:14 volumio volumio[6503]: 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 10 16:17:14 volumio volumio[6503]: info: Spotify Successfully logged in Feb 10 16:17:14 volumio volumio[6503]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 10 16:17:14 volumio volumio[6503]: info: [1770715034841] CoreMusicLibrary::Adding element Spotify Feb 10 16:17:14 volumio volumio[6503]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 10 16:17:14 volumio volumio[6503]: Cannot find translation for source YouTube Music Feb 10 16:17:14 volumio volumio[6503]: Cannot find translation for source Spotify Feb 10 16:17:15 volumio volumio[6503]: info: [yt-cast-receiver] DIAL server listening on port 8098 Feb 10 16:17:15 volumio volumio[6503]: info: CoreCommandRouter::volumioRetrievevolume Feb 10 16:17:15 volumio volumio[6503]: info: VolumeController:: Volume=100 Mute =false Feb 10 16:17:15 volumio volumio[6503]: info: CoreCommandRouter::volumioGetState Feb 10 16:17:15 volumio volumio[6503]: info: CorePlayQueue::getTrack 0 Feb 10 16:17:15 volumio volumio[6503]: info: CoreStateMachine::pushState Feb 10 16:17:15 volumio volumio[6503]: info: CorePlayQueue::getTrack 0 Feb 10 16:17:15 volumio volumio[6503]: info: CoreCommandRouter::volumioPushState Feb 10 16:17:16 volumio volumio[6503]: info: go-librespot daemon successfully initialized Feb 10 16:17:17 volumio mpd[6726]: 2026-02-10T16:17:17 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 10 16:17:17 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 10 16:17:17 volumio sudo[6680]: pam_unix(sudo:session): session closed for user root Feb 10 16:17:17 volumio sudo[6691]: pam_unix(sudo:session): session closed for user root Feb 10 16:17:17 volumio volumio[6503]: error: MPD error: The expression evaluated to a falsy value: Feb 10 16:17:17 volumio volumio[6503]: assert.ok(self.idling) Feb 10 16:17:17 volumio volumio[6503]: error: The expression evaluated to a falsy value: Feb 10 16:17:17 volumio volumio[6503]: assert.ok(self.idling) Feb 10 16:17:17 volumio volumio[6503]: error: updateQueue error: null Feb 10 16:17:17 volumio volumio[6503]: info: MPD running with PID6726 Feb 10 16:17:17 volumio volumio[6503]: ,establishing connection Feb 10 16:17:17 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 49. Feb 10 16:17:17 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 16:17:17 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 16:17:17 volumio go-librespot[6822]: go-librespot daemon starting... Feb 10 16:17:17 volumio volumio[6503]: info: Completed starting Core Plugins Feb 10 16:17:17 volumio volumio[6503]: info: ------------------------------------------- Feb 10 16:17:17 volumio volumio[6503]: info: ----- MyVolumio plugins startup ---- Feb 10 16:17:17 volumio volumio[6503]: info: ------------------------------------------- Feb 10 16:17:17 volumio volumio[6503]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 10 16:17:17 volumio volumio[6503]: error: updateQueue error: null Feb 10 16:17:17 volumio go-librespot[6823]: time="2026-02-10T16:17:17+07:00" level=info msg="running go-librespot 0.4.0" Feb 10 16:17:17 volumio go-librespot[6823]: time="2026-02-10T16:17:17+07:00" level=debug msg="app state loaded" Feb 10 16:17:17 volumio go-librespot[6823]: time="2026-02-10T16:17:17+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 16:17:17 volumio go-librespot[6823]: time="2026-02-10T16:17:17+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 10 16:17:17 volumio go-librespot[6823]: time="2026-02-10T16:17:17+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 10 16:17:17 volumio go-librespot[6823]: time="2026-02-10T16:17:17+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 10 16:17:17 volumio go-librespot[6823]: time="2026-02-10T16:17:17+07:00" level=info msg="zeroconf server listening on port 36271" Feb 10 16:17:18 volumio go-librespot[6823]: time="2026-02-10T16:17:18+07:00" level=debug msg="obtained new client token: AAChI8BiprarY3w05qCjf5RE8hMHvHJ1iXDVsRH6gCgS9qbxug8TM8q7vT1cUgDcZqvuWvypDI6cQOZ907xXc4qze1pOixZ/jCzykUBDDanvx1esuG3n8Fzl7wf1dABcrCdsad04Xu25zBVh8jirqWNv7YzwAMuf2AOiTkxr9PqPfyjcv2P6ImNeNV487wCugwndSJEMCNyF8DQYvrhO++UoI/WkDJ+37JxjU3u8wzO+f5DDzpqfQK0=" Feb 10 16:17:18 volumio go-librespot[6823]: time="2026-02-10T16:17:18+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 10 16:17:18 volumio go-librespot[6823]: time="2026-02-10T16:17:18+07:00" level=debug msg="completed keyexchange" Feb 10 16:17:18 volumio go-librespot[6823]: time="2026-02-10T16:17:18+07:00" level=debug msg="completed challenge" Feb 10 16:17:18 volumio go-librespot[6823]: time="2026-02-10T16:17:18+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 10 16:17:18 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 16:17:18 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 16:17:19 volumio volumio[6503]: info: Initializing connection to go-librespot Websocket Feb 10 16:17:19 volumio volumio[6503]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 10 16:17:22 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 50. Feb 10 16:17:22 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 16:17:22 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 16:17:22 volumio go-librespot[6830]: go-librespot daemon starting... Feb 10 16:17:22 volumio volumio[6503]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 10 16:17:22 volumio go-librespot[6831]: time="2026-02-10T16:17:22+07:00" level=info msg="running go-librespot 0.4.0" Feb 10 16:17:22 volumio go-librespot[6831]: time="2026-02-10T16:17:22+07:00" level=debug msg="app state loaded" Feb 10 16:17:22 volumio go-librespot[6831]: time="2026-02-10T16:17:22+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 16:17:22 volumio go-librespot[6831]: time="2026-02-10T16:17:22+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 10 16:17:22 volumio go-librespot[6831]: time="2026-02-10T16:17:22+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 10 16:17:22 volumio go-librespot[6831]: time="2026-02-10T16:17:22+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 10 16:17:22 volumio go-librespot[6831]: time="2026-02-10T16:17:22+07:00" level=info msg="zeroconf server listening on port 41597" Feb 10 16:17:22 volumio volumio[6503]: info: Initializing connection to go-librespot Websocket Feb 10 16:17:22 volumio go-librespot[6831]: time="2026-02-10T16:17:22+07:00" level=debug msg="new websocket client" Feb 10 16:17:22 volumio volumio[6503]: info: Connection to go-librespot Websocket established Feb 10 16:17:22 volumio go-librespot[6831]: time="2026-02-10T16:17:22+07:00" level=debug msg="obtained new client token: AAByPcwtEZcadMQqsbjp7PB2QZ1jQeax/mypzD2UUBe3iLJZY/sFezYbtvp8Ay86xdBa35y3Y/zhoknYD3ZyA0fwYCYUcEQXwezZ7WOPXJnuYTKn0PptMlG/+YZzhAZsqamkBErSkPYox2sDo5VG8deNTjYrBuIOhpS3+HrxdrWjBMyfvi7ZMnVoosG8HiNxwUhQK+GJr8CW+k96LALTiFfSKAqQcDPCo7IpHcxiZCjgaoinFPj9MVs7zA==" Feb 10 16:17:22 volumio go-librespot[6831]: time="2026-02-10T16:17:22+07:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:4070, retrying with a different AP" error="dial tcp 104.199.241.202:4070: connect: connection refused" Feb 10 16:17:23 volumio go-librespot[6831]: time="2026-02-10T16:17:23+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Feb 10 16:17:23 volumio go-librespot[6831]: time="2026-02-10T16:17:23+07:00" level=debug msg="completed keyexchange" Feb 10 16:17:23 volumio go-librespot[6831]: time="2026-02-10T16:17:23+07:00" level=debug msg="completed challenge" Feb 10 16:17:23 volumio go-librespot[6831]: time="2026-02-10T16:17:23+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 10 16:17:23 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 16:17:23 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 16:17:23 volumio volumio[6503]: info: Connection to go-librespot Websocket closed Feb 10 16:17:25 volumio volumio[6503]: info: Getting Spotify volume Feb 10 16:17:25 volumio volumio[6503]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 10 16:17:25 volumio volumio[6503]: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 10 16:17:25 volumio volumio[6503]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Feb 10 16:17:25 volumio volumio[6503]: errno: -111, Feb 10 16:17:25 volumio volumio[6503]: code: 'ECONNREFUSED', Feb 10 16:17:25 volumio volumio[6503]: syscall: 'connect', Feb 10 16:17:25 volumio volumio[6503]: address: '127.0.0.1', Feb 10 16:17:25 volumio volumio[6503]: port: 9879, Feb 10 16:17:25 volumio volumio[6503]: response: undefined Feb 10 16:17:25 volumio volumio[6503]: } Feb 10 16:17:25 volumio volumio[6503]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 10 16:17:26 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 51. Feb 10 16:17:26 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 16:17:26 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 16:17:26 volumio go-librespot[6850]: go-librespot daemon starting... Feb 10 16:17:26 volumio go-librespot[6851]: time="2026-02-10T16:17:26+07:00" level=info msg="running go-librespot 0.4.0" Feb 10 16:17:26 volumio go-librespot[6851]: time="2026-02-10T16:17:26+07:00" level=debug msg="app state loaded" Feb 10 16:17:26 volumio go-librespot[6851]: time="2026-02-10T16:17:26+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 16:17:26 volumio go-librespot[6851]: time="2026-02-10T16:17:26+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 10 16:17:26 volumio go-librespot[6851]: time="2026-02-10T16:17:26+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 10 16:17:26 volumio go-librespot[6851]: time="2026-02-10T16:17:26+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 10 16:17:26 volumio go-librespot[6851]: time="2026-02-10T16:17:26+07:00" level=info msg="zeroconf server listening on port 44865" Feb 10 16:17:27 volumio go-librespot[6851]: time="2026-02-10T16:17:27+07:00" level=debug msg="obtained new client token: AABiQirdFQFhpwLUqvI8ad1na+PTOyHpEWEwonMbSmEpRWNVa2WgbcGDkNDqPC+5+6Jppp+vYgsP/p/URKNb5pNGq0mTWBIshu5dSzO+Mi1zp8epWzsslNL+K1F4vwA+yHPrjO9cbvQAllFDQ1qE0y+CdhfgIKeiQsspwP7ij66WzrVtfmlkjpjtiqFxLeBDYbmKHI8uRJ58DdQdesUyOBPkzq0U2+p+kbGLbMRlda4NFiuPxButIK0=" Feb 10 16:17:27 volumio go-librespot[6851]: time="2026-02-10T16:17:27+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 10 16:17:27 volumio sudo[6874]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-10 16:16' Feb 10 16:17:27 volumio sudo[6874]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 16:17:27 volumio go-librespot[6851]: time="2026-02-10T16:17:27+07:00" level=debug msg="completed keyexchange" Feb 10 16:17:27 volumio go-librespot[6851]: time="2026-02-10T16:17:27+07:00" level=debug msg="completed challenge" Feb 10 16:17:27 volumio go-librespot[6851]: time="2026-02-10T16:17:27+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 10 16:17:27 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 16:17:27 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 16:17:27 volumio sudo[6874]: pam_unix(sudo:session): session closed for user root Feb 10 16:17:27 volumio volumio-remote-updater[643]: [2026-02-10 16:17:27] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Feb 10 16:17:27 volumio volumio-remote-updater[643]: [2026-02-10 16:17:27] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Feb 10 16:17:27 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Feb 10 16:17:27 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Feb 10 16:17:27 volumio systemd[1]: volumio.service: Consumed 49.343s CPU time. Feb 10 16:17:28 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 10 16:17:28 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 10 16:17:28 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 10464. Feb 10 16:17:28 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 10 16:17:28 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Feb 10 16:17:28 volumio systemd[1]: volumio.service: Consumed 49.343s CPU time. Feb 10 16:17:28 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Feb 10 16:17:28 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 10 16:17:30 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 52. Feb 10 16:17:30 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 16:17:30 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 16:17:30 volumio go-librespot[6901]: go-librespot daemon starting... Feb 10 16:17:30 volumio go-librespot[6902]: time="2026-02-10T16:17:30+07:00" level=info msg="running go-librespot 0.4.0" Feb 10 16:17:30 volumio go-librespot[6902]: time="2026-02-10T16:17:30+07:00" level=debug msg="app state loaded" Feb 10 16:17:30 volumio go-librespot[6902]: time="2026-02-10T16:17:30+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 16:17:31 volumio go-librespot[6902]: time="2026-02-10T16:17:31+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 10 16:17:31 volumio go-librespot[6902]: time="2026-02-10T16:17:31+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 10 16:17:31 volumio go-librespot[6902]: time="2026-02-10T16:17:31+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 10 16:17:31 volumio go-librespot[6902]: time="2026-02-10T16:17:31+07:00" level=info msg="zeroconf server listening on port 35277" Feb 10 16:17:31 volumio go-librespot[6902]: time="2026-02-10T16:17:31+07:00" level=debug msg="obtained new client token: AADHboOXEsHeYnFaeIOLTXMVnDtvQyciXwSK0/+4S7p6uXNcu2tcIQdANqy+/fbCdiyCTf0/zlpI0Qm+6vg/276I0zogwnR+aYAIQYgKJJMMcRYyn2DOM9MosnCHlnDnKik/pMLQ37QeKQ2NVzaLX/KfyqzO4JWutxGE9P+H5MjJIgArB9nHiWbe3gTu9Ph/7WjLot9LAmAP74MFpC1egP27IMKPPBDd9MghsJ1y+ubNJ49pALXHBg/2Mg==" Feb 10 16:17:31 volumio go-librespot[6902]: time="2026-02-10T16:17:31+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 10 16:17:31 volumio go-librespot[6902]: time="2026-02-10T16:17:31+07:00" level=debug msg="completed keyexchange" Feb 10 16:17:31 volumio go-librespot[6902]: time="2026-02-10T16:17:31+07:00" level=debug msg="completed challenge" Feb 10 16:17:31 volumio go-librespot[6902]: time="2026-02-10T16:17:31+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 10 16:17:31 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 16:17:31 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 16:17:31 volumio volumio[6886]: info: ------------------------------------------- Feb 10 16:17:31 volumio volumio[6886]: info: ----- Volumio3 ---- Feb 10 16:17:31 volumio volumio[6886]: info: ------------------------------------------- Feb 10 16:17:31 volumio volumio[6886]: info: ----- System startup ---- Feb 10 16:17:31 volumio volumio[6886]: info: ------------------------------------------- Feb 10 16:17:32 volumio volumio-remote-updater[643]: [2026-02-10 16:17:32] [connect] Successful connection Feb 10 16:17:33 volumio volumio[6886]: info: MYVOLUMIO Environment detected Feb 10 16:17:33 volumio volumio[6886]: info: Plugin folders cleanup Feb 10 16:17:33 volumio volumio[6886]: info: Scanning into folder /volumio/app/plugins/ Feb 10 16:17:33 volumio volumio[6886]: info: Scanning category audio_interface Feb 10 16:17:33 volumio volumio[6886]: info: Scanning category miscellanea Feb 10 16:17:33 volumio volumio[6886]: info: Scanning category music_service Feb 10 16:17:33 volumio volumio[6886]: info: Scanning category plugins.json Feb 10 16:17:33 volumio volumio[6886]: info: Scanning category system_controller Feb 10 16:17:33 volumio volumio[6886]: info: Scanning category user_interface Feb 10 16:17:33 volumio volumio[6886]: info: Scanning into folder /data/plugins/ Feb 10 16:17:33 volumio volumio[6886]: info: Scanning category music_service Feb 10 16:17:33 volumio volumio[6886]: info: Plugin folders cleanup completed Feb 10 16:17:33 volumio volumio[6886]: info: ------------------------------------------- Feb 10 16:17:33 volumio volumio[6886]: info: ----- Core plugins startup ---- Feb 10 16:17:33 volumio volumio[6886]: info: ------------------------------------------- Feb 10 16:17:33 volumio volumio[6886]: info: Loading plugins from folder /volumio/app/plugins/ Feb 10 16:17:33 volumio volumio[6886]: info: Adding plugin upnp to MyMusic Plugins Feb 10 16:17:33 volumio volumio[6886]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 10 16:17:33 volumio volumio[6886]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 10 16:17:33 volumio volumio[6886]: info: Loading plugins from folder /data/plugins/ Feb 10 16:17:33 volumio volumio[6886]: info: Loading plugin "system"... Feb 10 16:17:33 volumio volumio[6886]: info: Loading plugin "appearance"... Feb 10 16:17:34 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 53. Feb 10 16:17:34 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 16:17:34 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 16:17:34 volumio go-librespot[6925]: go-librespot daemon starting... Feb 10 16:17:34 volumio go-librespot[6926]: time="2026-02-10T16:17:34+07:00" level=info msg="running go-librespot 0.4.0" Feb 10 16:17:34 volumio go-librespot[6926]: time="2026-02-10T16:17:34+07:00" level=debug msg="app state loaded" Feb 10 16:17:34 volumio go-librespot[6926]: time="2026-02-10T16:17:34+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 16:17:35 volumio volumio[6886]: info: Loading plugin "network"... Feb 10 16:17:35 volumio volumio[6886]: info: Refreshing Cached IP Addresses Feb 10 16:17:35 volumio sudo[6934]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 10 16:17:35 volumio sudo[6934]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 16:17:35 volumio sudo[6936]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 10 16:17:35 volumio sudo[6936]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 16:17:35 volumio volumio[6886]: info: Loading plugin "services"... Feb 10 16:17:35 volumio sudo[6934]: pam_unix(sudo:session): session closed for user root Feb 10 16:17:35 volumio sudo[6936]: pam_unix(sudo:session): session closed for user root Feb 10 16:17:35 volumio volumio[6886]: info: Loading plugin "alsa_controller"... Feb 10 16:17:35 volumio sudo[6948]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 10 16:17:35 volumio sudo[6948]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 16:17:35 volumio volumio[6886]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 10 16:17:35 volumio volumio[6886]: info: Loading plugin "wizard"... Feb 10 16:17:35 volumio volumio[6886]: info: Loading plugin "networkfs"... Feb 10 16:17:35 volumio volumio[6886]: info: Starting Udev Watcher for removable devices Feb 10 16:17:35 volumio volumio[6886]: info: Ignoring mount for partition: boot Feb 10 16:17:35 volumio volumio[6886]: info: Ignoring mount for partition: volumio Feb 10 16:17:35 volumio volumio[6886]: info: Ignoring mount for partition: volumio_data Feb 10 16:17:35 volumio volumio[6886]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 10 16:17:35 volumio volumio[6886]: info: Loading plugin "volumio_command_line_client"... Feb 10 16:17:35 volumio volumio[6886]: info: Loading plugin "upnp"... Feb 10 16:17:35 volumio volumio[6886]: info: [1770715055684] Starting Upmpd Daemon Feb 10 16:17:35 volumio volumio[6886]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 10 16:17:35 volumio volumio[6886]: info: Loading plugin "my_music"... Feb 10 16:17:35 volumio volumio[6886]: info: Loading plugin "mpd"... Feb 10 16:17:36 volumio volumio[6886]: info: Loading plugin "upnp_browser"... Feb 10 16:17:36 volumio go-librespot[6926]: time="2026-02-10T16:17:36+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 10 16:17:36 volumio go-librespot[6926]: time="2026-02-10T16:17:36+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 10 16:17:36 volumio go-librespot[6926]: time="2026-02-10T16:17:36+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 10 16:17:36 volumio go-librespot[6926]: time="2026-02-10T16:17:36+07:00" level=info msg="zeroconf server listening on port 34603" Feb 10 16:17:36 volumio go-librespot[6926]: time="2026-02-10T16:17:36+07:00" level=debug msg="obtained new client token: AADCHS3Ud2Gbk2MCj9GjsRnpM7L4079L+gNNekk/+gAxrh19HwsTXFkKkGrmT6l3K/XTs9y8JoBNq2qwABLsRd4JViCo5i1iSjJ5tI4KSdcBE+u8KEFqqfoTEXMA3YPnzFANXEOlLpFMdqs0PMYX7cogHHKrFYFXh2ImXz0a82h6B10Gq43rLvjG9n7uMASNPcf6IBvXrqK9VkeZYY/NpjTE+tkMJwYp/0IhmMzTt6jLzIabTNgiODb6Qg==" Feb 10 16:17:36 volumio go-librespot[6926]: time="2026-02-10T16:17:36+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 10 16:17:36 volumio go-librespot[6926]: time="2026-02-10T16:17:36+07:00" level=debug msg="completed keyexchange" Feb 10 16:17:36 volumio go-librespot[6926]: time="2026-02-10T16:17:36+07:00" level=debug msg="completed challenge" Feb 10 16:17:36 volumio go-librespot[6926]: time="2026-02-10T16:17:36+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 10 16:17:36 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 16:17:36 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 16:17:38 volumio sudo[6948]: pam_unix(sudo:session): session closed for user root Feb 10 16:17:39 volumio volumio[6886]: info: Starting UPNP Browser Feb 10 16:17:39 volumio volumio[6886]: info: Loading plugin "alarm-clock"... Feb 10 16:17:39 volumio volumio[6886]: info: Loading plugin "airplay_emulation"... Feb 10 16:17:39 volumio volumio[6886]: info: Starting Shairport Sync Feb 10 16:17:39 volumio volumio[6886]: info: Loading plugin "last_100"... Feb 10 16:17:39 volumio volumio[6886]: info: Loading plugin "webradio"... Feb 10 16:17:39 volumio volumio[6886]: info: Loading plugin "i2s_dacs"... Feb 10 16:17:39 volumio volumio[6886]: info: Loading plugin "volumiodiscovery"... Feb 10 16:17:39 volumio volumio[6886]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 10 16:17:39 volumio volumio[6886]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 10 16:17:39 volumio node[6886]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 10 16:17:39 volumio volumio[6886]: *** WARNING *** For more information see Feb 10 16:17:39 volumio volumio[6886]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 10 16:17:39 volumio volumio[6886]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 10 16:17:39 volumio volumio[6886]: *** WARNING *** For more information see Feb 10 16:17:39 volumio node[6886]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 10 16:17:39 volumio node[6886]: *** WARNING *** For more information see Feb 10 16:17:39 volumio node[6886]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 10 16:17:39 volumio node[6886]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 10 16:17:39 volumio node[6886]: *** WARNING *** For more information see Feb 10 16:17:39 volumio volumio[6886]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 10 16:17:39 volumio volumio[6886]: info: Discovery: Started advertising with name: Volumio Feb 10 16:17:39 volumio volumio[6886]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 10 16:17:39 volumio volumio[6886]: info: Loading plugin "spop"... Feb 10 16:17:40 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 54. Feb 10 16:17:40 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 16:17:40 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 16:17:40 volumio go-librespot[6970]: go-librespot daemon starting... Feb 10 16:17:40 volumio go-librespot[6971]: time="2026-02-10T16:17:40+07:00" level=info msg="running go-librespot 0.4.0" Feb 10 16:17:40 volumio go-librespot[6971]: time="2026-02-10T16:17:40+07:00" level=debug msg="app state loaded" Feb 10 16:17:40 volumio go-librespot[6971]: time="2026-02-10T16:17:40+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 16:17:40 volumio go-librespot[6971]: time="2026-02-10T16:17:40+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 10 16:17:40 volumio go-librespot[6971]: time="2026-02-10T16:17:40+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 10 16:17:40 volumio go-librespot[6971]: time="2026-02-10T16:17:40+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 10 16:17:40 volumio go-librespot[6971]: time="2026-02-10T16:17:40+07:00" level=info msg="zeroconf server listening on port 42773" Feb 10 16:17:40 volumio go-librespot[6971]: time="2026-02-10T16:17:40+07:00" level=debug msg="obtained new client token: AACJJe1/hjlJMHjZ7pZ3n1qk/GjwYCIdIglSPxMuXKxBmTVRplyU88izh6klJq6vtKabtI3OUAKQVj9l4XkzOVTsvWyMPbTgNQyTYImHUOapk0p8xMxsPfg441EzbGAZmXkN3faNLe959mu+0O+FTiZGUfLLEn+NvhzDc5E8GeTUpV1O8rbW7vbNKXYbbuPltYD6evSHbHMGNC3HUUNwWplP+X5CxVwrf9LP+W0kOcGQWj/P6AQaC3VAUA==" Feb 10 16:17:41 volumio go-librespot[6971]: time="2026-02-10T16:17:41+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 10 16:17:41 volumio go-librespot[6971]: time="2026-02-10T16:17:41+07:00" level=debug msg="completed keyexchange" Feb 10 16:17:41 volumio go-librespot[6971]: time="2026-02-10T16:17:41+07:00" level=debug msg="completed challenge" Feb 10 16:17:41 volumio go-librespot[6971]: time="2026-02-10T16:17: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 10 16:17:41 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 16:17:41 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 16:17:41 volumio volumio[6886]: info: Loading plugin "ytcr"... Feb 10 16:17:44 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 55. Feb 10 16:17:44 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 16:17:44 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 16:17:44 volumio go-librespot[6978]: go-librespot daemon starting... Feb 10 16:17:44 volumio go-librespot[6979]: time="2026-02-10T16:17:44+07:00" level=info msg="running go-librespot 0.4.0" Feb 10 16:17:44 volumio go-librespot[6979]: time="2026-02-10T16:17:44+07:00" level=debug msg="app state loaded" Feb 10 16:17:44 volumio go-librespot[6979]: time="2026-02-10T16:17:44+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 16:17:44 volumio volumio[6886]: info: Loading plugin "ytmusic"... Feb 10 16:17:44 volumio go-librespot[6979]: time="2026-02-10T16:17:44+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 10 16:17:44 volumio go-librespot[6979]: time="2026-02-10T16:17:44+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 10 16:17:44 volumio go-librespot[6979]: time="2026-02-10T16:17:44+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 10 16:17:44 volumio go-librespot[6979]: time="2026-02-10T16:17:44+07:00" level=info msg="zeroconf server listening on port 46091" Feb 10 16:17:45 volumio go-librespot[6979]: time="2026-02-10T16:17:45+07:00" level=debug msg="obtained new client token: AAAYu/NQ1xn2YRrUmoH32GYSGw/kse+c87zsTodnB3P1YVUTAsCVgByrwjtIyVSLLYNjqa7Z5egrRiwyzByZW2A7KiMoixJhTqNujCe+7KWJ7wRYtYZ1IVVxrcrtQ5VbQbynAYi2mrlOV6n1viuEKORFV60vd7fFRUTukjjnoy3ELpWvE/5LkL2KQZYWvu7V/RQ4Urz/y7sQ6VNKv4FEZ9lRhiLO1dndDer7zqxFU6u7wQTu40aOAH4=" Feb 10 16:17:45 volumio go-librespot[6979]: time="2026-02-10T16:17:45+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 10 16:17:45 volumio go-librespot[6979]: time="2026-02-10T16:17:45+07:00" level=debug msg="completed keyexchange" Feb 10 16:17:45 volumio go-librespot[6979]: time="2026-02-10T16:17:45+07:00" level=debug msg="completed challenge" Feb 10 16:17:45 volumio volumio-remote-updater[643]: [2026-02-10 16:17:45] [connect] Successful connection Feb 10 16:17:45 volumio go-librespot[6979]: time="2026-02-10T16:17:45+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 10 16:17:45 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 16:17:45 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 16:17:45 volumio volumio[6886]: info: Loading plugin "outputs"... Feb 10 16:17:45 volumio volumio[6886]: info: Loading plugin "albumart"... Feb 10 16:17:45 volumio volumio[6886]: info: Plugin example_plugin is not enabled Feb 10 16:17:45 volumio volumio[6886]: info: Loading plugin "inputs"... Feb 10 16:17:45 volumio volumio[6886]: info: Loading plugin "updater_comm"... Feb 10 16:17:45 volumio volumio[6886]: info: Plugin mpdemulation is not enabled Feb 10 16:17:45 volumio volumio[6886]: info: Loading plugin "rest_api"... Feb 10 16:17:45 volumio volumio[6886]: info: Loading plugin "websocket"... Feb 10 16:17:46 volumio volumio[6886]: info: Starting Socket.io Server version 1.7.4 Feb 10 16:17:46 volumio volumio[6886]: info: Loading plugin "RoonBridge"... Feb 10 16:17:46 volumio volumio[6886]: info: Applying required configuration parameters for plugin RoonBridge Feb 10 16:17:46 volumio volumio[6886]: info: Loading i18n strings for locale en Feb 10 16:17:46 volumio volumio[6886]: Updating browse sources language Feb 10 16:17:46 volumio volumio[6886]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 10 16:17:46 volumio volumio[6886]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 10 16:17:46 volumio volumio[6886]: info: CoreCommandRouter::initPlayerControls Feb 10 16:17:46 volumio volumio[6886]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 16:17:46 volumio volumio[6886]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 16:17:46 volumio volumio[6886]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 16:17:46 volumio volumio[7000]: Forking 3 albumart workers Feb 10 16:17:46 volumio volumio[6886]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 16:17:46 volumio volumio[6886]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 16:17:46 volumio volumio[6886]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 16:17:46 volumio volumio[6886]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 16:17:46 volumio volumio[6886]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 16:17:46 volumio volumio[6886]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 10 16:17:46 volumio volumio[6886]: Express server listening on port 3000 Feb 10 16:17:46 volumio volumio[6886]: [Metrics] WebUI: 16s 56.45ms Feb 10 16:17:46 volumio volumio[6886]: info: CoreStateMachine::resetVolumioState Feb 10 16:17:46 volumio volumio[6886]: info: CoreStateMachine::getcurrentVolume Feb 10 16:17:46 volumio volumio[6886]: info: CoreCommandRouter::volumioRetrievevolume Feb 10 16:17:47 volumio sudo[7037]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 10 16:17:47 volumio sudo[7037]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 16:17:47 volumio sudo[7044]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 10 16:17:47 volumio sudo[7044]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 16:17:47 volumio sudo[7037]: pam_unix(sudo:session): session closed for user root Feb 10 16:17:47 volumio sudo[7044]: pam_unix(sudo:session): session closed for user root Feb 10 16:17:47 volumio volumio[6886]: info: Volumio Network Manager: Network status updated: 1 Feb 10 16:17:47 volumio volumio[6886]: info: VolumeController:: Volume=100 Mute =false Feb 10 16:17:47 volumio volumio[6886]: info: CoreStateMachine::pushState Feb 10 16:17:47 volumio volumio[6886]: info: CorePlayQueue::getTrack 0 Feb 10 16:17:47 volumio volumio[6886]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 10 16:17:47 volumio volumio[6886]: info: CoreCommandRouter::volumioPushState Feb 10 16:17:47 volumio volumio[6886]: info: CoreStateMachine::updateTrackBlock Feb 10 16:17:47 volumio volumio[6886]: info: CorePlayQueue::getTrackBlock Feb 10 16:17:47 volumio volumio[6886]: info: CoreCommandRouter::volumioRetrievevolume Feb 10 16:17:47 volumio volumio-remote-updater[643]: [2026-02-10 16:17:47] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1770715065 101 Feb 10 16:17:47 volumio volumio[6886]: 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 10 16:17:47 volumio volumio[6886]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 16:17:47 volumio volumio[6886]: info: Reloading queue from file Feb 10 16:17:47 volumio volumio[6886]: info: CoreStateMachine::setRepeat null single undefined Feb 10 16:17:47 volumio volumio[6886]: info: CoreStateMachine::pushState Feb 10 16:17:47 volumio volumio[6886]: info: CorePlayQueue::getTrack 0 Feb 10 16:17:47 volumio volumio[6886]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 10 16:17:47 volumio volumio[6886]: info: CoreCommandRouter::volumioPushState Feb 10 16:17:47 volumio volumio[6886]: info: CoreStateMachine::setRandom null Feb 10 16:17:47 volumio volumio[6886]: info: CoreStateMachine::pushState Feb 10 16:17:47 volumio volumio[6886]: info: CorePlayQueue::getTrack 0 Feb 10 16:17:47 volumio volumio[6886]: info: CoreCommandRouter::volumioPushState Feb 10 16:17:47 volumio volumio[6886]: info: Setting Device type: Raspberry PI Feb 10 16:17:47 volumio volumio[6886]: info: Completed loading Core Plugins Feb 10 16:17:47 volumio volumio[6886]: info: Preparing to generate the ALSA configuration file Feb 10 16:17:47 volumio volumio[6886]: info: VolumeController:: Volume=100 Mute =false Feb 10 16:17:47 volumio volumio[6886]: info: CoreStateMachine::pushState Feb 10 16:17:47 volumio volumio[6886]: info: CorePlayQueue::getTrack 0 Feb 10 16:17:47 volumio volumio[6886]: info: CoreCommandRouter::volumioPushState Feb 10 16:17:47 volumio volumio[6886]: info: Asound.conf file unchanged, so no further update is needed Feb 10 16:17:47 volumio volumio[6886]: info: Output device has changed, restarting MPD Feb 10 16:17:47 volumio volumio[6886]: info: Output device has changed, restarting Shairport Sync Feb 10 16:17:47 volumio volumio[6886]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 16:17:47 volumio volumio[6886]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 16:17:47 volumio sudo[7061]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 10 16:17:47 volumio sudo[7061]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 16:17:47 volumio sudo[7065]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 10 16:17:47 volumio sudo[7065]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 16:17:48 volumio sudo[7063]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 10 16:17:48 volumio sudo[7063]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 16:17:48 volumio volumio[6886]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 10 16:17:48 volumio volumio[6886]: info: ___________ START PLUGINS ___________ Feb 10 16:17:48 volumio sudo[7063]: pam_unix(sudo:session): session closed for user root Feb 10 16:17:48 volumio volumio[6886]: info: ControllerMpd::onStart: Initializing MPD Feb 10 16:17:48 volumio volumio[6886]: info: Creating MPD Configuration file Feb 10 16:17:48 volumio sudo[7061]: pam_unix(sudo:session): session closed for user root Feb 10 16:17:48 volumio volumio[6886]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 10 16:17:48 volumio volumio[6886]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 10 16:17:48 volumio volumio[6886]: info: [1770715068105] CoreMusicLibrary::Adding element Media Servers Feb 10 16:17:48 volumio volumio[6886]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 10 16:17:48 volumio volumio[6886]: info: UPNP Browser: Client initialized successfully Feb 10 16:17:48 volumio sudo[7074]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 10 16:17:48 volumio sudo[7074]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 16:17:48 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 10 16:17:48 volumio sudo[7074]: pam_unix(sudo:session): session closed for user root Feb 10 16:17:48 volumio sudo[7076]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 10 16:17:48 volumio volumio[6886]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 16:17:48 volumio volumio[6886]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 16:17:48 volumio sudo[7076]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 16:17:48 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 10 16:17:48 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 10 16:17:48 volumio systemd[1]: mpd.service: Consumed 7.190s CPU time. Feb 10 16:17:48 volumio volumio[6886]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 10 16:17:48 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 10 16:17:48 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 10 16:17:48 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 10 16:17:48 volumio volumio[6886]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 16:17:48 volumio volumio[6886]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 16:17:48 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 10 16:17:48 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 10 16:17:48 volumio volumio[6886]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 10 16:17:48 volumio volumio[6886]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 10 16:17:48 volumio volumio[6886]: info: [1770715068465] CoreMusicLibrary::Adding element Last_100 Feb 10 16:17:48 volumio volumio[6886]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 10 16:17:48 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 10 16:17:48 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 10 16:17:48 volumio volumio[6886]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 10 16:17:48 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 10 16:17:48 volumio volumio[6886]: info: [1770715068487] CoreMusicLibrary::Adding element Webradio Feb 10 16:17:48 volumio volumio[6886]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 10 16:17:48 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 10 16:17:48 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 10 16:17:48 volumio volumio[6886]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 10 16:17:48 volumio volumio[6886]: info: Initializing BBC Radios Feb 10 16:17:48 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 10 16:17:48 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 10 16:17:48 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 56. Feb 10 16:17:48 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 16:17:48 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 16:17:48 volumio go-librespot[7099]: go-librespot daemon starting... Feb 10 16:17:48 volumio go-librespot[7101]: time="2026-02-10T16:17:48+07:00" level=info msg="running go-librespot 0.4.0" Feb 10 16:17:48 volumio go-librespot[7101]: time="2026-02-10T16:17:48+07:00" level=debug msg="app state loaded" Feb 10 16:17:48 volumio go-librespot[7101]: time="2026-02-10T16:17:48+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 16:17:48 volumio volumio[6886]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 10 16:17:48 volumio volumio[6886]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 16:17:48 volumio volumio[6886]: info: Creating Spotify config file Feb 10 16:17:48 volumio volumio[6886]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 16:17:49 volumio sudo[7094]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 10 16:17:49 volumio sudo[7094]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 10 16:17:49 volumio sudo[7094]: pam_unix(sudo:session): session closed for user root Feb 10 16:17:49 volumio go-librespot[7101]: time="2026-02-10T16:17:49+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 10 16:17:49 volumio go-librespot[7101]: time="2026-02-10T16:17:49+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 10 16:17:49 volumio go-librespot[7101]: time="2026-02-10T16:17:49+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 10 16:17:49 volumio go-librespot[7101]: time="2026-02-10T16:17:49+07:00" level=info msg="zeroconf server listening on port 41693" Feb 10 16:17:49 volumio go-librespot[7101]: time="2026-02-10T16:17:49+07:00" level=debug msg="obtained new client token: AADJH25rPK6m1qYnyR+Nse3swRaGq5U00wMP40J3itIUJuA960qsTsnukhUKbLsCrdrYTBQFYeHTryfybeMK30GftiEgN9C3ipdrJaUVUAFlAB+qjLokDIFeqEReM0FnVjSPbpvvCnX1y8jOMWnpiaIK5MhFlUc3DeSHGl1ZohePk/ykubGZ7Nfc9v6q8Jyfv6tb+g3vuvzs2e+AJPd3elyBFVnJtCg51OjsOA/Sib21HkOVDU8DwHlBaA==" Feb 10 16:17:49 volumio go-librespot[7101]: time="2026-02-10T16:17:49+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 10 16:17:50 volumio go-librespot[7101]: time="2026-02-10T16:17:50+07:00" level=debug msg="completed keyexchange" Feb 10 16:17:50 volumio go-librespot[7101]: time="2026-02-10T16:17:50+07:00" level=debug msg="completed challenge" Feb 10 16:17:50 volumio go-librespot[7101]: time="2026-02-10T16:17:50+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 10 16:17:50 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 16:17:50 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 16:17:50 volumio volumio[6886]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 10 16:17:50 volumio volumio[6886]: info: [1770715070212] CoreMusicLibrary::Adding element YouTube Music Feb 10 16:17:50 volumio volumio[6886]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 10 16:17:50 volumio volumio[6886]: Cannot find translation for source YouTube Music Feb 10 16:17:50 volumio volumio[7011]: Starting albumart workers Feb 10 16:17:50 volumio volumio[6886]: info: Volumio Calling Home Feb 10 16:17:50 volumio volumio[7013]: Starting albumart workers Feb 10 16:17:50 volumio sudo[7115]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Feb 10 16:17:50 volumio sudo[7115]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 16:17:50 volumio sudo[7115]: pam_unix(sudo:session): session closed for user root Feb 10 16:17:50 volumio volumio[6886]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Feb 10 16:17:50 volumio volumio[6886]: info: Discovery: Found device Volumio Feb 10 16:17:50 volumio volumio[6886]: info: CoreCommandRouter::volumioGetState Feb 10 16:17:50 volumio volumio[6886]: info: CorePlayQueue::getTrack 0 Feb 10 16:17:50 volumio volumio[6886]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Feb 10 16:17:50 volumio volumio[6886]: info: Discovery: Found device Volumio Feb 10 16:17:50 volumio volumio[6886]: info: CoreCommandRouter::volumioGetState Feb 10 16:17:50 volumio volumio[6886]: info: CorePlayQueue::getTrack 0 Feb 10 16:17:51 volumio volumio[6886]: info: MPD Permissions set Feb 10 16:17:51 volumio volumio[6886]: info: MPD Permissions set Feb 10 16:17:51 volumio volumio[6886]: info: Upmpdcli Daemon Started Feb 10 16:17:51 volumio volumio[6886]: info: Spotify config file written Feb 10 16:17:51 volumio volumio[7010]: Starting albumart workers Feb 10 16:17:51 volumio volumio[6886]: 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 10 16:17:51 volumio sudo[7121]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 10 16:17:51 volumio sudo[7121]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 16:17:51 volumio volumio[6886]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 16:17:51 volumio volumio[6886]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 16:17:51 volumio volumio[6886]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 16:17:51 volumio volumio[6886]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 16:17:51 volumio volumio[6886]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 16:17:51 volumio volumio[6886]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 16:17:51 volumio volumio[6886]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 16:17:51 volumio volumio[6886]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 16:17:51 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 16:17:51 volumio volumio[6886]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 16:17:51 volumio volumio[6886]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 16:17:51 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 16:17:51 volumio volumio[6886]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 16:17:51 volumio volumio[6886]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 16:17:51 volumio volumio[6886]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 16:17:51 volumio volumio[6886]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 16:17:51 volumio volumio[6886]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 16:17:51 volumio volumio[6886]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 16:17:51 volumio go-librespot[7128]: go-librespot daemon starting... Feb 10 16:17:51 volumio volumio[6886]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 16:17:51 volumio volumio[6886]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 16:17:51 volumio sudo[7121]: pam_unix(sudo:session): session closed for user root Feb 10 16:17:51 volumio go-librespot[7129]: time="2026-02-10T16:17:51+07:00" level=info msg="running go-librespot 0.4.0" Feb 10 16:17:51 volumio go-librespot[7129]: time="2026-02-10T16:17:51+07:00" level=debug msg="app state loaded" Feb 10 16:17:51 volumio go-librespot[7129]: time="2026-02-10T16:17:51+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 16:17:51 volumio volumio[6886]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 16:17:51 volumio volumio[6886]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 16:17:51 volumio volumio[6886]: info: No need to fix Spotify hosts Feb 10 16:17:52 volumio go-librespot[7129]: time="2026-02-10T16:17:52+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 10 16:17:52 volumio go-librespot[7129]: time="2026-02-10T16:17:52+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 10 16:17:52 volumio go-librespot[7129]: time="2026-02-10T16:17:52+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 10 16:17:52 volumio go-librespot[7129]: time="2026-02-10T16:17:52+07:00" level=info msg="zeroconf server listening on port 34987" Feb 10 16:17:52 volumio go-librespot[7129]: time="2026-02-10T16:17:52+07:00" level=debug msg="obtained new client token: AADInCElzrTWH2Euqan1JgBUTCrPw4kOu8FQ6Oxq56ZaH4u9txAdN8werrE07mCpwWvfWbKEEojKm/1ribqzeLk46G3BHDxQzKaYWA/J9ROhsLc2dG0ndSA9c/Lgqq/Ic/yBLMBjQeqQ4fsOJjg7riSUgWAxD8tZ3QIxH3V9Wa4wgjJrCThXdM9uOxSphaePFMpgvKgPUTOWUDKPiIi0MJlrH6uhAYWqa0vK0pDlWiu0zjTDjl5dTLxWWQ==" Feb 10 16:17:52 volumio go-librespot[7129]: time="2026-02-10T16:17:52+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 10 16:17:52 volumio go-librespot[7129]: time="2026-02-10T16:17:52+07:00" level=debug msg="completed keyexchange" Feb 10 16:17:52 volumio go-librespot[7129]: time="2026-02-10T16:17:52+07:00" level=debug msg="completed challenge" Feb 10 16:17:52 volumio go-librespot[7129]: time="2026-02-10T16:17:52+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 10 16:17:52 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 16:17:52 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 16:17:52 volumio volumio[6886]: info: Volumio called home Feb 10 16:17:52 volumio volumio[6886]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 10 16:17:52 volumio volumio[6886]: SPOTIFY: BQCShlTnujnD6n0LpWtUbArK8dblFS47iLuTXcIULId_780r-_YunhVZFRCOg76PF8LmwSS8sXggjRfjuwaFxjNoYx-frfLVI21-gb17F9TcZTRvMDIVmHtaPjNzNjaBZQoWwyoTBb1JxgXlcx6Bh_pGlmBVTp2N8ioVMp3Obq24G9R1l-PAZ0-woue-mKKtUIfuwX33jVI-NtxRfqdfHD0eEG2yE6mWa1ik_FkqFdJeeoYFkhs4xgOXxKyahgR76UQuA5XPUklTfpGcrUY1jtbPIQizSmh9AY4ojcuOQQbqRDwS006fDfi_ Feb 10 16:17:52 volumio volumio[6886]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 10 16:17:52 volumio volumio[6886]: info: New Spotify access token = BQCShlTnujnD6n0LpWtUbArK8dblFS47iLuTXcIULId_780r-_YunhVZFRCOg76PF8LmwSS8sXggjRfjuwaFxjNoYx-frfLVI21-gb17F9TcZTRvMDIVmHtaPjNzNjaBZQoWwyoTBb1JxgXlcx6Bh_pGlmBVTp2N8ioVMp3Obq24G9R1l-PAZ0-woue-mKKtUIfuwX33jVI-NtxRfqdfHD0eEG2yE6mWa1ik_FkqFdJeeoYFkhs4xgOXxKyahgR76UQuA5XPUklTfpGcrUY1jtbPIQizSmh9AY4ojcuOQQbqRDwS006fDfi_ Feb 10 16:17:52 volumio volumio[6886]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 10 16:17:53 volumio volumio[6886]: info: Starting Shairport Sync Feb 10 16:17:53 volumio volumio[6886]: info: Starting Shairport Sync Feb 10 16:17:53 volumio volumio[6886]: info: Starting Shairport Sync Feb 10 16:17:53 volumio sudo[7154]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 10 16:17:53 volumio sudo[7154]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 16:17:53 volumio sudo[7156]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 10 16:17:53 volumio sudo[7156]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 16:17:53 volumio sudo[7159]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 10 16:17:53 volumio sudo[7159]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 16:17:53 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 10 16:17:53 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 10 16:17:53 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 10 16:17:53 volumio systemd[1]: shairport-sync.service: Consumed 2.220s CPU time. Feb 10 16:17:53 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 10 16:17:53 volumio sudo[7159]: pam_unix(sudo:session): session closed for user root Feb 10 16:17:53 volumio sudo[7154]: pam_unix(sudo:session): session closed for user root Feb 10 16:17:53 volumio sudo[7156]: pam_unix(sudo:session): session closed for user root Feb 10 16:17:53 volumio volumio[6886]: info: Shairport-Sync Started Feb 10 16:17:53 volumio volumio[6886]: Error adding Membership: Error: addMembership EINVAL Feb 10 16:17:53 volumio volumio[6886]: info: Shairport-Sync Started Feb 10 16:17:53 volumio volumio[6886]: info: Shairport-Sync Started Feb 10 16:17:53 volumio volumio[6886]: info: CoreCommandRouter::volumioGetState Feb 10 16:17:53 volumio volumio[6886]: info: CorePlayQueue::getTrack 0 Feb 10 16:17:53 volumio volumio[6886]: 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 10 16:17:53 volumio volumio[6886]: info: Spotify Successfully logged in Feb 10 16:17:53 volumio volumio[6886]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 10 16:17:53 volumio volumio[6886]: info: [1770715073899] CoreMusicLibrary::Adding element Spotify Feb 10 16:17:53 volumio volumio[6886]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 10 16:17:53 volumio volumio[6886]: Cannot find translation for source YouTube Music Feb 10 16:17:53 volumio volumio[6886]: Cannot find translation for source Spotify Feb 10 16:17:54 volumio volumio[6886]: info: [yt-cast-receiver] DIAL server listening on port 8098 Feb 10 16:17:54 volumio volumio[6886]: info: CoreCommandRouter::volumioRetrievevolume Feb 10 16:17:54 volumio volumio[6886]: info: VolumeController:: Volume=100 Mute =false Feb 10 16:17:54 volumio volumio[6886]: info: CoreCommandRouter::volumioGetState Feb 10 16:17:54 volumio volumio[6886]: info: CorePlayQueue::getTrack 0 Feb 10 16:17:54 volumio volumio[6886]: info: CoreStateMachine::pushState Feb 10 16:17:54 volumio volumio[6886]: info: CorePlayQueue::getTrack 0 Feb 10 16:17:54 volumio volumio[6886]: info: CoreCommandRouter::volumioPushState Feb 10 16:17:55 volumio volumio[6886]: info: go-librespot daemon successfully initialized Feb 10 16:17:56 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 57. Feb 10 16:17:56 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 16:17:56 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 16:17:56 volumio go-librespot[7201]: go-librespot daemon starting... Feb 10 16:17:56 volumio mpd[7113]: 2026-02-10T16:17:56 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 10 16:17:56 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 10 16:17:56 volumio sudo[7076]: pam_unix(sudo:session): session closed for user root Feb 10 16:17:56 volumio sudo[7065]: pam_unix(sudo:session): session closed for user root Feb 10 16:17:56 volumio go-librespot[7202]: time="2026-02-10T16:17:56+07:00" level=info msg="running go-librespot 0.4.0" Feb 10 16:17:56 volumio go-librespot[7202]: time="2026-02-10T16:17:56+07:00" level=debug msg="app state loaded" Feb 10 16:17:56 volumio go-librespot[7202]: time="2026-02-10T16:17:56+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 16:17:56 volumio volumio[6886]: error: MPD error: The expression evaluated to a falsy value: Feb 10 16:17:56 volumio volumio[6886]: assert.ok(self.idling) Feb 10 16:17:56 volumio volumio[6886]: error: The expression evaluated to a falsy value: Feb 10 16:17:56 volumio volumio[6886]: assert.ok(self.idling) Feb 10 16:17:56 volumio volumio[6886]: error: updateQueue error: null Feb 10 16:17:56 volumio volumio[6886]: info: MPD running with PID7113 Feb 10 16:17:56 volumio volumio[6886]: ,establishing connection Feb 10 16:17:56 volumio volumio[6886]: info: Completed starting Core Plugins Feb 10 16:17:56 volumio volumio[6886]: info: ------------------------------------------- Feb 10 16:17:56 volumio volumio[6886]: info: ----- MyVolumio plugins startup ---- Feb 10 16:17:56 volumio volumio[6886]: info: ------------------------------------------- Feb 10 16:17:56 volumio volumio[6886]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 10 16:17:56 volumio volumio[6886]: error: updateQueue error: null Feb 10 16:17:56 volumio go-librespot[7202]: time="2026-02-10T16:17:56+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 10 16:17:56 volumio go-librespot[7202]: time="2026-02-10T16:17:56+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 10 16:17:56 volumio go-librespot[7202]: time="2026-02-10T16:17:56+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 10 16:17:56 volumio go-librespot[7202]: time="2026-02-10T16:17:56+07:00" level=info msg="zeroconf server listening on port 39341" Feb 10 16:17:57 volumio go-librespot[7202]: time="2026-02-10T16:17:57+07:00" level=debug msg="obtained new client token: AAD702bFQ5Jy/csGz9NvK8fRsrewxgResQYV/0Kr0tZS24AkEkT7cRz6XEDMfhvx6E9rGgavXiZwrkIY2TYOg7oNez+bg79tnb6V4lXMc+8vsMk/Aov9BW8l3ElSErSsTofQXJH1e+Sw9dr4LusmSp4Ukcb22zCD6z5MiVN6Yu3vlyX6fIMwepJxYvRcvkgdPtHHwXx7nt9DbWyWaVQMPU0zK1cg0QiwGXp2bhz1VgRjMlyjHAUcdXXMbw==" Feb 10 16:17:57 volumio go-librespot[7202]: time="2026-02-10T16:17:57+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 10 16:17:57 volumio go-librespot[7202]: time="2026-02-10T16:17:57+07:00" level=debug msg="completed keyexchange" Feb 10 16:17:57 volumio go-librespot[7202]: time="2026-02-10T16:17:57+07:00" level=debug msg="completed challenge" Feb 10 16:17:57 volumio go-librespot[7202]: time="2026-02-10T16:17:57+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 10 16:17:57 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 16:17:57 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 16:17:58 volumio volumio[6886]: info: Initializing connection to go-librespot Websocket Feb 10 16:17:58 volumio volumio[6886]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 10 16:18:00 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 58. Feb 10 16:18:00 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 16:18:00 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 16:18:00 volumio go-librespot[7213]: go-librespot daemon starting... Feb 10 16:18:00 volumio go-librespot[7214]: time="2026-02-10T16:18:00+07:00" level=info msg="running go-librespot 0.4.0" Feb 10 16:18:00 volumio go-librespot[7214]: time="2026-02-10T16:18:00+07:00" level=debug msg="app state loaded" Feb 10 16:18:00 volumio go-librespot[7214]: time="2026-02-10T16:18:00+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 16:18:00 volumio go-librespot[7214]: time="2026-02-10T16:18: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-gew1.spotify.com:80]" Feb 10 16:18:00 volumio go-librespot[7214]: time="2026-02-10T16:18:00+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 10 16:18:00 volumio go-librespot[7214]: time="2026-02-10T16:18:00+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 10 16:18:00 volumio go-librespot[7214]: time="2026-02-10T16:18:00+07:00" level=info msg="zeroconf server listening on port 35677" Feb 10 16:18:01 volumio go-librespot[7214]: time="2026-02-10T16:18:01+07:00" level=debug msg="obtained new client token: AABWb1GdIHlR0AM77cMnrErs2GL8k6jEmNi3WXGAh61V0rQGO+XOovnfNDL/FaKrpeqtvMDRhhkVb/MR5mfElc8s8d8yXQYra7toFOZb6vkuGVdjpB1AJw665oEmxim36ExwqnD4Tgjn3oQUICCNaVWUvQhJEwMGKY6FyLBysBRyJJOG/7+dHUetz1sAvAji9nhGb3g6qzKd0P57nREd7owDP23IH1xcnjlR2P3zfesLdSItF+yyKiU=" Feb 10 16:18:01 volumio go-librespot[7214]: time="2026-02-10T16:18:01+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 10 16:18:01 volumio volumio[6886]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 10 16:18:01 volumio go-librespot[7214]: time="2026-02-10T16:18:01+07:00" level=debug msg="completed keyexchange" Feb 10 16:18:01 volumio go-librespot[7214]: time="2026-02-10T16:18:01+07:00" level=debug msg="completed challenge" Feb 10 16:18:01 volumio go-librespot[7214]: time="2026-02-10T16:18:01+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 10 16:18:01 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 16:18:01 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 16:18:01 volumio volumio[6886]: info: Initializing connection to go-librespot Websocket Feb 10 16:18:01 volumio volumio[6886]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 10 16:18:04 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 59. Feb 10 16:18:04 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 16:18:04 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 16:18:04 volumio go-librespot[7221]: go-librespot daemon starting... Feb 10 16:18:04 volumio go-librespot[7222]: time="2026-02-10T16:18:04+07:00" level=info msg="running go-librespot 0.4.0" Feb 10 16:18:04 volumio go-librespot[7222]: time="2026-02-10T16:18:04+07:00" level=debug msg="app state loaded" Feb 10 16:18:04 volumio go-librespot[7222]: time="2026-02-10T16:18:04+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 16:18:04 volumio volumio[6886]: info: Initializing connection to go-librespot Websocket Feb 10 16:18:04 volumio go-librespot[7222]: time="2026-02-10T16:18:04+07:00" level=debug msg="new websocket client" Feb 10 16:18:04 volumio volumio[6886]: info: Connection to go-librespot Websocket established Feb 10 16:18:05 volumio go-librespot[7222]: time="2026-02-10T16:18:05+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 10 16:18:05 volumio go-librespot[7222]: time="2026-02-10T16:18:05+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 10 16:18:05 volumio go-librespot[7222]: time="2026-02-10T16:18:05+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 10 16:18:05 volumio go-librespot[7222]: time="2026-02-10T16:18:05+07:00" level=info msg="zeroconf server listening on port 37947" Feb 10 16:18:05 volumio volumio[6886]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 10 16:18:05 volumio volumio[6886]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 10 16:18:05 volumio volumio[6886]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 10 16:18:05 volumio volumio[6886]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 10 16:18:05 volumio volumio[6886]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 10 16:18:05 volumio volumio[6886]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 10 16:18:05 volumio volumio[6886]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 10 16:18:05 volumio volumio[6886]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 10 16:18:05 volumio volumio[6886]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 10 16:18:05 volumio volumio[6886]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 10 16:18:05 volumio volumio[6886]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 10 16:18:05 volumio volumio[6886]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 10 16:18:05 volumio volumio[6886]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 10 16:18:05 volumio volumio[6886]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 10 16:18:05 volumio volumio[6886]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 10 16:18:05 volumio volumio[6886]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 10 16:18:05 volumio volumio[6886]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 10 16:18:05 volumio volumio[6886]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 10 16:18:05 volumio volumio[6886]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 10 16:18:05 volumio volumio[6886]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 10 16:18:05 volumio volumio[6886]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 10 16:18:05 volumio volumio[6886]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 10 16:18:05 volumio volumio[6886]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 10 16:18:05 volumio volumio[6886]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 10 16:18:05 volumio volumio[6886]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 10 16:18:05 volumio volumio[6886]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 10 16:18:05 volumio volumio[6886]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 10 16:18:05 volumio volumio[6886]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 10 16:18:05 volumio volumio[6886]: info: Adding plugin bluetooth to MyMusic Plugins Feb 10 16:18:05 volumio volumio[6886]: info: Adding plugin multiroom to MyMusic Plugins Feb 10 16:18:05 volumio volumio[6886]: info: Adding plugin metavolumio to MyMusic Plugins Feb 10 16:18:05 volumio volumio[6886]: info: Adding plugin cd_controller to MyMusic Plugins Feb 10 16:18:05 volumio volumio[6886]: info: Adding plugin qobuzconnect to MyMusic Plugins Feb 10 16:18:05 volumio volumio[6886]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 10 16:18:05 volumio volumio[6886]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 10 16:18:05 volumio volumio[6886]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 10 16:18:05 volumio go-librespot[7222]: time="2026-02-10T16:18:05+07:00" level=debug msg="obtained new client token: AAAz1mmrKJG2EF2ox3324uO1uiUADRhAGPNYY6ZYv8i7PmHLjY7B1zp1dxd/Q6aEA6snx8lQG8X22Nn6kyYXwKcrrEda3vxYNyF4ziHYSj92mIlspbwOE6z87uihNZDcubxx5njhvAc781NBOYM3KGwAk+OfOM/4UHQyq6A/tQg1yysiKBxXRnvnruIvGRVDZBEB8gLUsHIJ/T9KTwZl7VTpCoK077HLYe9DNHe8ZvNn6O57MbVslWQniA==" Feb 10 16:18:05 volumio go-librespot[7222]: time="2026-02-10T16:18:05+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 10 16:18:05 volumio go-librespot[7222]: time="2026-02-10T16:18:05+07:00" level=debug msg="completed keyexchange" Feb 10 16:18:05 volumio go-librespot[7222]: time="2026-02-10T16:18:05+07:00" level=debug msg="completed challenge" Feb 10 16:18:05 volumio go-librespot[7222]: time="2026-02-10T16:18:05+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 10 16:18:05 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 16:18:05 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 16:18:07 volumio volumio[6886]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 10 16:18:07 volumio volumio[6886]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 10 16:18:07 volumio volumio[6886]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 16:18:07 volumio volumio[6886]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 16:18:07 volumio volumio[6886]: info: Starting MyVolumio Remote Streaming Endpoints Feb 10 16:18:07 volumio volumio[6886]: info: MyVolumio login type: Token Feb 10 16:18:07 volumio volumio[6886]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 10 16:18:07 volumio volumio[6886]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 10 16:18:08 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 60. Feb 10 16:18:08 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 16:18:08 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 16:18:08 volumio go-librespot[7243]: go-librespot daemon starting... Feb 10 16:18:08 volumio volumio[6886]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 10 16:18:08 volumio volumio[6886]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 10 16:18:08 volumio volumio[6886]: info: Streaming services startup Feb 10 16:18:08 volumio volumio[6886]: info: Starting Streaming Daemon Feb 10 16:18:08 volumio go-librespot[7244]: time="2026-02-10T16:18:08+07:00" level=info msg="running go-librespot 0.4.0" Feb 10 16:18:08 volumio go-librespot[7244]: time="2026-02-10T16:18:08+07:00" level=debug msg="app state loaded" Feb 10 16:18:08 volumio go-librespot[7244]: time="2026-02-10T16:18:08+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 16:18:08 volumio sudo[7252]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 10 16:18:08 volumio sudo[7252]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 16:18:08 volumio volumio[6886]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 10 16:18:09 volumio sudo[7252]: pam_unix(sudo:session): session closed for user root Feb 10 16:18:09 volumio volumio[6886]: info: Getting Spotify volume Feb 10 16:18:09 volumio volumio[6886]: info: Connection to go-librespot Websocket closed Feb 10 16:18:09 volumio volumio[6886]: error: Cannot start Volumio Streaming Daemon Feb 10 16:18:09 volumio volumio[6886]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 10 16:18:09 volumio volumio[6886]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 10 16:18:09 volumio volumio[6886]: 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 10 16:18:09 volumio volumio[6886]: info: CoreCommandRouter::volumioGetState Feb 10 16:18:09 volumio volumio[6886]: info: CorePlayQueue::getTrack 0 Feb 10 16:18:09 volumio volumio[6886]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Feb 10 16:18:09 volumio volumio[6886]: SPOTIFY: SPOTIFY VOLUME undefined Feb 10 16:18:09 volumio volumio[6886]: SPOTIFY: VOLUMIO VOLUME 100 Feb 10 16:18:09 volumio volumio[6886]: info: Aligning Spotify Volume to Volumio Volume Feb 10 16:18:09 volumio volumio[6886]: info: CoreCommandRouter::volumioGetState Feb 10 16:18:09 volumio volumio[6886]: info: CorePlayQueue::getTrack 0 Feb 10 16:18:09 volumio volumio[6886]: info: Setting Spotify Volume from Volumio: 100 Feb 10 16:18:09 volumio go-librespot[7244]: time="2026-02-10T16:18:09+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 10 16:18:09 volumio go-librespot[7244]: time="2026-02-10T16:18:09+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 10 16:18:09 volumio go-librespot[7244]: time="2026-02-10T16:18:09+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 10 16:18:09 volumio go-librespot[7244]: time="2026-02-10T16:18:09+07:00" level=info msg="zeroconf server listening on port 39457" Feb 10 16:18:09 volumio go-librespot[7244]: time="2026-02-10T16:18:09+07:00" level=debug msg="obtained new client token: AAA8raTjwyk13c61+OiR/D2TElphKuVY4228+fbkUYKsJvIbRYsENfLPUzvANzlGJWoQYwoD8UOXEUX00dPNMcCE9Fz8ieVWbBjJsk/8V8bysoEP+Rybr7H897PF5Ujt2BGke8Kz6IdQFLVI8gpwHota0r3mNB2Nk9hGc37ekQbwxe//MhlGN2Ovhl1RhflAkMFqUIMUjRQuxqFR0ncsOdU+6T/ZV42/PIEf78XHi4phorXQeyaXEBV+PQ==" Feb 10 16:18:09 volumio go-librespot[7244]: time="2026-02-10T16:18:09+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 10 16:18:09 volumio go-librespot[7244]: time="2026-02-10T16:18:09+07:00" level=debug msg="completed keyexchange" Feb 10 16:18:10 volumio go-librespot[7244]: time="2026-02-10T16:18:10+07:00" level=debug msg="completed challenge" Feb 10 16:18:10 volumio go-librespot[7244]: time="2026-02-10T16:18:10+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 10 16:18:10 volumio volumio[6886]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Feb 10 16:18:10 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 16:18:10 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 16:18:10 volumio volumio[6886]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 10 16:18:10 volumio volumio[6886]: Error: socket hang up Feb 10 16:18:10 volumio volumio[6886]: at connResetException (node:internal/errors:720:14) Feb 10 16:18:10 volumio volumio[6886]: at Socket.socketOnEnd (node:_http_client:519:23) Feb 10 16:18:10 volumio volumio[6886]: at Socket.emit (node:events:526:35) Feb 10 16:18:10 volumio volumio[6886]: at endReadableNT (node:internal/streams/readable:1376:12) Feb 10 16:18:10 volumio volumio[6886]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Feb 10 16:18:10 volumio volumio[6886]: code: 'ECONNRESET', Feb 10 16:18:10 volumio volumio[6886]: response: undefined Feb 10 16:18:10 volumio volumio[6886]: } Feb 10 16:18:10 volumio volumio[6886]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 10 16:18:11 volumio sudo[7272]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-10 16:17' Feb 10 16:18:11 volumio sudo[7272]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 16:18:11 volumio sudo[7272]: pam_unix(sudo:session): session closed for user root Feb 10 16:18:13 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 61. Feb 10 16:18:13 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 16:18:13 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 16:18:13 volumio go-librespot[7280]: go-librespot daemon starting... Feb 10 16:18:13 volumio go-librespot[7281]: time="2026-02-10T16:18:13+07:00" level=info msg="running go-librespot 0.4.0" Feb 10 16:18:13 volumio go-librespot[7281]: time="2026-02-10T16:18:13+07:00" level=debug msg="app state loaded" Feb 10 16:18:13 volumio go-librespot[7281]: time="2026-02-10T16:18:13+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 16:18:13 volumio volumio-remote-updater[643]: [2026-02-10 16:18:13] [error] handle_read_frame error: asio.system:104 (Connection reset by peer) Feb 10 16:18:13 volumio volumio-remote-updater[643]: [2026-02-10 16:18:13] [disconnect] Disconnect close local:[1006,Connection reset by peer] remote:[1006] Feb 10 16:18:13 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Feb 10 16:18:13 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Feb 10 16:18:13 volumio systemd[1]: volumio.service: Consumed 55.945s CPU time. Feb 10 16:18:13 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 10 16:18:13 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 10 16:18:13 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 10465. Feb 10 16:18:13 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 10 16:18:13 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Feb 10 16:18:13 volumio systemd[1]: volumio.service: Consumed 55.945s CPU time. Feb 10 16:18:13 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Feb 10 16:18:13 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 10 16:18:13 volumio go-librespot[7281]: time="2026-02-10T16:18:13+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 10 16:18:13 volumio go-librespot[7281]: time="2026-02-10T16:18:13+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 10 16:18:13 volumio go-librespot[7281]: time="2026-02-10T16:18:13+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 10 16:18:13 volumio go-librespot[7281]: time="2026-02-10T16:18:13+07:00" level=info msg="zeroconf server listening on port 38589" Feb 10 16:18:14 volumio go-librespot[7281]: time="2026-02-10T16:18:14+07:00" level=debug msg="obtained new client token: AACfxnbGOvGiWTvA0OWLASnEbQwDVtH4WbGsFj9l60qVfXw2fX7jxOvFgGHsuWaZRk04aD+f3VY3R9lDkAOqWLyuXVOyFjLPyzszcvwrPztj4e5NqAv8Y55JnwbH09SfpcRr25ALBSWc+uVwpUGGcRGNZLxHCU4FIvf2iMXIWqRP7nRxAUxiUFt8KnUJQPJWptRY1owOB8u0GGlKxSlF7VcxL2Kp/3Y0dpKOZ1NAgpE2WDa/jgJFgiE=" Feb 10 16:18:14 volumio go-librespot[7281]: time="2026-02-10T16:18:14+07:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:4070, retrying with a different AP" error="dial tcp 104.199.241.202:4070: connect: connection refused" Feb 10 16:18:14 volumio go-librespot[7281]: time="2026-02-10T16:18:14+07:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:443, retrying with a different AP" error="dial tcp 104.199.241.202:443: connect: connection refused" Feb 10 16:18:14 volumio go-librespot[7281]: time="2026-02-10T16:18:14+07:00" level=debug msg="connected to ap-gae2.spotify.com:80" Feb 10 16:18:14 volumio go-librespot[7281]: time="2026-02-10T16:18:14+07:00" level=debug msg="completed keyexchange" Feb 10 16:18:14 volumio go-librespot[7281]: time="2026-02-10T16:18:14+07:00" level=debug msg="completed challenge" Feb 10 16:18:14 volumio go-librespot[7281]: time="2026-02-10T16:18:14+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 10 16:18:14 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 16:18:14 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 16:18:17 volumio volumio[7302]: info: ------------------------------------------- Feb 10 16:18:17 volumio volumio[7302]: info: ----- Volumio3 ---- Feb 10 16:18:17 volumio volumio[7302]: info: ------------------------------------------- Feb 10 16:18:17 volumio volumio[7302]: info: ----- System startup ---- Feb 10 16:18:17 volumio volumio[7302]: info: ------------------------------------------- Feb 10 16:18:17 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 62. Feb 10 16:18:17 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 16:18:17 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 16:18:17 volumio go-librespot[7324]: go-librespot daemon starting... Feb 10 16:18:18 volumio go-librespot[7325]: time="2026-02-10T16:18:18+07:00" level=info msg="running go-librespot 0.4.0" Feb 10 16:18:18 volumio go-librespot[7325]: time="2026-02-10T16:18:18+07:00" level=debug msg="app state loaded" Feb 10 16:18:18 volumio go-librespot[7325]: time="2026-02-10T16:18:18+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 16:18:18 volumio volumio-remote-updater[643]: [2026-02-10 16:18:18] [connect] Successful connection Feb 10 16:18:18 volumio go-librespot[7325]: time="2026-02-10T16:18:18+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 10 16:18:18 volumio go-librespot[7325]: time="2026-02-10T16:18:18+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 10 16:18:18 volumio go-librespot[7325]: time="2026-02-10T16:18:18+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 10 16:18:18 volumio go-librespot[7325]: time="2026-02-10T16:18:18+07:00" level=info msg="zeroconf server listening on port 43723" Feb 10 16:18:18 volumio volumio[7302]: info: MYVOLUMIO Environment detected Feb 10 16:18:18 volumio go-librespot[7325]: time="2026-02-10T16:18:18+07:00" level=debug msg="obtained new client token: AAAqx595/pulD741OXjL0H+T9V/VVGC0lAKg/M0ax4KczxcwuvzDjIM7IRRiKr4ZSK8waPdvya8aEs9VfrTNlc2zkW16Ov0MblS9UAL0R2InDHPa54mfOUpagPMJ9EwALNY67vXhaOx4riJ+4avm5KDyaGjRc7I/6ntWGN0SAWL6/QRNS9yYxoSXuKtgJ1YD9Oio2gc/VdRJEIs4Uh7lQ3RNokgU89CZgX8WsFAcl/IB2FqZAF+HNoH7LA==" Feb 10 16:18:18 volumio volumio[7302]: info: Plugin folders cleanup Feb 10 16:18:18 volumio volumio[7302]: info: Scanning into folder /volumio/app/plugins/ Feb 10 16:18:18 volumio volumio[7302]: info: Scanning category audio_interface Feb 10 16:18:18 volumio volumio[7302]: info: Scanning category miscellanea Feb 10 16:18:18 volumio volumio[7302]: info: Scanning category music_service Feb 10 16:18:18 volumio volumio[7302]: info: Scanning category plugins.json Feb 10 16:18:18 volumio volumio[7302]: info: Scanning category system_controller Feb 10 16:18:18 volumio volumio[7302]: info: Scanning category user_interface Feb 10 16:18:18 volumio volumio[7302]: info: Scanning into folder /data/plugins/ Feb 10 16:18:18 volumio volumio[7302]: info: Scanning category music_service Feb 10 16:18:18 volumio volumio[7302]: info: Plugin folders cleanup completed Feb 10 16:18:18 volumio volumio[7302]: info: ------------------------------------------- Feb 10 16:18:18 volumio volumio[7302]: info: ----- Core plugins startup ---- Feb 10 16:18:18 volumio volumio[7302]: info: ------------------------------------------- Feb 10 16:18:18 volumio volumio[7302]: info: Loading plugins from folder /volumio/app/plugins/ Feb 10 16:18:18 volumio volumio[7302]: info: Adding plugin upnp to MyMusic Plugins Feb 10 16:18:18 volumio volumio[7302]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 10 16:18:18 volumio volumio[7302]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 10 16:18:18 volumio volumio[7302]: info: Loading plugins from folder /data/plugins/ Feb 10 16:18:18 volumio volumio[7302]: info: Loading plugin "system"... Feb 10 16:18:18 volumio go-librespot[7325]: time="2026-02-10T16:18:18+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 10 16:18:18 volumio volumio[7302]: info: Loading plugin "appearance"... Feb 10 16:18:18 volumio go-librespot[7325]: time="2026-02-10T16:18:18+07:00" level=debug msg="completed keyexchange" Feb 10 16:18:18 volumio go-librespot[7325]: time="2026-02-10T16:18:18+07:00" level=debug msg="completed challenge" Feb 10 16:18:19 volumio go-librespot[7325]: time="2026-02-10T16:18:19+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 10 16:18:19 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 16:18:19 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 16:18:20 volumio volumio[7302]: info: Loading plugin "network"... Feb 10 16:18:20 volumio volumio[7302]: info: Refreshing Cached IP Addresses Feb 10 16:18:20 volumio sudo[7339]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 10 16:18:20 volumio sudo[7339]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 16:18:20 volumio sudo[7339]: pam_unix(sudo:session): session closed for user root Feb 10 16:18:20 volumio sudo[7341]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 10 16:18:20 volumio volumio[7302]: info: Loading plugin "services"... Feb 10 16:18:20 volumio sudo[7341]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 16:18:20 volumio volumio[7302]: info: Loading plugin "alsa_controller"... Feb 10 16:18:20 volumio sudo[7341]: pam_unix(sudo:session): session closed for user root Feb 10 16:18:20 volumio sudo[7349]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 10 16:18:20 volumio sudo[7349]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 16:18:21 volumio volumio[7302]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 10 16:18:21 volumio volumio[7302]: info: Loading plugin "wizard"... Feb 10 16:18:21 volumio volumio[7302]: info: Loading plugin "networkfs"... Feb 10 16:18:21 volumio volumio[7302]: info: Starting Udev Watcher for removable devices Feb 10 16:18:21 volumio volumio[7302]: info: Ignoring mount for partition: boot Feb 10 16:18:21 volumio volumio[7302]: info: Ignoring mount for partition: volumio Feb 10 16:18:21 volumio volumio[7302]: info: Ignoring mount for partition: volumio_data Feb 10 16:18:21 volumio volumio[7302]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 10 16:18:21 volumio volumio[7302]: info: Loading plugin "volumio_command_line_client"... Feb 10 16:18:21 volumio volumio[7302]: info: Loading plugin "upnp"... Feb 10 16:18:21 volumio volumio[7302]: info: [1770715101196] Starting Upmpd Daemon Feb 10 16:18:21 volumio volumio[7302]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 10 16:18:21 volumio volumio[7302]: info: Loading plugin "my_music"... Feb 10 16:18:21 volumio volumio[7302]: info: Loading plugin "mpd"... Feb 10 16:18:21 volumio volumio[7302]: info: Loading plugin "upnp_browser"... Feb 10 16:18:22 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 63. Feb 10 16:18:22 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 16:18:22 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 16:18:22 volumio go-librespot[7372]: go-librespot daemon starting... Feb 10 16:18:22 volumio go-librespot[7373]: time="2026-02-10T16:18:22+07:00" level=info msg="running go-librespot 0.4.0" Feb 10 16:18:22 volumio go-librespot[7373]: time="2026-02-10T16:18:22+07:00" level=debug msg="app state loaded" Feb 10 16:18:22 volumio go-librespot[7373]: time="2026-02-10T16:18:22+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 16:18:22 volumio go-librespot[7373]: time="2026-02-10T16:18:22+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 10 16:18:22 volumio go-librespot[7373]: time="2026-02-10T16:18:22+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 10 16:18:22 volumio go-librespot[7373]: time="2026-02-10T16:18:22+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 10 16:18:23 volumio go-librespot[7373]: time="2026-02-10T16:18:23+07:00" level=info msg="zeroconf server listening on port 44189" Feb 10 16:18:23 volumio go-librespot[7373]: time="2026-02-10T16:18:23+07:00" level=debug msg="obtained new client token: AACZxafbVxgaICIqQQPeK3fYE9jCwavRlu5sUd6nuWiG96Me90ifqevtrddqLWRB9CF1SirnfZdp1DsM+6PceBjAmg0MWKtAcQwXaG2yv/S0Uu38hvGa7t/z1UnK4ptXOtv1pWlssI2z9foYAYG5y8I339A6c8L9HljsFpM9VGQ+JzcDyvzEwJHCiF1cADjKf3LqJLMsxIRbno7iujKoFcMTY1YB9zF1R4sG+I0uIoDxMX1SYP7ts+I=" Feb 10 16:18:23 volumio go-librespot[7373]: time="2026-02-10T16:18:23+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 10 16:18:23 volumio go-librespot[7373]: time="2026-02-10T16:18:23+07:00" level=debug msg="completed keyexchange" Feb 10 16:18:23 volumio go-librespot[7373]: time="2026-02-10T16:18:23+07:00" level=debug msg="completed challenge" Feb 10 16:18:23 volumio go-librespot[7373]: time="2026-02-10T16:18:23+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 10 16:18:23 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 16:18:23 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 16:18:23 volumio sudo[7349]: pam_unix(sudo:session): session closed for user root Feb 10 16:18:24 volumio volumio[7302]: info: Starting UPNP Browser Feb 10 16:18:24 volumio volumio[7302]: info: Loading plugin "alarm-clock"... Feb 10 16:18:25 volumio volumio[7302]: info: Loading plugin "airplay_emulation"... Feb 10 16:18:25 volumio volumio[7302]: info: Starting Shairport Sync Feb 10 16:18:25 volumio volumio[7302]: info: Loading plugin "last_100"... Feb 10 16:18:25 volumio volumio[7302]: info: Loading plugin "webradio"... Feb 10 16:18:25 volumio volumio[7302]: info: Loading plugin "i2s_dacs"... Feb 10 16:18:25 volumio volumio[7302]: info: Loading plugin "volumiodiscovery"... Feb 10 16:18:25 volumio volumio[7302]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 10 16:18:25 volumio node[7302]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 10 16:18:25 volumio volumio[7302]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 10 16:18:25 volumio node[7302]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 10 16:18:25 volumio volumio[7302]: *** WARNING *** For more information see Feb 10 16:18:25 volumio node[7302]: *** WARNING *** For more information see Feb 10 16:18:25 volumio volumio[7302]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 10 16:18:25 volumio node[7302]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 10 16:18:25 volumio volumio[7302]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 10 16:18:25 volumio volumio[7302]: *** WARNING *** For more information see Feb 10 16:18:25 volumio node[7302]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 10 16:18:25 volumio node[7302]: *** WARNING *** For more information see Feb 10 16:18:25 volumio volumio[7302]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 10 16:18:25 volumio volumio[7302]: info: Discovery: Started advertising with name: Volumio Feb 10 16:18:25 volumio volumio[7302]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 10 16:18:25 volumio volumio[7302]: info: Loading plugin "spop"... Feb 10 16:18:26 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 64. Feb 10 16:18:26 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 16:18:26 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 16:18:26 volumio go-librespot[7383]: go-librespot daemon starting... Feb 10 16:18:26 volumio go-librespot[7384]: time="2026-02-10T16:18:26+07:00" level=info msg="running go-librespot 0.4.0" Feb 10 16:18:26 volumio go-librespot[7384]: time="2026-02-10T16:18:26+07:00" level=debug msg="app state loaded" Feb 10 16:18:26 volumio go-librespot[7384]: time="2026-02-10T16:18:26+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 16:18:27 volumio go-librespot[7384]: time="2026-02-10T16:18:27+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 10 16:18:27 volumio go-librespot[7384]: time="2026-02-10T16:18:27+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 10 16:18:27 volumio go-librespot[7384]: time="2026-02-10T16:18:27+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 10 16:18:27 volumio go-librespot[7384]: time="2026-02-10T16:18:27+07:00" level=info msg="zeroconf server listening on port 33713" Feb 10 16:18:27 volumio go-librespot[7384]: time="2026-02-10T16:18:27+07:00" level=debug msg="obtained new client token: AAARrtfzHrMT2tiG9s23KyVt7KFPdN0ApRMacJiJYH2XlA1sjbl/E/qnc4iM6CuAnhHRu7N6/TBFMnW3MzSRzPT6z1CWNBjiWRmUgr+BU8VHxaGd2k8llTLzc8De0QPMYooRqe5kCQ4FT+OYCdSkitQAmvAzTdoaeVqxEVEKPUip89zra3Tz0JRTby0Q41btl7HYVZ+Ln2QMGkc2/Pt+2feBUgib6cnviZj9TxAZAg4WRZ4z4egR+cPUgw==" Feb 10 16:18:27 volumio volumio[7302]: info: Loading plugin "ytcr"... Feb 10 16:18:27 volumio go-librespot[7384]: time="2026-02-10T16:18:27+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 10 16:18:27 volumio go-librespot[7384]: time="2026-02-10T16:18:27+07:00" level=debug msg="completed keyexchange" Feb 10 16:18:27 volumio go-librespot[7384]: time="2026-02-10T16:18:27+07:00" level=debug msg="completed challenge" Feb 10 16:18:27 volumio go-librespot[7384]: time="2026-02-10T16:18:27+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 10 16:18:27 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 16:18:27 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 16:18:30 volumio volumio[7302]: info: Loading plugin "ytmusic"... Feb 10 16:18:30 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 65. Feb 10 16:18:30 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 16:18:30 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 16:18:30 volumio go-librespot[7391]: go-librespot daemon starting... Feb 10 16:18:30 volumio go-librespot[7392]: time="2026-02-10T16:18:30+07:00" level=info msg="running go-librespot 0.4.0" Feb 10 16:18:30 volumio go-librespot[7392]: time="2026-02-10T16:18:30+07:00" level=debug msg="app state loaded" Feb 10 16:18:30 volumio go-librespot[7392]: time="2026-02-10T16:18:30+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 16:18:30 volumio volumio-remote-updater[643]: [2026-02-10 16:18:30] [connect] Successful connection Feb 10 16:18:31 volumio volumio[7302]: info: Loading plugin "outputs"... Feb 10 16:18:31 volumio volumio[7302]: info: Loading plugin "albumart"... Feb 10 16:18:31 volumio go-librespot[7392]: time="2026-02-10T16:18:31+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 10 16:18:31 volumio go-librespot[7392]: time="2026-02-10T16:18:31+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 10 16:18:31 volumio go-librespot[7392]: time="2026-02-10T16:18:31+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 10 16:18:31 volumio go-librespot[7392]: time="2026-02-10T16:18:31+07:00" level=info msg="zeroconf server listening on port 41187" Feb 10 16:18:31 volumio volumio[7302]: info: Plugin example_plugin is not enabled Feb 10 16:18:31 volumio volumio[7302]: info: Loading plugin "inputs"... Feb 10 16:18:31 volumio volumio[7302]: info: Loading plugin "updater_comm"... Feb 10 16:18:31 volumio volumio[7302]: info: Plugin mpdemulation is not enabled Feb 10 16:18:31 volumio volumio[7302]: info: Loading plugin "rest_api"... Feb 10 16:18:31 volumio volumio[7302]: info: Loading plugin "websocket"... Feb 10 16:18:31 volumio go-librespot[7392]: time="2026-02-10T16:18:31+07:00" level=debug msg="obtained new client token: AACXewns/DgzC2CF57K9Mbb0wUjGe+0MEoK1lpoo67lO6lGtgYjIs3geuqIxBsyJv40/fgBhkWmgRz7h/8Z04gPJ9OofMasFC2gWu7GeXYrcSudxh9sAtAIoWuDRL5woXCzemnOPwefFGfQgsExmsTUkOpFYGki8D5ed0tiwBMH2IAvS8vkNfMSbIAuqkJByPX8UwZ0lXEYCnkkrRgfTJDBQrUqs2R+nI2YU7xjn5fMN4z10vRDmLJDq7g==" Feb 10 16:18:31 volumio volumio[7302]: info: Starting Socket.io Server version 1.7.4 Feb 10 16:18:31 volumio volumio[7302]: info: Loading plugin "RoonBridge"... Feb 10 16:18:31 volumio go-librespot[7392]: time="2026-02-10T16:18:31+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 10 16:18:31 volumio go-librespot[7392]: time="2026-02-10T16:18:31+07:00" level=debug msg="completed keyexchange" Feb 10 16:18:31 volumio go-librespot[7392]: time="2026-02-10T16:18:31+07:00" level=debug msg="completed challenge" Feb 10 16:18:32 volumio go-librespot[7392]: time="2026-02-10T16:18:32+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 10 16:18:32 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 16:18:32 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 16:18:32 volumio volumio[7302]: info: Applying required configuration parameters for plugin RoonBridge Feb 10 16:18:32 volumio volumio[7302]: info: Loading i18n strings for locale en Feb 10 16:18:32 volumio volumio[7302]: Updating browse sources language Feb 10 16:18:32 volumio volumio[7302]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 10 16:18:32 volumio volumio[7302]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 10 16:18:32 volumio volumio[7302]: info: CoreCommandRouter::initPlayerControls Feb 10 16:18:32 volumio volumio[7302]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 16:18:32 volumio volumio[7302]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 16:18:32 volumio volumio[7302]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 16:18:32 volumio volumio[7302]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 16:18:32 volumio volumio[7302]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 16:18:32 volumio volumio[7302]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 16:18:32 volumio volumio[7302]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 16:18:32 volumio volumio[7302]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 16:18:32 volumio volumio[7302]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 10 16:18:32 volumio volumio[7415]: Forking 3 albumart workers Feb 10 16:18:32 volumio volumio[7302]: Express server listening on port 3000 Feb 10 16:18:32 volumio volumio[7302]: [Metrics] WebUI: 16s 222.62ms Feb 10 16:18:32 volumio volumio[7302]: info: CoreStateMachine::resetVolumioState Feb 10 16:18:32 volumio volumio[7302]: info: CoreStateMachine::getcurrentVolume Feb 10 16:18:32 volumio volumio[7302]: info: CoreCommandRouter::volumioRetrievevolume Feb 10 16:18:32 volumio sudo[7442]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 10 16:18:32 volumio sudo[7442]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 16:18:32 volumio sudo[7451]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 10 16:18:32 volumio sudo[7451]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 16:18:32 volumio sudo[7442]: pam_unix(sudo:session): session closed for user root Feb 10 16:18:32 volumio sudo[7451]: pam_unix(sudo:session): session closed for user root Feb 10 16:18:32 volumio volumio[7302]: info: Volumio Network Manager: Network status updated: 1 Feb 10 16:18:33 volumio volumio-remote-updater[643]: [2026-02-10 16:18:33] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1770715110 101 Feb 10 16:18:33 volumio volumio[7302]: 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 10 16:18:33 volumio volumio[7302]: info: VolumeController:: Volume=100 Mute =false Feb 10 16:18:33 volumio volumio[7302]: info: CoreStateMachine::pushState Feb 10 16:18:33 volumio volumio[7302]: info: CorePlayQueue::getTrack 0 Feb 10 16:18:33 volumio volumio[7302]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 10 16:18:33 volumio volumio[7302]: info: CoreCommandRouter::volumioPushState Feb 10 16:18:33 volumio volumio[7302]: info: CoreStateMachine::updateTrackBlock Feb 10 16:18:33 volumio volumio[7302]: info: CorePlayQueue::getTrackBlock Feb 10 16:18:33 volumio volumio[7302]: info: CoreCommandRouter::volumioRetrievevolume Feb 10 16:18:33 volumio volumio[7302]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 16:18:33 volumio volumio[7302]: info: Reloading queue from file Feb 10 16:18:33 volumio volumio[7302]: info: CoreStateMachine::setRepeat null single undefined Feb 10 16:18:33 volumio volumio[7302]: info: CoreStateMachine::pushState Feb 10 16:18:33 volumio volumio[7302]: info: CorePlayQueue::getTrack 0 Feb 10 16:18:33 volumio volumio[7302]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 10 16:18:33 volumio volumio[7302]: info: CoreCommandRouter::volumioPushState Feb 10 16:18:33 volumio volumio[7302]: info: CoreStateMachine::setRandom null Feb 10 16:18:33 volumio volumio[7302]: info: CoreStateMachine::pushState Feb 10 16:18:33 volumio volumio[7302]: info: CorePlayQueue::getTrack 0 Feb 10 16:18:33 volumio volumio[7302]: info: CoreCommandRouter::volumioPushState Feb 10 16:18:33 volumio volumio[7302]: info: Setting Device type: Raspberry PI Feb 10 16:18:33 volumio volumio[7302]: info: Completed loading Core Plugins Feb 10 16:18:33 volumio volumio[7302]: info: Preparing to generate the ALSA configuration file Feb 10 16:18:33 volumio volumio[7302]: info: VolumeController:: Volume=100 Mute =false Feb 10 16:18:33 volumio volumio[7302]: info: CoreStateMachine::pushState Feb 10 16:18:33 volumio volumio[7302]: info: CorePlayQueue::getTrack 0 Feb 10 16:18:33 volumio volumio[7302]: info: CoreCommandRouter::volumioPushState Feb 10 16:18:33 volumio volumio[7302]: info: Asound.conf file unchanged, so no further update is needed Feb 10 16:18:33 volumio volumio[7302]: info: Output device has changed, restarting MPD Feb 10 16:18:33 volumio sudo[7477]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 10 16:18:33 volumio sudo[7477]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 16:18:33 volumio volumio[7302]: info: Output device has changed, restarting Shairport Sync Feb 10 16:18:33 volumio volumio[7302]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 16:18:33 volumio volumio[7302]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 16:18:33 volumio sudo[7480]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 10 16:18:33 volumio sudo[7480]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 16:18:33 volumio sudo[7480]: pam_unix(sudo:session): session closed for user root Feb 10 16:18:33 volumio sudo[7482]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 10 16:18:33 volumio sudo[7482]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 16:18:33 volumio sudo[7477]: pam_unix(sudo:session): session closed for user root Feb 10 16:18:33 volumio volumio[7302]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 10 16:18:33 volumio volumio[7302]: info: ___________ START PLUGINS ___________ Feb 10 16:18:33 volumio volumio[7302]: info: ControllerMpd::onStart: Initializing MPD Feb 10 16:18:33 volumio volumio[7302]: info: Creating MPD Configuration file Feb 10 16:18:33 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 10 16:18:33 volumio volumio[7302]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 10 16:18:33 volumio volumio[7302]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 10 16:18:33 volumio volumio[7302]: info: [1770715113968] CoreMusicLibrary::Adding element Media Servers Feb 10 16:18:33 volumio volumio[7302]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 10 16:18:34 volumio sudo[7490]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 10 16:18:34 volumio sudo[7490]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 16:18:34 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 10 16:18:34 volumio volumio[7302]: info: UPNP Browser: Client initialized successfully Feb 10 16:18:34 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 10 16:18:34 volumio systemd[1]: mpd.service: Consumed 7.197s CPU time. Feb 10 16:18:34 volumio sudo[7490]: pam_unix(sudo:session): session closed for user root Feb 10 16:18:34 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 10 16:18:34 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 10 16:18:34 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 10 16:18:34 volumio sudo[7492]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 10 16:18:34 volumio sudo[7492]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 16:18:34 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 10 16:18:34 volumio volumio[7302]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 16:18:34 volumio volumio[7302]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 16:18:34 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 10 16:18:34 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 10 16:18:34 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 10 16:18:34 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 10 16:18:34 volumio volumio[7302]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 10 16:18:34 volumio volumio[7302]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 16:18:34 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 10 16:18:34 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 10 16:18:34 volumio volumio[7302]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 16:18:34 volumio volumio[7302]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 10 16:18:34 volumio volumio[7302]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 10 16:18:34 volumio volumio[7302]: info: [1770715114338] CoreMusicLibrary::Adding element Last_100 Feb 10 16:18:34 volumio volumio[7302]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 10 16:18:34 volumio volumio[7302]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 10 16:18:34 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 10 16:18:34 volumio volumio[7302]: info: [1770715114357] CoreMusicLibrary::Adding element Webradio Feb 10 16:18:34 volumio volumio[7302]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 10 16:18:34 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 10 16:18:34 volumio volumio[7302]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 10 16:18:34 volumio volumio[7302]: info: Initializing BBC Radios Feb 10 16:18:34 volumio volumio[7302]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 10 16:18:34 volumio volumio[7302]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 16:18:34 volumio volumio[7302]: info: Creating Spotify config file Feb 10 16:18:34 volumio volumio[7302]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 16:18:34 volumio sudo[7506]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 10 16:18:34 volumio sudo[7506]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 10 16:18:34 volumio sudo[7506]: pam_unix(sudo:session): session closed for user root Feb 10 16:18:35 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 66. Feb 10 16:18:35 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 16:18:35 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 16:18:35 volumio go-librespot[7522]: go-librespot daemon starting... Feb 10 16:18:35 volumio go-librespot[7523]: time="2026-02-10T16:18:35+07:00" level=info msg="running go-librespot 0.4.0" Feb 10 16:18:35 volumio volumio[7302]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 10 16:18:35 volumio volumio[7302]: info: [1770715115635] CoreMusicLibrary::Adding element YouTube Music Feb 10 16:18:35 volumio volumio[7302]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 10 16:18:35 volumio volumio[7302]: Cannot find translation for source YouTube Music Feb 10 16:18:35 volumio volumio[7302]: info: Volumio Calling Home Feb 10 16:18:35 volumio sudo[7532]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Feb 10 16:18:35 volumio sudo[7532]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 16:18:36 volumio go-librespot[7523]: time="2026-02-10T16:18:36+07:00" level=info msg="zeroconf server listening on port 36861" Feb 10 16:18:36 volumio sudo[7532]: pam_unix(sudo:session): session closed for user root Feb 10 16:18:36 volumio volumio[7429]: Starting albumart workers Feb 10 16:18:36 volumio volumio[7430]: Starting albumart workers Feb 10 16:18:36 volumio volumio[7425]: Starting albumart workers Feb 10 16:18:36 volumio volumio[7302]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Feb 10 16:18:36 volumio volumio[7302]: info: Discovery: Found device Volumio Feb 10 16:18:36 volumio volumio[7302]: info: CoreCommandRouter::volumioGetState Feb 10 16:18:36 volumio volumio[7302]: info: CorePlayQueue::getTrack 0 Feb 10 16:18:36 volumio volumio[7302]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Feb 10 16:18:36 volumio volumio[7302]: info: Discovery: Found device Volumio Feb 10 16:18:36 volumio volumio[7302]: info: CoreCommandRouter::volumioGetState Feb 10 16:18:36 volumio volumio[7302]: info: CorePlayQueue::getTrack 0 Feb 10 16:18:36 volumio volumio[7302]: info: MPD Permissions set Feb 10 16:18:36 volumio volumio[7302]: info: MPD Permissions set Feb 10 16:18:36 volumio volumio[7302]: info: Upmpdcli Daemon Started Feb 10 16:18:36 volumio volumio[7302]: info: Spotify config file written Feb 10 16:18:36 volumio sudo[7538]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 10 16:18:36 volumio sudo[7538]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 16:18:36 volumio volumio[7302]: 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 10 16:18:36 volumio volumio[7302]: info: Volumio called home Feb 10 16:18:36 volumio volumio[7302]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 16:18:36 volumio volumio[7302]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 16:18:36 volumio volumio[7302]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 16:18:36 volumio volumio[7302]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 16:18:36 volumio volumio[7302]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 16:18:36 volumio volumio[7302]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 16:18:36 volumio volumio[7302]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 16:18:36 volumio volumio[7302]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 16:18:36 volumio volumio[7302]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 16:18:36 volumio volumio[7302]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 16:18:36 volumio volumio[7302]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 16:18:37 volumio volumio[7302]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 16:18:37 volumio volumio[7302]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 16:18:37 volumio volumio[7302]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 16:18:37 volumio volumio[7302]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 16:18:37 volumio volumio[7302]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 16:18:37 volumio volumio[7302]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 16:18:37 volumio volumio[7302]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 16:18:37 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Feb 10 16:18:37 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Feb 10 16:18:37 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 16:18:37 volumio volumio[7302]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 16:18:37 volumio volumio[7302]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 16:18:37 volumio volumio[7302]: info: No need to fix Spotify hosts Feb 10 16:18:37 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 16:18:37 volumio go-librespot[7550]: go-librespot daemon starting... Feb 10 16:18:37 volumio sudo[7538]: pam_unix(sudo:session): session closed for user root Feb 10 16:18:37 volumio go-librespot[7551]: time="2026-02-10T16:18:37+07:00" level=info msg="running go-librespot 0.4.0" Feb 10 16:18:37 volumio go-librespot[7551]: time="2026-02-10T16:18:37+07:00" level=debug msg="app state loaded" Feb 10 16:18:37 volumio go-librespot[7551]: time="2026-02-10T16:18:37+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 16:18:37 volumio go-librespot[7551]: time="2026-02-10T16:18:37+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 10 16:18:37 volumio go-librespot[7551]: time="2026-02-10T16:18:37+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 10 16:18:37 volumio go-librespot[7551]: time="2026-02-10T16:18:37+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 10 16:18:37 volumio go-librespot[7551]: time="2026-02-10T16:18:37+07:00" level=info msg="zeroconf server listening on port 45013" Feb 10 16:18:38 volumio go-librespot[7551]: time="2026-02-10T16:18:38+07:00" level=debug msg="obtained new client token: AAAIRlXq2Vqr0N2CCf1PcnPgvuArzrff6rBQEn487od8FIAdhgpcVX/X/FPW1/u5x4CgWECsn1AoS5KFp45ODhi05/cacmiy9AowLRv3pjgUnMkL4JFC9xrCjDE++WVVQUhBPu38uW5jOHH3yB0c7K9lgKURakgICtUHvBXNtLoekDuViXsDvrfHM+KUQkaPS7pyT6x+Lhfb5U+sxAe1HhJxvcIXY1/Trh3A/Fexf3peUtEs1yX1hLE=" Feb 10 16:18:38 volumio go-librespot[7551]: time="2026-02-10T16:18:38+07:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:4070, retrying with a different AP" error="dial tcp 104.199.241.202:4070: connect: connection refused" Feb 10 16:18:38 volumio go-librespot[7551]: time="2026-02-10T16:18:38+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Feb 10 16:18:38 volumio go-librespot[7551]: time="2026-02-10T16:18:38+07:00" level=debug msg="completed keyexchange" Feb 10 16:18:38 volumio go-librespot[7551]: time="2026-02-10T16:18:38+07:00" level=debug msg="completed challenge" Feb 10 16:18:38 volumio go-librespot[7551]: time="2026-02-10T16:18:38+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 10 16:18:38 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 16:18:38 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 16:18:38 volumio volumio[7302]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 10 16:18:38 volumio volumio[7302]: SPOTIFY: BQAzwgmDfgPLjdfKUqyCbsh4LgZRoA0J8XUn4NiCLRj71tDmXSH_FDSl8osctZ7ExHdDxHvG3ul7din_i4DSrInsu_tBxMlH24JCiqFWweQY7WZzfiGoK1HKgHqa0z7LndYQbJPI8g9Y9KXQokQy2P_bDT9ezU5_r18DE9s2wkudHcW9u2dPBoVs8dY_PrfKbCfNcqHZLbwrCSL_mTXiI1aw1ul09-Q6A7mibxM16HMjmEnwLx-HTI9R0F5hDB-k5vGTixdTl_sSmpoo2gji6tvb21-THKGNF03IGript8-6KTmzFU8aenve Feb 10 16:18:38 volumio volumio[7302]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 10 16:18:38 volumio volumio[7302]: info: New Spotify access token = BQAzwgmDfgPLjdfKUqyCbsh4LgZRoA0J8XUn4NiCLRj71tDmXSH_FDSl8osctZ7ExHdDxHvG3ul7din_i4DSrInsu_tBxMlH24JCiqFWweQY7WZzfiGoK1HKgHqa0z7LndYQbJPI8g9Y9KXQokQy2P_bDT9ezU5_r18DE9s2wkudHcW9u2dPBoVs8dY_PrfKbCfNcqHZLbwrCSL_mTXiI1aw1ul09-Q6A7mibxM16HMjmEnwLx-HTI9R0F5hDB-k5vGTixdTl_sSmpoo2gji6tvb21-THKGNF03IGript8-6KTmzFU8aenve Feb 10 16:18:38 volumio volumio[7302]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 10 16:18:38 volumio volumio[7302]: info: Starting Shairport Sync Feb 10 16:18:38 volumio volumio[7302]: info: Starting Shairport Sync Feb 10 16:18:38 volumio volumio[7302]: info: Starting Shairport Sync Feb 10 16:18:38 volumio sudo[7578]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 10 16:18:38 volumio sudo[7578]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 16:18:38 volumio sudo[7582]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 10 16:18:38 volumio sudo[7582]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 16:18:38 volumio sudo[7580]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 10 16:18:38 volumio sudo[7580]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 16:18:39 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 10 16:18:39 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 10 16:18:39 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 10 16:18:39 volumio systemd[1]: shairport-sync.service: Consumed 2.296s CPU time. Feb 10 16:18:39 volumio volumio[7302]: info: CoreCommandRouter::volumioGetState Feb 10 16:18:39 volumio volumio[7302]: info: CorePlayQueue::getTrack 0 Feb 10 16:18:39 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 10 16:18:39 volumio sudo[7582]: pam_unix(sudo:session): session closed for user root Feb 10 16:18:39 volumio sudo[7578]: pam_unix(sudo:session): session closed for user root Feb 10 16:18:39 volumio sudo[7580]: pam_unix(sudo:session): session closed for user root Feb 10 16:18:39 volumio volumio[7302]: info: Shairport-Sync Started Feb 10 16:18:39 volumio volumio[7302]: Error adding Membership: Error: addMembership EINVAL Feb 10 16:18:39 volumio volumio[7302]: info: Shairport-Sync Started Feb 10 16:18:39 volumio volumio[7302]: info: Shairport-Sync Started Feb 10 16:18:39 volumio volumio[7302]: 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 10 16:18:39 volumio volumio[7302]: info: Spotify Successfully logged in Feb 10 16:18:39 volumio volumio[7302]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 10 16:18:39 volumio volumio[7302]: info: [1770715119510] CoreMusicLibrary::Adding element Spotify Feb 10 16:18:39 volumio volumio[7302]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 10 16:18:39 volumio volumio[7302]: Cannot find translation for source YouTube Music Feb 10 16:18:39 volumio volumio[7302]: Cannot find translation for source Spotify Feb 10 16:18:40 volumio volumio[7302]: info: [yt-cast-receiver] DIAL server listening on port 8098 Feb 10 16:18:40 volumio volumio[7302]: info: CoreCommandRouter::volumioRetrievevolume Feb 10 16:18:40 volumio volumio[7302]: info: VolumeController:: Volume=100 Mute =false Feb 10 16:18:40 volumio volumio[7302]: info: CoreCommandRouter::volumioGetState Feb 10 16:18:40 volumio volumio[7302]: info: CorePlayQueue::getTrack 0 Feb 10 16:18:40 volumio volumio[7302]: info: CoreStateMachine::pushState Feb 10 16:18:40 volumio volumio[7302]: info: CorePlayQueue::getTrack 0 Feb 10 16:18:40 volumio volumio[7302]: info: CoreCommandRouter::volumioPushState Feb 10 16:18:41 volumio volumio[7302]: info: go-librespot daemon successfully initialized Feb 10 16:18:41 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Feb 10 16:18:41 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 16:18:41 volumio mpd[7521]: 2026-02-10T16:18:41 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 10 16:18:41 volumio go-librespot[7618]: go-librespot daemon starting... Feb 10 16:18:41 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 16:18:41 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 10 16:18:41 volumio sudo[7482]: pam_unix(sudo:session): session closed for user root Feb 10 16:18:41 volumio sudo[7492]: pam_unix(sudo:session): session closed for user root Feb 10 16:18:41 volumio go-librespot[7621]: time="2026-02-10T16:18:41+07:00" level=info msg="running go-librespot 0.4.0" Feb 10 16:18:41 volumio go-librespot[7621]: time="2026-02-10T16:18:41+07:00" level=debug msg="app state loaded" Feb 10 16:18:41 volumio go-librespot[7621]: time="2026-02-10T16:18:41+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 16:18:42 volumio volumio[7302]: error: MPD error: The expression evaluated to a falsy value: Feb 10 16:18:42 volumio volumio[7302]: assert.ok(self.idling) Feb 10 16:18:42 volumio volumio[7302]: error: The expression evaluated to a falsy value: Feb 10 16:18:42 volumio volumio[7302]: assert.ok(self.idling) Feb 10 16:18:42 volumio volumio[7302]: error: updateQueue error: null Feb 10 16:18:42 volumio volumio[7302]: info: MPD running with PID7521 Feb 10 16:18:42 volumio volumio[7302]: ,establishing connection Feb 10 16:18:42 volumio volumio[7302]: info: Completed starting Core Plugins Feb 10 16:18:42 volumio volumio[7302]: info: ------------------------------------------- Feb 10 16:18:42 volumio volumio[7302]: info: ----- MyVolumio plugins startup ---- Feb 10 16:18:42 volumio volumio[7302]: info: ------------------------------------------- Feb 10 16:18:42 volumio volumio[7302]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 10 16:18:42 volumio volumio[7302]: error: updateQueue error: null Feb 10 16:18:42 volumio go-librespot[7621]: time="2026-02-10T16:18:42+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 10 16:18:42 volumio go-librespot[7621]: time="2026-02-10T16:18:42+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 10 16:18:42 volumio go-librespot[7621]: time="2026-02-10T16:18:42+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 10 16:18:42 volumio go-librespot[7621]: time="2026-02-10T16:18:42+07:00" level=info msg="zeroconf server listening on port 41779" Feb 10 16:18:42 volumio go-librespot[7621]: time="2026-02-10T16:18:42+07:00" level=debug msg="obtained new client token: AABfU0/nisSDNRDEl78Q2Be/jDJNl29Ngai8XyCy/MH5cDjv4ByhwYz5I39SQ3ZHrEd7PEgGWwY8kun/SzD5RnodLsVCgTZeGwUPYRgAqocvZX5U1EvQ56xr/tneD+qMdDdNLzZZt2PGfBQB4O9q7zI+cFOSDGdbzDGLXxoYE3rDpw+ffK4b5G6wFIjgsodmNx8Q5HafaNJewUmICBIgNSVsvzKqt15qKD7Aja4NTyBvdyRo4OcKjO/mNw==" Feb 10 16:18:42 volumio go-librespot[7621]: time="2026-02-10T16:18:42+07:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:4070, retrying with a different AP" error="dial tcp 104.199.241.202:4070: connect: connection refused" Feb 10 16:18:42 volumio go-librespot[7621]: time="2026-02-10T16:18:42+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Feb 10 16:18:42 volumio go-librespot[7621]: time="2026-02-10T16:18:42+07:00" level=debug msg="completed keyexchange" Feb 10 16:18:42 volumio go-librespot[7621]: time="2026-02-10T16:18:42+07:00" level=debug msg="completed challenge" Feb 10 16:18:43 volumio go-librespot[7621]: time="2026-02-10T16:18:43+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 10 16:18:43 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 16:18:43 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 16:18:44 volumio volumio[7302]: info: Initializing connection to go-librespot Websocket Feb 10 16:18:44 volumio volumio[7302]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 10 16:18:46 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Feb 10 16:18:46 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 16:18:46 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 16:18:46 volumio go-librespot[7631]: go-librespot daemon starting... Feb 10 16:18:46 volumio go-librespot[7632]: time="2026-02-10T16:18:46+07:00" level=info msg="running go-librespot 0.4.0" Feb 10 16:18:46 volumio go-librespot[7632]: time="2026-02-10T16:18:46+07:00" level=debug msg="app state loaded" Feb 10 16:18:46 volumio go-librespot[7632]: time="2026-02-10T16:18:46+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 16:18:46 volumio go-librespot[7632]: time="2026-02-10T16:18:46+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 10 16:18:46 volumio go-librespot[7632]: time="2026-02-10T16:18:46+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 10 16:18:46 volumio go-librespot[7632]: time="2026-02-10T16:18:46+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 10 16:18:46 volumio go-librespot[7632]: time="2026-02-10T16:18:46+07:00" level=info msg="zeroconf server listening on port 43925" Feb 10 16:18:46 volumio volumio[7302]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 10 16:18:47 volumio go-librespot[7632]: time="2026-02-10T16:18:47+07:00" level=debug msg="obtained new client token: AACbKqOA0jdHoBZb2lVMpSp/OIDQSC0RXHQeAT7WRvM3hl8k/fCp7+BK4s6xN5vtH/Ifw604HCyHSTsTl6uQg11DAx7XK3iiOO1WgrNsn/X0Kce7meBTyZiQ5bxOaSyfYGqka8JceCLw1hgbOHoW/iOXe5ityUaVa570Hv8OJY8eKgNu2nE35xUHYwz3AiYLB37ChLJhZBVxw88c5rL+IvwmIwjpVFUE1tTz6wMAx6/CwhBnBPVefuc=" Feb 10 16:18:47 volumio go-librespot[7632]: time="2026-02-10T16:18:47+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 10 16:18:47 volumio go-librespot[7632]: time="2026-02-10T16:18:47+07:00" level=debug msg="completed keyexchange" Feb 10 16:18:47 volumio go-librespot[7632]: time="2026-02-10T16:18:47+07:00" level=debug msg="completed challenge" Feb 10 16:18:47 volumio volumio[7302]: info: Initializing connection to go-librespot Websocket Feb 10 16:18:47 volumio go-librespot[7632]: time="2026-02-10T16:18:47+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 10 16:18:47 volumio volumio[7302]: info: Error connecting to go-librespot Websocket: Error: socket hang up Feb 10 16:18:47 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 16:18:47 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 16:18:50 volumio volumio[7302]: info: Initializing connection to go-librespot Websocket Feb 10 16:18:50 volumio volumio[7302]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 10 16:18:50 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Feb 10 16:18:50 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 16:18:50 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 16:18:50 volumio go-librespot[7639]: go-librespot daemon starting... Feb 10 16:18:50 volumio go-librespot[7640]: time="2026-02-10T16:18:50+07:00" level=info msg="running go-librespot 0.4.0" Feb 10 16:18:50 volumio go-librespot[7640]: time="2026-02-10T16:18:50+07:00" level=debug msg="app state loaded" Feb 10 16:18:50 volumio go-librespot[7640]: time="2026-02-10T16:18:50+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 16:18:51 volumio volumio[7302]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 10 16:18:51 volumio volumio[7302]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 10 16:18:51 volumio volumio[7302]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 10 16:18:51 volumio volumio[7302]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 10 16:18:51 volumio volumio[7302]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 10 16:18:51 volumio volumio[7302]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 10 16:18:51 volumio volumio[7302]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 10 16:18:51 volumio volumio[7302]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 10 16:18:51 volumio volumio[7302]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 10 16:18:51 volumio volumio[7302]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 10 16:18:51 volumio volumio[7302]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 10 16:18:51 volumio volumio[7302]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 10 16:18:51 volumio volumio[7302]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 10 16:18:51 volumio volumio[7302]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 10 16:18:51 volumio volumio[7302]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 10 16:18:51 volumio volumio[7302]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 10 16:18:51 volumio volumio[7302]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 10 16:18:51 volumio volumio[7302]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 10 16:18:51 volumio volumio[7302]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 10 16:18:51 volumio volumio[7302]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 10 16:18:51 volumio volumio[7302]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 10 16:18:51 volumio volumio[7302]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 10 16:18:51 volumio volumio[7302]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 10 16:18:51 volumio volumio[7302]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 10 16:18:51 volumio volumio[7302]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 10 16:18:51 volumio volumio[7302]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 10 16:18:51 volumio volumio[7302]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 10 16:18:51 volumio volumio[7302]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 10 16:18:51 volumio volumio[7302]: info: Adding plugin bluetooth to MyMusic Plugins Feb 10 16:18:51 volumio volumio[7302]: info: Adding plugin multiroom to MyMusic Plugins Feb 10 16:18:51 volumio volumio[7302]: info: Adding plugin metavolumio to MyMusic Plugins Feb 10 16:18:51 volumio go-librespot[7640]: time="2026-02-10T16:18: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 10 16:18:51 volumio go-librespot[7640]: time="2026-02-10T16:18: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 10 16:18:51 volumio go-librespot[7640]: time="2026-02-10T16:18: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 10 16:18:51 volumio volumio[7302]: info: Adding plugin cd_controller to MyMusic Plugins Feb 10 16:18:51 volumio volumio[7302]: info: Adding plugin qobuzconnect to MyMusic Plugins Feb 10 16:18:51 volumio volumio[7302]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 10 16:18:51 volumio volumio[7302]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 10 16:18:51 volumio volumio[7302]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 10 16:18:51 volumio go-librespot[7640]: time="2026-02-10T16:18:51+07:00" level=info msg="zeroconf server listening on port 34359" Feb 10 16:18:51 volumio go-librespot[7640]: time="2026-02-10T16:18:51+07:00" level=debug msg="obtained new client token: AAC1/loK4n4XyY0+7lgvtZcCYMxHk85cos1yUtdemebaUBC8x7kwN9pizXQNkx6a/hLtInuosJ3moRa+MTZMRtjHgIDuqJfhZFdNG4tVWtsts3lrnHn8CQJ8ECn23MIMUzxAGamvEnAY3Fh8gNEowvlT6+0vn+xe/ut4rTFqPVUglJzINXu6LEgoiT6XL8agljjvoI/tbBjizzJni0zyDT3ABgqx40xRE5/73hxT8wXT+7CgWf1ms33mfw==" Feb 10 16:18:51 volumio go-librespot[7640]: time="2026-02-10T16:18:51+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 10 16:18:51 volumio go-librespot[7640]: time="2026-02-10T16:18:51+07:00" level=debug msg="completed keyexchange" Feb 10 16:18:51 volumio go-librespot[7640]: time="2026-02-10T16:18:51+07:00" level=debug msg="completed challenge" Feb 10 16:18:51 volumio go-librespot[7640]: time="2026-02-10T16:18: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 10 16:18:51 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 16:18:51 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 16:18:52 volumio volumio[7302]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 10 16:18:52 volumio volumio[7302]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 10 16:18:52 volumio volumio[7302]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 16:18:52 volumio volumio[7302]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 16:18:52 volumio volumio[7302]: info: Starting MyVolumio Remote Streaming Endpoints Feb 10 16:18:52 volumio volumio[7302]: info: MyVolumio login type: Token Feb 10 16:18:53 volumio volumio[7302]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 10 16:18:53 volumio volumio[7302]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 10 16:18:54 volumio volumio[7302]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 10 16:18:54 volumio volumio[7302]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 10 16:18:54 volumio volumio[7302]: info: Streaming services startup Feb 10 16:18:54 volumio volumio[7302]: info: Starting Streaming Daemon Feb 10 16:18:54 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Feb 10 16:18:54 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 16:18:54 volumio sudo[7662]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 10 16:18:54 volumio sudo[7662]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 16:18:54 volumio volumio[7302]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 10 16:18:54 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 16:18:54 volumio go-librespot[7667]: go-librespot daemon starting... Feb 10 16:18:54 volumio sudo[7662]: pam_unix(sudo:session): session closed for user root Feb 10 16:18:54 volumio go-librespot[7669]: time="2026-02-10T16:18:54+07:00" level=info msg="running go-librespot 0.4.0" Feb 10 16:18:54 volumio go-librespot[7669]: time="2026-02-10T16:18:54+07:00" level=debug msg="app state loaded" Feb 10 16:18:54 volumio go-librespot[7669]: time="2026-02-10T16:18:54+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 16:18:54 volumio volumio[7302]: info: Initializing connection to go-librespot Websocket Feb 10 16:18:54 volumio volumio[7302]: error: Cannot start Volumio Streaming Daemon Feb 10 16:18:54 volumio volumio[7302]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 10 16:18:54 volumio volumio[7302]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 10 16:18:55 volumio go-librespot[7669]: time="2026-02-10T16:18:55+07:00" level=debug msg="new websocket client" Feb 10 16:18:55 volumio volumio[7302]: info: Connection to go-librespot Websocket established Feb 10 16:18:55 volumio go-librespot[7669]: time="2026-02-10T16:18: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 10 16:18:55 volumio go-librespot[7669]: time="2026-02-10T16:18:55+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 10 16:18:55 volumio go-librespot[7669]: time="2026-02-10T16:18:55+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 10 16:18:55 volumio go-librespot[7669]: time="2026-02-10T16:18:55+07:00" level=info msg="zeroconf server listening on port 33325" Feb 10 16:18:55 volumio go-librespot[7669]: time="2026-02-10T16:18:55+07:00" level=debug msg="obtained new client token: AABKSibiR4OXlPYncOeHU7CbpUqB5EsTW5Mi6uAvfXgbfmA3L8HwqSYGG3zRwC6CFm2SXVdoWNLvKIyOMUS0y2tkC0Fd3QvXkgzibk2/twAc3cycz+zzQxv406h7R7tP5DrcYejBjFDnLJtGQZP32IISapsPp6GVzS/rN+2tQHndDmfvuDERO8dKGB2PMRj7JUw8Oq3AiEA75Gi+/mkIs2FfJxNCVSAfsepAmfCSuR5GaaAJMv+npQWmsg==" Feb 10 16:18:55 volumio go-librespot[7669]: time="2026-02-10T16:18:55+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 10 16:18:55 volumio go-librespot[7669]: time="2026-02-10T16:18:55+07:00" level=debug msg="completed keyexchange" Feb 10 16:18:55 volumio go-librespot[7669]: time="2026-02-10T16:18:55+07:00" level=debug msg="completed challenge" Feb 10 16:18:55 volumio go-librespot[7669]: time="2026-02-10T16:18:55+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 10 16:18:55 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 16:18:55 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 16:18:55 volumio volumio[7302]: info: Connection to go-librespot Websocket closed Feb 10 16:18:56 volumio volumio[7302]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Feb 10 16:18:57 volumio volumio[7302]: info: MyVolumio token set successfully Feb 10 16:18:57 volumio volumio[7302]: info: MYVOLUMIO: Adding device Feb 10 16:18:57 volumio volumio[7302]: info: MYVOLUMIO: Evaluating Server Feb 10 16:18:57 volumio volumio[7302]: info: MyVolumio status changed Feb 10 16:18:57 volumio volumio[7302]: info: Streaming services startup Feb 10 16:18:57 volumio volumio[7302]: info: Starting Streaming Daemon Feb 10 16:18:57 volumio volumio[7302]: info: Removing browser output: myVolumio user plan is not superstar Feb 10 16:18:57 volumio volumio[7302]: info: Removing audio output: Feb 10 16:18:57 volumio volumio[7302]: info: Stoppping Tunnel 1 Feb 10 16:18:57 volumio sudo[7698]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 10 16:18:57 volumio sudo[7698]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 16:18:57 volumio sudo[7698]: pam_unix(sudo:session): session closed for user root Feb 10 16:18:57 volumio sudo[7701]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Feb 10 16:18:57 volumio sudo[7701]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 16:18:57 volumio volumio[7302]: error: Cannot start Volumio Streaming Daemon Feb 10 16:18:57 volumio volumio[7302]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 10 16:18:57 volumio volumio[7302]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 10 16:18:57 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 10 16:18:57 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 10 16:18:57 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 10 16:18:57 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 10 16:18:57 volumio volumio[7302]: info: Setting Geolocation for MyVolumio to as1 Feb 10 16:18:57 volumio volumio[7302]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 16:18:57 volumio volumio[7302]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 16:18:57 volumio volumio[7302]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 16:18:57 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 10 16:18:57 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 10 16:18:57 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 10 16:18:57 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 10 16:18:57 volumio sudo[7701]: pam_unix(sudo:session): session closed for user root Feb 10 16:18:57 volumio volumio[7302]: info: Remote SSH Stopped Feb 10 16:18:58 volumio volumio[7302]: info: Getting Spotify volume Feb 10 16:18:58 volumio volumio[7302]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 10 16:18:58 volumio volumio[7302]: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 10 16:18:58 volumio volumio[7302]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Feb 10 16:18:58 volumio volumio[7302]: errno: -111, Feb 10 16:18:58 volumio volumio[7302]: code: 'ECONNREFUSED', Feb 10 16:18:58 volumio volumio[7302]: syscall: 'connect', Feb 10 16:18:58 volumio volumio[7302]: address: '127.0.0.1', Feb 10 16:18:58 volumio volumio[7302]: port: 9879, Feb 10 16:18:58 volumio volumio[7302]: response: undefined Feb 10 16:18:58 volumio volumio[7302]: } Feb 10 16:18:58 volumio volumio[7302]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 10 16:18:59 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Feb 10 16:18:59 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 16:18:59 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 16:18:59 volumio go-librespot[7715]: go-librespot daemon starting... Feb 10 16:18:59 volumio go-librespot[7716]: time="2026-02-10T16:18:59+07:00" level=info msg="running go-librespot 0.4.0" Feb 10 16:18:59 volumio go-librespot[7716]: time="2026-02-10T16:18:59+07:00" level=debug msg="app state loaded" Feb 10 16:18:59 volumio go-librespot[7716]: time="2026-02-10T16:18:59+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 16:18:59 volumio sudo[7725]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-10 16:17' Feb 10 16:18:59 volumio sudo[7725]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 16:18:59 volumio go-librespot[7716]: time="2026-02-10T16:18:59+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 10 16:18:59 volumio go-librespot[7716]: time="2026-02-10T16:18:59+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 10 16:18:59 volumio go-librespot[7716]: time="2026-02-10T16:18:59+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 10 16:18:59 volumio go-librespot[7716]: time="2026-02-10T16:18:59+07:00" level=info msg="zeroconf server listening on port 37615" 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"