Feb 10 13:19:00 volumio sudo[22568]: pam_unix(sudo:session): session closed for user root Feb 10 13:19:01 volumio volumio[22517]: info: Starting UPNP Browser Feb 10 13:19:01 volumio volumio[22517]: info: Loading plugin "alarm-clock"... Feb 10 13:19:02 volumio volumio[22517]: info: Loading plugin "airplay_emulation"... Feb 10 13:19:02 volumio volumio[22517]: info: Starting Shairport Sync Feb 10 13:19:02 volumio volumio[22517]: info: Loading plugin "last_100"... Feb 10 13:19:02 volumio volumio[22517]: info: Loading plugin "webradio"... Feb 10 13:19:02 volumio volumio[22517]: info: Loading plugin "i2s_dacs"... Feb 10 13:19:02 volumio volumio[22517]: info: Loading plugin "volumiodiscovery"... Feb 10 13:19:02 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Feb 10 13:19:02 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 13:19:02 volumio volumio[22517]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 10 13:19:02 volumio volumio[22517]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 10 13:19:02 volumio volumio[22517]: *** WARNING *** For more information see Feb 10 13:19:02 volumio volumio[22517]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 10 13:19:02 volumio volumio[22517]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 10 13:19:02 volumio volumio[22517]: *** WARNING *** For more information see Feb 10 13:19:02 volumio node[22517]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 10 13:19:02 volumio node[22517]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 10 13:19:02 volumio node[22517]: *** WARNING *** For more information see Feb 10 13:19:02 volumio node[22517]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 10 13:19:02 volumio node[22517]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 10 13:19:02 volumio node[22517]: *** WARNING *** For more information see Feb 10 13:19:02 volumio volumio[22517]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 10 13:19:02 volumio volumio[22517]: info: Discovery: Started advertising with name: Volumio Feb 10 13:19:02 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 13:19:02 volumio go-librespot[22596]: go-librespot daemon starting... Feb 10 13:19:02 volumio go-librespot[22598]: time="2026-02-10T13:19:02+07:00" level=info msg="running go-librespot 0.4.0" Feb 10 13:19:02 volumio go-librespot[22598]: time="2026-02-10T13:19:02+07:00" level=debug msg="app state loaded" Feb 10 13:19:02 volumio go-librespot[22598]: time="2026-02-10T13:19:02+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 13:19:02 volumio volumio[22517]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 10 13:19:02 volumio volumio[22517]: info: Loading plugin "spop"... Feb 10 13:19:02 volumio go-librespot[22598]: time="2026-02-10T13:19:02+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 10 13:19:02 volumio go-librespot[22598]: time="2026-02-10T13:19:02+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 13:19:02 volumio go-librespot[22598]: time="2026-02-10T13:19:02+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 13:19:02 volumio go-librespot[22598]: time="2026-02-10T13:19:02+07:00" level=info msg="zeroconf server listening on port 35431" Feb 10 13:19:03 volumio go-librespot[22598]: time="2026-02-10T13:19:03+07:00" level=debug msg="obtained new client token: AACzNDYbt+LypArgOB+fapJCl6POAapub4Df8ypjQRBdtThgYy+VTfFDXC7zagok1COzYj4950sU1QwUxauj9k5ZhZmjFmkWedoUnLXFYerSj8GbE1jt+xSQR882Mu1/K+iC23uryWmpfoolO/tMqxCdZJYCxBFir45CJ+HM/GpBT6UBQEKIpr5rqWCe+cokTtdx0ipuy3MYCnel431HWHwiQkv6eidcS4/ENXn6hdSVyDSi+N47Dgw=" Feb 10 13:19:03 volumio go-librespot[22598]: time="2026-02-10T13:19:03+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 10 13:19:03 volumio go-librespot[22598]: time="2026-02-10T13:19:03+07:00" level=debug msg="completed keyexchange" Feb 10 13:19:03 volumio go-librespot[22598]: time="2026-02-10T13:19:03+07:00" level=debug msg="completed challenge" Feb 10 13:19:03 volumio go-librespot[22598]: time="2026-02-10T13:19:03+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 10 13:19:03 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 13:19:03 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 13:19:04 volumio volumio[22517]: info: Loading plugin "ytcr"... Feb 10 13:19:06 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 11. Feb 10 13:19:06 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 13:19:06 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 13:19:06 volumio go-librespot[22608]: go-librespot daemon starting... Feb 10 13:19:06 volumio go-librespot[22609]: time="2026-02-10T13:19:06+07:00" level=info msg="running go-librespot 0.4.0" Feb 10 13:19:06 volumio go-librespot[22609]: time="2026-02-10T13:19:06+07:00" level=debug msg="app state loaded" Feb 10 13:19:06 volumio go-librespot[22609]: time="2026-02-10T13:19:06+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 13:19:07 volumio volumio[22517]: info: Loading plugin "ytmusic"... Feb 10 13:19:07 volumio go-librespot[22609]: time="2026-02-10T13:19:07+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 10 13:19:07 volumio go-librespot[22609]: time="2026-02-10T13:19:07+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 13:19:07 volumio go-librespot[22609]: time="2026-02-10T13:19:07+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 13:19:07 volumio go-librespot[22609]: time="2026-02-10T13:19:07+07:00" level=info msg="zeroconf server listening on port 37853" Feb 10 13:19:07 volumio go-librespot[22609]: time="2026-02-10T13:19:07+07:00" level=debug msg="obtained new client token: AACggwBCvJbiSG3Q5pweJ2UzqPxH/UtlkuVrslje4kRGMVVst6+c48bGZ1fV+b1CzbAzZVfsel9TOvijWjus56PjN0sjNLhPh2yKCwNnCcQP6NyAQ2C1Gjmq30TPWXMr3LhRHMpY/Qs+kLCapratwmzES3iuqgH0RxY022efz0CX1G901TYdfSKoE60HoNrcSxkG5EDz0fdAkmwq5MfiAb0WmxAgY9mACgMm4Dqx6hBo/kvYEZ3O/+fTZQ==" Feb 10 13:19:07 volumio go-librespot[22609]: time="2026-02-10T13:19:07+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 10 13:19:07 volumio go-librespot[22609]: time="2026-02-10T13:19:07+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 10 13:19:07 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 13:19:07 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 13:19:07 volumio volumio-remote-updater[643]: [2026-02-10 13:19:07] [connect] Successful connection Feb 10 13:19:08 volumio volumio[22517]: info: Loading plugin "outputs"... Feb 10 13:19:08 volumio volumio[22517]: info: Loading plugin "albumart"... Feb 10 13:19:08 volumio volumio[22517]: info: Plugin example_plugin is not enabled Feb 10 13:19:08 volumio volumio[22517]: info: Loading plugin "inputs"... Feb 10 13:19:08 volumio volumio[22517]: info: Loading plugin "updater_comm"... Feb 10 13:19:08 volumio volumio[22517]: info: Plugin mpdemulation is not enabled Feb 10 13:19:08 volumio volumio[22517]: info: Loading plugin "rest_api"... Feb 10 13:19:08 volumio volumio[22517]: info: Loading plugin "websocket"... Feb 10 13:19:08 volumio volumio[22517]: info: Starting Socket.io Server version 1.7.4 Feb 10 13:19:08 volumio volumio[22517]: info: Loading plugin "RoonBridge"... Feb 10 13:19:08 volumio volumio[22517]: info: Applying required configuration parameters for plugin RoonBridge Feb 10 13:19:09 volumio volumio[22517]: info: Loading i18n strings for locale en Feb 10 13:19:09 volumio volumio[22517]: Updating browse sources language Feb 10 13:19:09 volumio volumio[22517]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 10 13:19:09 volumio volumio[22630]: Forking 3 albumart workers Feb 10 13:19:09 volumio volumio[22517]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 10 13:19:09 volumio volumio[22517]: info: CoreCommandRouter::initPlayerControls Feb 10 13:19:09 volumio volumio[22517]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:19:09 volumio volumio[22517]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:19:09 volumio volumio[22517]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:19:09 volumio volumio[22517]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:19:09 volumio volumio[22517]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:19:09 volumio volumio[22517]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:19:09 volumio volumio[22517]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:19:09 volumio volumio[22517]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:19:09 volumio volumio[22517]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 10 13:19:09 volumio volumio[22517]: Express server listening on port 3000 Feb 10 13:19:09 volumio volumio[22517]: [Metrics] WebUI: 16s 103.05ms Feb 10 13:19:09 volumio volumio[22517]: info: CoreStateMachine::resetVolumioState Feb 10 13:19:09 volumio volumio[22517]: info: CoreStateMachine::getcurrentVolume Feb 10 13:19:09 volumio volumio[22517]: info: CoreCommandRouter::volumioRetrievevolume Feb 10 13:19:09 volumio sudo[22664]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 10 13:19:09 volumio sudo[22664]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 13:19:09 volumio sudo[22664]: pam_unix(sudo:session): session closed for user root Feb 10 13:19:09 volumio sudo[22674]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 10 13:19:09 volumio sudo[22674]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 13:19:09 volumio sudo[22674]: pam_unix(sudo:session): session closed for user root Feb 10 13:19:09 volumio volumio[22517]: info: Volumio Network Manager: Network status updated: 1 Feb 10 13:19:09 volumio volumio[22517]: info: VolumeController:: Volume=100 Mute =false Feb 10 13:19:09 volumio volumio[22517]: info: CoreStateMachine::pushState Feb 10 13:19:09 volumio volumio[22517]: info: CorePlayQueue::getTrack 0 Feb 10 13:19:09 volumio volumio[22517]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 10 13:19:09 volumio volumio[22517]: info: CoreCommandRouter::volumioPushState Feb 10 13:19:09 volumio volumio[22517]: info: CoreStateMachine::updateTrackBlock Feb 10 13:19:09 volumio volumio[22517]: info: CorePlayQueue::getTrackBlock Feb 10 13:19:09 volumio volumio[22517]: info: CoreCommandRouter::volumioRetrievevolume Feb 10 13:19:10 volumio volumio-remote-updater[643]: [2026-02-10 13:19:09] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1770704347 101 Feb 10 13:19:10 volumio volumio[22517]: 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 13:19:10 volumio volumio[22517]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 13:19:10 volumio volumio[22517]: info: Reloading queue from file Feb 10 13:19:10 volumio volumio[22517]: info: CoreStateMachine::setRepeat null single undefined Feb 10 13:19:10 volumio volumio[22517]: info: CoreStateMachine::pushState Feb 10 13:19:10 volumio volumio[22517]: info: CorePlayQueue::getTrack 0 Feb 10 13:19:10 volumio volumio[22517]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 10 13:19:10 volumio volumio[22517]: info: CoreCommandRouter::volumioPushState Feb 10 13:19:10 volumio volumio[22517]: info: CoreStateMachine::setRandom null Feb 10 13:19:10 volumio volumio[22517]: info: CoreStateMachine::pushState Feb 10 13:19:10 volumio volumio[22517]: info: CorePlayQueue::getTrack 0 Feb 10 13:19:10 volumio volumio[22517]: info: CoreCommandRouter::volumioPushState Feb 10 13:19:10 volumio volumio[22517]: info: Setting Device type: Raspberry PI Feb 10 13:19:10 volumio volumio[22517]: info: Completed loading Core Plugins Feb 10 13:19:10 volumio volumio[22517]: info: Preparing to generate the ALSA configuration file Feb 10 13:19:10 volumio volumio[22517]: info: VolumeController:: Volume=100 Mute =false Feb 10 13:19:10 volumio volumio[22517]: info: CoreStateMachine::pushState Feb 10 13:19:10 volumio volumio[22517]: info: CorePlayQueue::getTrack 0 Feb 10 13:19:10 volumio volumio[22517]: info: CoreCommandRouter::volumioPushState Feb 10 13:19:10 volumio volumio[22517]: info: Asound.conf file unchanged, so no further update is needed Feb 10 13:19:10 volumio volumio[22517]: info: Output device has changed, restarting MPD Feb 10 13:19:10 volumio sudo[22691]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 10 13:19:10 volumio sudo[22691]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 13:19:10 volumio volumio[22517]: info: Output device has changed, restarting Shairport Sync Feb 10 13:19:10 volumio volumio[22517]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:19:10 volumio sudo[22693]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 10 13:19:10 volumio volumio[22517]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 13:19:10 volumio sudo[22693]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 13:19:10 volumio sudo[22693]: pam_unix(sudo:session): session closed for user root Feb 10 13:19:10 volumio volumio[22517]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 10 13:19:10 volumio volumio[22517]: info: ___________ START PLUGINS ___________ Feb 10 13:19:10 volumio sudo[22696]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 10 13:19:10 volumio sudo[22696]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 13:19:10 volumio volumio[22517]: info: ControllerMpd::onStart: Initializing MPD Feb 10 13:19:10 volumio volumio[22517]: info: Creating MPD Configuration file Feb 10 13:19:10 volumio sudo[22691]: pam_unix(sudo:session): session closed for user root Feb 10 13:19:10 volumio volumio[22517]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 10 13:19:10 volumio volumio[22517]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 10 13:19:10 volumio volumio[22517]: info: [1770704350696] CoreMusicLibrary::Adding element Media Servers Feb 10 13:19:10 volumio volumio[22517]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 10 13:19:10 volumio sudo[22704]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 10 13:19:10 volumio sudo[22704]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 13:19:10 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 12. Feb 10 13:19:10 volumio volumio[22517]: info: UPNP Browser: Client initialized successfully Feb 10 13:19:10 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 13:19:10 volumio sudo[22704]: pam_unix(sudo:session): session closed for user root Feb 10 13:19:10 volumio sudo[22706]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 10 13:19:10 volumio sudo[22706]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 13:19:10 volumio volumio[22517]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:19:10 volumio volumio[22517]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 13:19:10 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 13:19:10 volumio go-librespot[22708]: go-librespot daemon starting... Feb 10 13:19:10 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 10 13:19:11 volumio go-librespot[22714]: time="2026-02-10T13:19:11+07:00" level=info msg="running go-librespot 0.4.0" Feb 10 13:19:11 volumio volumio[22517]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 10 13:19:11 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 10 13:19:11 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 10 13:19:11 volumio systemd[1]: mpd.service: Consumed 7.112s CPU time. Feb 10 13:19:11 volumio go-librespot[22714]: time="2026-02-10T13:19:11+07:00" level=debug msg="app state loaded" Feb 10 13:19:11 volumio volumio[22517]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:19:11 volumio volumio[22517]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 13:19:11 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 10 13:19:11 volumio go-librespot[22714]: time="2026-02-10T13:19:11+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 13:19:11 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 10 13:19:11 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 10 13:19:11 volumio volumio[22517]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 10 13:19:11 volumio volumio[22517]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 10 13:19:11 volumio volumio[22517]: info: [1770704351112] CoreMusicLibrary::Adding element Last_100 Feb 10 13:19:11 volumio volumio[22517]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 10 13:19:11 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 10 13:19:11 volumio volumio[22517]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 10 13:19:11 volumio volumio[22517]: info: [1770704351126] CoreMusicLibrary::Adding element Webradio Feb 10 13:19:11 volumio volumio[22517]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 10 13:19:11 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 10 13:19:11 volumio volumio[22517]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 10 13:19:11 volumio volumio[22517]: info: Initializing BBC Radios Feb 10 13:19:11 volumio volumio[22517]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 10 13:19:11 volumio volumio[22517]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 13:19:11 volumio volumio[22517]: info: Creating Spotify config file Feb 10 13:19:11 volumio volumio[22517]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:19:11 volumio sudo[22725]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 10 13:19:11 volumio sudo[22725]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 10 13:19:11 volumio go-librespot[22714]: time="2026-02-10T13:19:11+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 10 13:19:11 volumio go-librespot[22714]: time="2026-02-10T13:19:11+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 10 13:19:11 volumio go-librespot[22714]: time="2026-02-10T13:19:11+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 10 13:19:11 volumio sudo[22725]: pam_unix(sudo:session): session closed for user root Feb 10 13:19:11 volumio go-librespot[22714]: time="2026-02-10T13:19:11+07:00" level=info msg="zeroconf server listening on port 46721" Feb 10 13:19:11 volumio go-librespot[22714]: time="2026-02-10T13:19:11+07:00" level=debug msg="obtained new client token: AABSm6U4NNLqDNJUMJWsPn0/f2CcdpUzkvyOoJmDUwBhas6jSjdXp6XIu9q0L4uCCmwFY6oNgVHOHL65jO9EKvrEp5yOGDEzQH82CGL6q1iXxAJ6z0jpkXksJIxX8hbH2WNebn/CsdArUQbbOcZzBNpQlNM+P1NEbysHE5x1/PTCzZKa+TknuPRBUOw95deYel/cdfCkGeCXWZBXzrdOBe1gZccef0pI0+0Z2Cni6d+of8Ciu7bHJ8fvjw==" Feb 10 13:19:12 volumio go-librespot[22714]: time="2026-02-10T13:19:12+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 13:19:12 volumio go-librespot[22714]: time="2026-02-10T13:19:12+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Feb 10 13:19:12 volumio go-librespot[22714]: time="2026-02-10T13:19:12+07:00" level=debug msg="completed keyexchange" Feb 10 13:19:12 volumio go-librespot[22714]: time="2026-02-10T13:19:12+07:00" level=debug msg="completed challenge" Feb 10 13:19:12 volumio go-librespot[22714]: time="2026-02-10T13:19:12+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 10 13:19:12 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 13:19:12 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 13:19:12 volumio volumio[22641]: Starting albumart workers Feb 10 13:19:12 volumio volumio[22640]: Starting albumart workers Feb 10 13:19:12 volumio volumio[22517]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 10 13:19:12 volumio volumio[22517]: info: [1770704352922] CoreMusicLibrary::Adding element YouTube Music Feb 10 13:19:12 volumio volumio[22517]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 10 13:19:12 volumio volumio[22517]: Cannot find translation for source YouTube Music Feb 10 13:19:12 volumio volumio[22517]: info: Volumio Calling Home Feb 10 13:19:13 volumio sudo[22743]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Feb 10 13:19:13 volumio sudo[22743]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 13:19:13 volumio volumio[22642]: Starting albumart workers Feb 10 13:19:13 volumio sudo[22743]: pam_unix(sudo:session): session closed for user root Feb 10 13:19:13 volumio volumio[22517]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Feb 10 13:19:13 volumio volumio[22517]: info: Discovery: Found device Volumio Feb 10 13:19:13 volumio volumio[22517]: info: CoreCommandRouter::volumioGetState Feb 10 13:19:13 volumio volumio[22517]: info: CorePlayQueue::getTrack 0 Feb 10 13:19:13 volumio volumio[22517]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Feb 10 13:19:13 volumio volumio[22517]: info: Discovery: Found device Volumio Feb 10 13:19:13 volumio volumio[22517]: info: CoreCommandRouter::volumioGetState Feb 10 13:19:13 volumio volumio[22517]: info: CorePlayQueue::getTrack 0 Feb 10 13:19:14 volumio volumio[22517]: info: MPD Permissions set Feb 10 13:19:14 volumio volumio[22517]: info: MPD Permissions set Feb 10 13:19:14 volumio volumio[22517]: info: Upmpdcli Daemon Started Feb 10 13:19:14 volumio volumio[22517]: info: Volumio called home Feb 10 13:19:14 volumio volumio[22517]: info: Spotify config file written Feb 10 13:19:14 volumio sudo[22755]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 10 13:19:14 volumio sudo[22755]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 13:19:14 volumio volumio[22517]: 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 13:19:14 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 13:19:14 volumio volumio[22517]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:19:14 volumio volumio[22517]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:19:14 volumio volumio[22517]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:19:14 volumio volumio[22517]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:19:14 volumio volumio[22517]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:19:14 volumio volumio[22517]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:19:14 volumio volumio[22517]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:19:14 volumio volumio[22517]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:19:14 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 13:19:14 volumio go-librespot[22763]: go-librespot daemon starting... Feb 10 13:19:14 volumio sudo[22755]: pam_unix(sudo:session): session closed for user root Feb 10 13:19:14 volumio volumio[22517]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 13:19:14 volumio volumio[22517]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:19:14 volumio volumio[22517]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:19:14 volumio volumio[22517]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:19:14 volumio volumio[22517]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:19:14 volumio volumio[22517]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:19:14 volumio volumio[22517]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:19:14 volumio volumio[22517]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:19:14 volumio volumio[22517]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:19:14 volumio volumio[22517]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:19:14 volumio go-librespot[22766]: time="2026-02-10T13:19:14+07:00" level=info msg="running go-librespot 0.4.0" Feb 10 13:19:14 volumio go-librespot[22766]: time="2026-02-10T13:19:14+07:00" level=debug msg="app state loaded" Feb 10 13:19:14 volumio go-librespot[22766]: time="2026-02-10T13:19:14+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 13:19:14 volumio volumio[22517]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 13:19:14 volumio volumio[22517]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:19:14 volumio volumio[22517]: info: No need to fix Spotify hosts Feb 10 13:19:15 volumio go-librespot[22766]: time="2026-02-10T13:19:15+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 10 13:19:15 volumio go-librespot[22766]: time="2026-02-10T13:19:15+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 10 13:19:15 volumio go-librespot[22766]: time="2026-02-10T13:19:15+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 10 13:19:15 volumio go-librespot[22766]: time="2026-02-10T13:19:15+07:00" level=info msg="zeroconf server listening on port 43867" Feb 10 13:19:15 volumio volumio[22517]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 10 13:19:15 volumio volumio[22517]: SPOTIFY: BQBhkQSoSM-Nddm8Yo_dJUT5gEQzGRVj82aXwtSRokqQBKePSloh5XShN5xp0G1y6svF3kmRrERi-6bu41Uv-sc3yfweTf2Xwi8lsTWFTfGpnQsH-JtRgb6QZpvoVcuV-WMUDA_Ae9sMuR3RrscOJu_gQVVNxahYILTQMmE-F-FE7sJKh4Rt_aqI5PlHQaz9XcS987pxdERXHDQURqLTgWTvYFhjE85fvKuwVoXwb3D5ES1rbIYb7cA_kYxjRcvWESvJTahqyTFShHCG7q3jqtESZYy9xpKzwbqxwasiA95QMdVG27w7OUzb Feb 10 13:19:15 volumio volumio[22517]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 10 13:19:15 volumio volumio[22517]: info: New Spotify access token = BQBhkQSoSM-Nddm8Yo_dJUT5gEQzGRVj82aXwtSRokqQBKePSloh5XShN5xp0G1y6svF3kmRrERi-6bu41Uv-sc3yfweTf2Xwi8lsTWFTfGpnQsH-JtRgb6QZpvoVcuV-WMUDA_Ae9sMuR3RrscOJu_gQVVNxahYILTQMmE-F-FE7sJKh4Rt_aqI5PlHQaz9XcS987pxdERXHDQURqLTgWTvYFhjE85fvKuwVoXwb3D5ES1rbIYb7cA_kYxjRcvWESvJTahqyTFShHCG7q3jqtESZYy9xpKzwbqxwasiA95QMdVG27w7OUzb Feb 10 13:19:15 volumio volumio[22517]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 10 13:19:15 volumio go-librespot[22766]: time="2026-02-10T13:19:15+07:00" level=debug msg="obtained new client token: AADv28SSnxvc0/GbhclJfEL1taSiMj3UdpW2kaAh7ld6fR75E6eTuX1y95cJ2rUNKY1I09E7EfzNVmSLz/3+gbGyGymIu4EY4TGL3uyp++cEmuDca227tPz6UyA67qt7yzloZ266fJqSayS3P+Rlb5zzt5IYjqSkzI/iktLiF/eG69dnIHQQMi3sbSFNmxUyNNtHSQgQSPOLCF43pwjTwfjOvEE7r+X9RL5J/i9F9ABE6KjjQRm/HJJOYg==" Feb 10 13:19:15 volumio volumio[22517]: info: Starting Shairport Sync Feb 10 13:19:15 volumio volumio[22517]: info: Starting Shairport Sync Feb 10 13:19:15 volumio volumio[22517]: info: Starting Shairport Sync Feb 10 13:19:15 volumio sudo[22790]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 10 13:19:15 volumio go-librespot[22766]: time="2026-02-10T13:19:15+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 10 13:19:15 volumio sudo[22788]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 10 13:19:15 volumio sudo[22788]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 13:19:15 volumio sudo[22790]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 13:19:15 volumio sudo[22792]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 10 13:19:15 volumio sudo[22792]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 13:19:15 volumio go-librespot[22766]: time="2026-02-10T13:19:15+07:00" level=debug msg="completed keyexchange" Feb 10 13:19:15 volumio go-librespot[22766]: time="2026-02-10T13:19:15+07:00" level=debug msg="completed challenge" Feb 10 13:19:15 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 10 13:19:15 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 10 13:19:15 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 10 13:19:15 volumio systemd[1]: shairport-sync.service: Consumed 2.421s CPU time. Feb 10 13:19:15 volumio volumio[22517]: info: CoreCommandRouter::volumioGetState Feb 10 13:19:15 volumio go-librespot[22766]: time="2026-02-10T13:19:15+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 10 13:19:15 volumio volumio[22517]: info: CorePlayQueue::getTrack 0 Feb 10 13:19:16 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 10 13:19:16 volumio sudo[22788]: pam_unix(sudo:session): session closed for user root Feb 10 13:19:16 volumio sudo[22790]: pam_unix(sudo:session): session closed for user root Feb 10 13:19:16 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 13:19:16 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 13:19:16 volumio sudo[22792]: pam_unix(sudo:session): session closed for user root Feb 10 13:19:16 volumio volumio[22517]: info: Shairport-Sync Started Feb 10 13:19:16 volumio volumio[22517]: Error adding Membership: Error: addMembership EINVAL Feb 10 13:19:16 volumio volumio[22517]: info: Shairport-Sync Started Feb 10 13:19:16 volumio volumio[22517]: info: Shairport-Sync Started Feb 10 13:19:16 volumio volumio[22517]: 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 13:19:16 volumio volumio[22517]: info: Spotify Successfully logged in Feb 10 13:19:16 volumio volumio[22517]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 10 13:19:16 volumio volumio[22517]: info: [1770704356402] CoreMusicLibrary::Adding element Spotify Feb 10 13:19:16 volumio volumio[22517]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 10 13:19:16 volumio volumio[22517]: Cannot find translation for source YouTube Music Feb 10 13:19:16 volumio volumio[22517]: Cannot find translation for source Spotify Feb 10 13:19:17 volumio volumio[22517]: info: [yt-cast-receiver] DIAL server listening on port 8098 Feb 10 13:19:17 volumio volumio[22517]: info: CoreCommandRouter::volumioRetrievevolume Feb 10 13:19:17 volumio volumio[22517]: info: VolumeController:: Volume=100 Mute =false Feb 10 13:19:17 volumio volumio[22517]: info: CoreCommandRouter::volumioGetState Feb 10 13:19:17 volumio volumio[22517]: info: CorePlayQueue::getTrack 0 Feb 10 13:19:17 volumio volumio[22517]: info: CoreStateMachine::pushState Feb 10 13:19:17 volumio volumio[22517]: info: CorePlayQueue::getTrack 0 Feb 10 13:19:17 volumio volumio[22517]: info: CoreCommandRouter::volumioPushState Feb 10 13:19:18 volumio volumio[22517]: info: go-librespot daemon successfully initialized Feb 10 13:19:18 volumio mpd[22741]: 2026-02-10T13:19:18 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 10 13:19:18 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 10 13:19:18 volumio sudo[22696]: pam_unix(sudo:session): session closed for user root Feb 10 13:19:18 volumio sudo[22706]: pam_unix(sudo:session): session closed for user root Feb 10 13:19:19 volumio volumio[22517]: error: MPD error: The expression evaluated to a falsy value: Feb 10 13:19:19 volumio volumio[22517]: assert.ok(self.idling) Feb 10 13:19:19 volumio volumio[22517]: error: The expression evaluated to a falsy value: Feb 10 13:19:19 volumio volumio[22517]: assert.ok(self.idling) Feb 10 13:19:19 volumio volumio[22517]: error: updateQueue error: null Feb 10 13:19:19 volumio volumio[22517]: info: MPD running with PID22741 Feb 10 13:19:19 volumio volumio[22517]: ,establishing connection Feb 10 13:19:19 volumio volumio[22517]: info: Completed starting Core Plugins Feb 10 13:19:19 volumio volumio[22517]: info: ------------------------------------------- Feb 10 13:19:19 volumio volumio[22517]: info: ----- MyVolumio plugins startup ---- Feb 10 13:19:19 volumio volumio[22517]: info: ------------------------------------------- Feb 10 13:19:19 volumio volumio[22517]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 10 13:19:19 volumio volumio[22517]: error: updateQueue error: null Feb 10 13:19:19 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 13. Feb 10 13:19:19 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 13:19:19 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 13:19:19 volumio go-librespot[22833]: go-librespot daemon starting... Feb 10 13:19:19 volumio go-librespot[22834]: time="2026-02-10T13:19:19+07:00" level=info msg="running go-librespot 0.4.0" Feb 10 13:19:19 volumio go-librespot[22834]: time="2026-02-10T13:19:19+07:00" level=debug msg="app state loaded" Feb 10 13:19:19 volumio go-librespot[22834]: time="2026-02-10T13:19:19+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 13:19:19 volumio go-librespot[22834]: time="2026-02-10T13:19:19+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 10 13:19:19 volumio go-librespot[22834]: time="2026-02-10T13:19:19+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 10 13:19:19 volumio go-librespot[22834]: time="2026-02-10T13:19:19+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 10 13:19:19 volumio go-librespot[22834]: time="2026-02-10T13:19:19+07:00" level=info msg="zeroconf server listening on port 39075" Feb 10 13:19:20 volumio go-librespot[22834]: time="2026-02-10T13:19:20+07:00" level=debug msg="obtained new client token: AAAEuT7pXF3lBZi+D3SQSPyzE+AhoKzYsLy5LAxJ1lHIpzjfwbU1at0bbIkyC/8HiDVwVl77Z+w7DaWgaxTmVqIaUjGIXb0SX9F+KOUMs1+0XE3+7QJ/lCU4czb72J7y95JUwQQkmGwkbPTO8jyJwuzrIss8ZyV7Fv1tAEtbMCWAUuogVwUVOzsPGyd67NDWQYjwSnZWYOxy/Ox5jE1EwW2qlJszejiiuF9wAcmHbrKDM9cMcy52KX0=" Feb 10 13:19:20 volumio go-librespot[22834]: time="2026-02-10T13:19:20+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 10 13:19:20 volumio go-librespot[22834]: time="2026-02-10T13:19:20+07:00" level=debug msg="completed keyexchange" Feb 10 13:19:20 volumio go-librespot[22834]: time="2026-02-10T13:19:20+07:00" level=debug msg="completed challenge" Feb 10 13:19:20 volumio go-librespot[22834]: time="2026-02-10T13:19:20+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 10 13:19:20 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 13:19:20 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 13:19:21 volumio volumio[22517]: info: Initializing connection to go-librespot Websocket Feb 10 13:19:21 volumio volumio[22517]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 10 13:19:23 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 14. Feb 10 13:19:23 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 13:19:23 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 13:19:23 volumio go-librespot[22841]: go-librespot daemon starting... Feb 10 13:19:23 volumio go-librespot[22842]: time="2026-02-10T13:19:23+07:00" level=info msg="running go-librespot 0.4.0" Feb 10 13:19:23 volumio go-librespot[22842]: time="2026-02-10T13:19:23+07:00" level=debug msg="app state loaded" Feb 10 13:19:23 volumio go-librespot[22842]: time="2026-02-10T13:19:23+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 13:19:23 volumio volumio[22517]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 10 13:19:24 volumio go-librespot[22842]: time="2026-02-10T13:19:24+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 10 13:19:24 volumio go-librespot[22842]: time="2026-02-10T13:19:24+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 13:19:24 volumio go-librespot[22842]: time="2026-02-10T13:19:24+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 13:19:24 volumio go-librespot[22842]: time="2026-02-10T13:19:24+07:00" level=info msg="zeroconf server listening on port 41443" Feb 10 13:19:24 volumio go-librespot[22842]: time="2026-02-10T13:19:24+07:00" level=debug msg="obtained new client token: AAA/jS0wVaClXQtG7D/Y4x1drg11Ys2aNeKgARBsCB0w0bhJ66GnE90cC8JviH8DEV0/jQ4LICJ73hstgutArQuxcE221DAWOrxm1NX8aHkjLXeyi4h2oHxxj7fwafmh3UZHWl4t5WuxqvYB4ReyZwDud2NWBMkqNcSJXmSSD038lrzXQhlppDTKNJCEoO7eLIZUimqqGsRo2JuaWZ8pPFnlUXKMVDgi1KjiTi0t9pMptwGruIgeL6uzJw==" Feb 10 13:19:24 volumio go-librespot[22842]: time="2026-02-10T13:19:24+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 10 13:19:24 volumio volumio[22517]: info: Initializing connection to go-librespot Websocket Feb 10 13:19:24 volumio go-librespot[22842]: time="2026-02-10T13:19:24+07:00" level=debug msg="new websocket client" Feb 10 13:19:24 volumio volumio[22517]: info: Connection to go-librespot Websocket established Feb 10 13:19:24 volumio go-librespot[22842]: time="2026-02-10T13:19:24+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 10 13:19:24 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 13:19:24 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 13:19:24 volumio volumio[22517]: info: Connection to go-librespot Websocket closed Feb 10 13:19:27 volumio volumio[22517]: info: Getting Spotify volume Feb 10 13:19:27 volumio volumio[22517]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 10 13:19:27 volumio volumio[22517]: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 10 13:19:27 volumio volumio[22517]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Feb 10 13:19:27 volumio volumio[22517]: errno: -111, Feb 10 13:19:27 volumio volumio[22517]: code: 'ECONNREFUSED', Feb 10 13:19:27 volumio volumio[22517]: syscall: 'connect', Feb 10 13:19:27 volumio volumio[22517]: address: '127.0.0.1', Feb 10 13:19:27 volumio volumio[22517]: port: 9879, Feb 10 13:19:27 volumio volumio[22517]: response: undefined Feb 10 13:19:27 volumio volumio[22517]: } Feb 10 13:19:27 volumio volumio[22517]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 10 13:19:27 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 15. Feb 10 13:19:27 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 13:19:27 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 13:19:27 volumio go-librespot[22861]: go-librespot daemon starting... Feb 10 13:19:27 volumio go-librespot[22863]: time="2026-02-10T13:19:27+07:00" level=info msg="running go-librespot 0.4.0" Feb 10 13:19:27 volumio go-librespot[22863]: time="2026-02-10T13:19:27+07:00" level=debug msg="app state loaded" Feb 10 13:19:27 volumio go-librespot[22863]: time="2026-02-10T13:19:27+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 13:19:28 volumio go-librespot[22863]: time="2026-02-10T13:19:28+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 10 13:19:28 volumio go-librespot[22863]: time="2026-02-10T13:19:28+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 13:19:28 volumio go-librespot[22863]: time="2026-02-10T13:19:28+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 13:19:28 volumio go-librespot[22863]: time="2026-02-10T13:19:28+07:00" level=info msg="zeroconf server listening on port 40261" Feb 10 13:19:28 volumio go-librespot[22863]: time="2026-02-10T13:19:28+07:00" level=debug msg="obtained new client token: AACw/qqXgEw3AYamdokaIlXd0KIH4wewgzCLqsAwI8HADR+L5yiCcNMS/24IpVAtJbnz4QgD/eAesz0Gw0FxvYhUKmNSyINpkXzvUe9KdlrT4J+jWP/jg0DpGThcY/vfXwLcH82+K25YTGS51dReGf+Xr3dpbA7xSHOjet8mIPAjJESP+Fzv7dtDDxY4ct0DB9e2ry95XX53F4W+s5EwE/xnwcD8DeblF9uEhEB33cOOlppWg77o0xW3tQ==" Feb 10 13:19:28 volumio go-librespot[22863]: time="2026-02-10T13:19:28+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 10 13:19:28 volumio go-librespot[22863]: time="2026-02-10T13:19:28+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 10 13:19:28 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 13:19:28 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 13:19:29 volumio sudo[22886]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-10 13:18' Feb 10 13:19:29 volumio sudo[22886]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 13:19:29 volumio sudo[22886]: pam_unix(sudo:session): session closed for user root Feb 10 13:19:29 volumio volumio-remote-updater[643]: [2026-02-10 13:19:29] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Feb 10 13:19:29 volumio volumio-remote-updater[643]: [2026-02-10 13:19:29] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Feb 10 13:19:29 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Feb 10 13:19:29 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Feb 10 13:19:29 volumio systemd[1]: volumio.service: Consumed 49.201s CPU time. Feb 10 13:19:29 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 10 13:19:29 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 10 13:19:29 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 10287. Feb 10 13:19:29 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 10 13:19:29 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Feb 10 13:19:29 volumio systemd[1]: volumio.service: Consumed 49.201s CPU time. Feb 10 13:19:29 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Feb 10 13:19:29 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 10 13:19:32 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 16. Feb 10 13:19:32 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 13:19:32 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 13:19:32 volumio go-librespot[22918]: go-librespot daemon starting... Feb 10 13:19:32 volumio go-librespot[22919]: time="2026-02-10T13:19:32+07:00" level=info msg="running go-librespot 0.4.0" Feb 10 13:19:32 volumio go-librespot[22919]: time="2026-02-10T13:19:32+07:00" level=debug msg="app state loaded" Feb 10 13:19:32 volumio go-librespot[22919]: time="2026-02-10T13:19:32+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 13:19:32 volumio go-librespot[22919]: time="2026-02-10T13:19:32+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 10 13:19:32 volumio go-librespot[22919]: time="2026-02-10T13:19:32+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 10 13:19:32 volumio go-librespot[22919]: time="2026-02-10T13:19:32+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 10 13:19:32 volumio go-librespot[22919]: time="2026-02-10T13:19:32+07:00" level=info msg="zeroconf server listening on port 36733" Feb 10 13:19:32 volumio go-librespot[22919]: time="2026-02-10T13:19:32+07:00" level=debug msg="obtained new client token: AABoRZ1vPOGMB+sorvFAC3ZO9xAanAHG3a3MeIZVf0cJbHhVYSTEWrdhcXgzRS0pLblUcqOE51Wkho2tFwIgUYe0yz8LzXrjA3xKiSRQhIG23oHmC5VvJsPtq6ezRhUNiMkT1JziYw0ooqdTZlp9eR5zj1Lif5GJ/LkWQe4cjJR5jmfHtaVZCanZR7jOLaiP3KuoF2m398EiTFt5+7yyKgqFZ16mesc413CAbdY5nl4xXlaC0duITSbBxQ==" Feb 10 13:19:33 volumio go-librespot[22919]: time="2026-02-10T13:19:33+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 10 13:19:33 volumio go-librespot[22919]: time="2026-02-10T13:19:33+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 10 13:19:33 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 13:19:33 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 13:19:33 volumio volumio[22900]: info: ------------------------------------------- Feb 10 13:19:33 volumio volumio[22900]: info: ----- Volumio3 ---- Feb 10 13:19:33 volumio volumio[22900]: info: ------------------------------------------- Feb 10 13:19:33 volumio volumio[22900]: info: ----- System startup ---- Feb 10 13:19:33 volumio volumio[22900]: info: ------------------------------------------- Feb 10 13:19:34 volumio volumio-remote-updater[643]: [2026-02-10 13:19:34] [connect] Successful connection Feb 10 13:19:34 volumio volumio[22900]: info: MYVOLUMIO Environment detected Feb 10 13:19:34 volumio volumio[22900]: info: Plugin folders cleanup Feb 10 13:19:34 volumio volumio[22900]: info: Scanning into folder /volumio/app/plugins/ Feb 10 13:19:34 volumio volumio[22900]: info: Scanning category audio_interface Feb 10 13:19:34 volumio volumio[22900]: info: Scanning category miscellanea Feb 10 13:19:34 volumio volumio[22900]: info: Scanning category music_service Feb 10 13:19:34 volumio volumio[22900]: info: Scanning category plugins.json Feb 10 13:19:34 volumio volumio[22900]: info: Scanning category system_controller Feb 10 13:19:34 volumio volumio[22900]: info: Scanning category user_interface Feb 10 13:19:34 volumio volumio[22900]: info: Scanning into folder /data/plugins/ Feb 10 13:19:34 volumio volumio[22900]: info: Scanning category music_service Feb 10 13:19:34 volumio volumio[22900]: info: Plugin folders cleanup completed Feb 10 13:19:34 volumio volumio[22900]: info: ------------------------------------------- Feb 10 13:19:34 volumio volumio[22900]: info: ----- Core plugins startup ---- Feb 10 13:19:34 volumio volumio[22900]: info: ------------------------------------------- Feb 10 13:19:34 volumio volumio[22900]: info: Loading plugins from folder /volumio/app/plugins/ Feb 10 13:19:34 volumio volumio[22900]: info: Adding plugin upnp to MyMusic Plugins Feb 10 13:19:34 volumio volumio[22900]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 10 13:19:34 volumio volumio[22900]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 10 13:19:34 volumio volumio[22900]: info: Loading plugins from folder /data/plugins/ Feb 10 13:19:34 volumio volumio[22900]: info: Loading plugin "system"... Feb 10 13:19:35 volumio volumio[22900]: info: Loading plugin "appearance"... Feb 10 13:19:36 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 17. Feb 10 13:19:36 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 13:19:36 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 13:19:36 volumio go-librespot[22938]: go-librespot daemon starting... Feb 10 13:19:36 volumio go-librespot[22939]: time="2026-02-10T13:19:36+07:00" level=info msg="running go-librespot 0.4.0" Feb 10 13:19:36 volumio go-librespot[22939]: time="2026-02-10T13:19:36+07:00" level=debug msg="app state loaded" Feb 10 13:19:36 volumio go-librespot[22939]: time="2026-02-10T13:19:36+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 13:19:36 volumio volumio[22900]: info: Loading plugin "network"... Feb 10 13:19:36 volumio volumio[22900]: info: Refreshing Cached IP Addresses Feb 10 13:19:36 volumio go-librespot[22939]: time="2026-02-10T13:19:36+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 10 13:19:36 volumio go-librespot[22939]: time="2026-02-10T13:19:36+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 10 13:19:36 volumio go-librespot[22939]: time="2026-02-10T13:19:36+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 10 13:19:36 volumio go-librespot[22939]: time="2026-02-10T13:19:36+07:00" level=info msg="zeroconf server listening on port 37125" Feb 10 13:19:37 volumio sudo[22947]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 10 13:19:37 volumio sudo[22947]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 13:19:37 volumio sudo[22949]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 10 13:19:37 volumio sudo[22949]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 13:19:37 volumio sudo[22947]: pam_unix(sudo:session): session closed for user root Feb 10 13:19:37 volumio sudo[22949]: pam_unix(sudo:session): session closed for user root Feb 10 13:19:37 volumio volumio[22900]: info: Loading plugin "services"... Feb 10 13:19:37 volumio volumio[22900]: info: Loading plugin "alsa_controller"... Feb 10 13:19:37 volumio sudo[22964]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 10 13:19:37 volumio sudo[22964]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 13:19:37 volumio volumio[22900]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 10 13:19:37 volumio volumio[22900]: info: Loading plugin "wizard"... Feb 10 13:19:37 volumio volumio[22900]: info: Loading plugin "networkfs"... Feb 10 13:19:37 volumio go-librespot[22939]: time="2026-02-10T13:19:37+07:00" level=debug msg="obtained new client token: AADosc2Yn0TBD+iSjbX0arAH3sYB168JqOZ22UZdFYSCA7AkEB8BzTlq+AzJ1Y9pZMqfceGChtprd4+EZU1uauBVolOoY3SUrEDOy5Dg3qCtbcwLloprFY92AhOEEdq9II0WAAzPuJS/a/3pLN98ehuUHTlV0vhoJs5LqWXfoV9DVSqxkndVGRD1ynXNZOoOIAo9BYMZE/rIg2fyplB279QSOdQQwRmOIv5GSSJE2wGKGr4GveXjmF0=" Feb 10 13:19:37 volumio volumio[22900]: info: Starting Udev Watcher for removable devices Feb 10 13:19:37 volumio volumio[22900]: info: Ignoring mount for partition: boot Feb 10 13:19:37 volumio volumio[22900]: info: Ignoring mount for partition: volumio Feb 10 13:19:37 volumio volumio[22900]: info: Ignoring mount for partition: volumio_data Feb 10 13:19:37 volumio volumio[22900]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 10 13:19:37 volumio volumio[22900]: info: Loading plugin "volumio_command_line_client"... Feb 10 13:19:37 volumio volumio[22900]: info: Loading plugin "upnp"... Feb 10 13:19:37 volumio go-librespot[22939]: time="2026-02-10T13:19:37+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 10 13:19:37 volumio volumio[22900]: info: [1770704377386] Starting Upmpd Daemon Feb 10 13:19:37 volumio volumio[22900]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 10 13:19:37 volumio volumio[22900]: info: Loading plugin "my_music"... Feb 10 13:19:37 volumio volumio[22900]: info: Loading plugin "mpd"... Feb 10 13:19:37 volumio go-librespot[22939]: time="2026-02-10T13:19:37+07:00" level=debug msg="completed keyexchange" Feb 10 13:19:37 volumio go-librespot[22939]: time="2026-02-10T13:19:37+07:00" level=debug msg="completed challenge" Feb 10 13:19:37 volumio go-librespot[22939]: time="2026-02-10T13:19:37+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 10 13:19:37 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 13:19:37 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 13:19:38 volumio volumio[22900]: info: Loading plugin "upnp_browser"... Feb 10 13:19:39 volumio sudo[22964]: pam_unix(sudo:session): session closed for user root Feb 10 13:19:40 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 18. Feb 10 13:19:40 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 13:19:40 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 13:19:40 volumio go-librespot[22981]: go-librespot daemon starting... Feb 10 13:19:40 volumio go-librespot[22982]: time="2026-02-10T13:19:40+07:00" level=info msg="running go-librespot 0.4.0" Feb 10 13:19:40 volumio go-librespot[22982]: time="2026-02-10T13:19:40+07:00" level=debug msg="app state loaded" Feb 10 13:19:40 volumio go-librespot[22982]: time="2026-02-10T13:19:40+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 13:19:40 volumio volumio[22900]: info: Starting UPNP Browser Feb 10 13:19:40 volumio volumio[22900]: info: Loading plugin "alarm-clock"... Feb 10 13:19:41 volumio volumio[22900]: info: Loading plugin "airplay_emulation"... Feb 10 13:19:41 volumio volumio[22900]: info: Starting Shairport Sync Feb 10 13:19:41 volumio volumio[22900]: info: Loading plugin "last_100"... Feb 10 13:19:41 volumio volumio[22900]: info: Loading plugin "webradio"... Feb 10 13:19:41 volumio go-librespot[22982]: time="2026-02-10T13:19:41+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 10 13:19:41 volumio go-librespot[22982]: time="2026-02-10T13:19:41+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 10 13:19:41 volumio go-librespot[22982]: time="2026-02-10T13:19:41+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 10 13:19:41 volumio go-librespot[22982]: time="2026-02-10T13:19:41+07:00" level=info msg="zeroconf server listening on port 42841" Feb 10 13:19:41 volumio volumio[22900]: info: Loading plugin "i2s_dacs"... Feb 10 13:19:41 volumio volumio[22900]: info: Loading plugin "volumiodiscovery"... Feb 10 13:19:41 volumio volumio[22900]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 10 13:19:41 volumio volumio[22900]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 10 13:19:41 volumio volumio[22900]: *** WARNING *** For more information see Feb 10 13:19:41 volumio volumio[22900]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 10 13:19:41 volumio volumio[22900]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 10 13:19:41 volumio volumio[22900]: *** WARNING *** For more information see Feb 10 13:19:41 volumio node[22900]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 10 13:19:41 volumio node[22900]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 10 13:19:41 volumio node[22900]: *** WARNING *** For more information see Feb 10 13:19:41 volumio node[22900]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 10 13:19:41 volumio node[22900]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 10 13:19:41 volumio node[22900]: *** WARNING *** For more information see Feb 10 13:19:41 volumio volumio[22900]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 10 13:19:41 volumio volumio[22900]: info: Discovery: Started advertising with name: Volumio Feb 10 13:19:41 volumio volumio[22900]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 10 13:19:41 volumio volumio[22900]: info: Loading plugin "spop"... Feb 10 13:19:41 volumio go-librespot[22982]: time="2026-02-10T13:19:41+07:00" level=debug msg="obtained new client token: AACIylTKTRwtetdTRQmwIpIiu55KQVVRoSOALDtV8zvyRtsTVNDInyhMSq8aYYtt3nwOlnmZNF0H/i783akjOlkszeJuRSw+sOx6BKgziDu9vg76CvXu7giUoZbCt2hXrajM4UPPA4/R/bAr3f/Lf7ERQC4ReXbbakxZpf9oCGIitMHYLhU3m9LRCRUGvCk4gTI66BJ5/bThhEH/eb7saOs55r4Qo7jeJ4stPFOgYE+WsyhSfZj8NmcLJA==" Feb 10 13:19:41 volumio go-librespot[22982]: time="2026-02-10T13:19:41+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 10 13:19:42 volumio go-librespot[22982]: time="2026-02-10T13:19:42+07:00" level=debug msg="completed keyexchange" Feb 10 13:19:42 volumio go-librespot[22982]: time="2026-02-10T13:19:42+07:00" level=debug msg="completed challenge" Feb 10 13:19:42 volumio go-librespot[22982]: time="2026-02-10T13:19:42+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 10 13:19:42 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 13:19:42 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 13:19:43 volumio volumio[22900]: info: Loading plugin "ytcr"... Feb 10 13:19:45 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 19. Feb 10 13:19:45 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 13:19:45 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 13:19:45 volumio go-librespot[22992]: go-librespot daemon starting... Feb 10 13:19:45 volumio go-librespot[22993]: time="2026-02-10T13:19:45+07:00" level=info msg="running go-librespot 0.4.0" Feb 10 13:19:45 volumio go-librespot[22993]: time="2026-02-10T13:19:45+07:00" level=debug msg="app state loaded" Feb 10 13:19:45 volumio go-librespot[22993]: time="2026-02-10T13:19:45+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 13:19:45 volumio go-librespot[22993]: time="2026-02-10T13:19:45+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 10 13:19:45 volumio go-librespot[22993]: time="2026-02-10T13:19:45+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 10 13:19:45 volumio go-librespot[22993]: time="2026-02-10T13:19:45+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 10 13:19:45 volumio go-librespot[22993]: time="2026-02-10T13:19:45+07:00" level=info msg="zeroconf server listening on port 46743" Feb 10 13:19:46 volumio go-librespot[22993]: time="2026-02-10T13:19:46+07:00" level=debug msg="obtained new client token: AACpgBo4zonVV4Vp4DYMIG1dnZiZrjVeRZjCp1wWBIGIcgktWDAwRHKj5hB/alhyIMDuJHzwJDI1ukAUD2HtokjlVDldb83v3QoBwsckfUTiZK4IPWcikcuntYsCR4Lz27az2OBYLizIqqZnT4gpmV//BFx3X778jEQvNQFz69d9jJdAKBkask6VZrBp9HusfgQt4SJDLNcnilSrchq/9IvmLJ5qf5ceQHMkvw+IJVTAwiw3mVS8pHc=" Feb 10 13:19:46 volumio volumio[22900]: info: Loading plugin "ytmusic"... Feb 10 13:19:46 volumio go-librespot[22993]: time="2026-02-10T13:19:46+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 10 13:19:46 volumio go-librespot[22993]: time="2026-02-10T13:19:46+07:00" level=debug msg="completed keyexchange" Feb 10 13:19:46 volumio go-librespot[22993]: time="2026-02-10T13:19:46+07:00" level=debug msg="completed challenge" Feb 10 13:19:46 volumio go-librespot[22993]: time="2026-02-10T13:19:46+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 10 13:19:46 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 13:19:46 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 13:19:47 volumio volumio-remote-updater[643]: [2026-02-10 13:19:47] [connect] Successful connection Feb 10 13:19:47 volumio volumio[22900]: info: Loading plugin "outputs"... Feb 10 13:19:47 volumio volumio[22900]: info: Loading plugin "albumart"... Feb 10 13:19:47 volumio volumio[22900]: info: Plugin example_plugin is not enabled Feb 10 13:19:47 volumio volumio[22900]: info: Loading plugin "inputs"... Feb 10 13:19:47 volumio volumio[22900]: info: Loading plugin "updater_comm"... Feb 10 13:19:47 volumio volumio[22900]: info: Plugin mpdemulation is not enabled Feb 10 13:19:47 volumio volumio[22900]: info: Loading plugin "rest_api"... Feb 10 13:19:47 volumio volumio[22900]: info: Loading plugin "websocket"... Feb 10 13:19:47 volumio volumio[22900]: info: Starting Socket.io Server version 1.7.4 Feb 10 13:19:47 volumio volumio[22900]: info: Loading plugin "RoonBridge"... Feb 10 13:19:48 volumio volumio[22900]: info: Applying required configuration parameters for plugin RoonBridge Feb 10 13:19:48 volumio volumio[22900]: info: Loading i18n strings for locale en Feb 10 13:19:48 volumio volumio[22900]: Updating browse sources language Feb 10 13:19:48 volumio volumio[22900]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 10 13:19:48 volumio volumio[22900]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 10 13:19:48 volumio volumio[22900]: info: CoreCommandRouter::initPlayerControls Feb 10 13:19:48 volumio volumio[22900]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:19:48 volumio volumio[22900]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:19:48 volumio volumio[22900]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:19:48 volumio volumio[22900]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:19:48 volumio volumio[22900]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:19:48 volumio volumio[22900]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:19:48 volumio volumio[22900]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:19:48 volumio volumio[22900]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:19:48 volumio volumio[22900]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 10 13:19:48 volumio volumio[22900]: Express server listening on port 3000 Feb 10 13:19:48 volumio volumio[22900]: [Metrics] WebUI: 16s 52.10ms Feb 10 13:19:48 volumio volumio[23015]: Forking 3 albumart workers Feb 10 13:19:48 volumio volumio[22900]: info: CoreStateMachine::resetVolumioState Feb 10 13:19:48 volumio volumio[22900]: info: CoreStateMachine::getcurrentVolume Feb 10 13:19:48 volumio volumio[22900]: info: CoreCommandRouter::volumioRetrievevolume Feb 10 13:19:48 volumio sudo[23041]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 10 13:19:48 volumio sudo[23041]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 13:19:48 volumio sudo[23054]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 10 13:19:48 volumio sudo[23054]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 13:19:48 volumio sudo[23054]: pam_unix(sudo:session): session closed for user root Feb 10 13:19:48 volumio sudo[23041]: pam_unix(sudo:session): session closed for user root Feb 10 13:19:48 volumio volumio[22900]: info: Volumio Network Manager: Network status updated: 1 Feb 10 13:19:49 volumio volumio[22900]: info: VolumeController:: Volume=100 Mute =false Feb 10 13:19:49 volumio volumio[22900]: info: CoreStateMachine::pushState Feb 10 13:19:49 volumio volumio[22900]: info: CorePlayQueue::getTrack 0 Feb 10 13:19:49 volumio volumio[22900]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 10 13:19:49 volumio volumio[22900]: info: CoreCommandRouter::volumioPushState Feb 10 13:19:49 volumio volumio[22900]: info: CoreStateMachine::updateTrackBlock Feb 10 13:19:49 volumio volumio[22900]: info: CorePlayQueue::getTrackBlock Feb 10 13:19:49 volumio volumio[22900]: info: CoreCommandRouter::volumioRetrievevolume Feb 10 13:19:49 volumio volumio-remote-updater[643]: [2026-02-10 13:19:49] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1770704387 101 Feb 10 13:19:49 volumio volumio[22900]: 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 13:19:49 volumio volumio[22900]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 13:19:49 volumio volumio[22900]: info: Reloading queue from file Feb 10 13:19:49 volumio volumio[22900]: info: CoreStateMachine::setRepeat null single undefined Feb 10 13:19:49 volumio volumio[22900]: info: CoreStateMachine::pushState Feb 10 13:19:49 volumio volumio[22900]: info: CorePlayQueue::getTrack 0 Feb 10 13:19:49 volumio volumio[22900]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 10 13:19:49 volumio volumio[22900]: info: CoreCommandRouter::volumioPushState Feb 10 13:19:49 volumio volumio[22900]: info: CoreStateMachine::setRandom null Feb 10 13:19:49 volumio volumio[22900]: info: CoreStateMachine::pushState Feb 10 13:19:49 volumio volumio[22900]: info: CorePlayQueue::getTrack 0 Feb 10 13:19:49 volumio volumio[22900]: info: CoreCommandRouter::volumioPushState Feb 10 13:19:49 volumio volumio[22900]: info: Setting Device type: Raspberry PI Feb 10 13:19:49 volumio volumio[22900]: info: Completed loading Core Plugins Feb 10 13:19:49 volumio volumio[22900]: info: Preparing to generate the ALSA configuration file Feb 10 13:19:49 volumio volumio[22900]: info: VolumeController:: Volume=100 Mute =false Feb 10 13:19:49 volumio volumio[22900]: info: CoreStateMachine::pushState Feb 10 13:19:49 volumio volumio[22900]: info: CorePlayQueue::getTrack 0 Feb 10 13:19:49 volumio volumio[22900]: info: CoreCommandRouter::volumioPushState Feb 10 13:19:49 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 20. Feb 10 13:19:49 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 13:19:49 volumio volumio[22900]: info: Asound.conf file unchanged, so no further update is needed Feb 10 13:19:49 volumio volumio[22900]: info: Output device has changed, restarting MPD Feb 10 13:19:49 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 13:19:49 volumio go-librespot[23077]: go-librespot daemon starting... Feb 10 13:19:49 volumio sudo[23076]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 10 13:19:49 volumio sudo[23076]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 13:19:49 volumio volumio[22900]: info: Output device has changed, restarting Shairport Sync Feb 10 13:19:49 volumio volumio[22900]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:19:49 volumio volumio[22900]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 13:19:49 volumio go-librespot[23080]: time="2026-02-10T13:19:49+07:00" level=info msg="running go-librespot 0.4.0" Feb 10 13:19:49 volumio go-librespot[23080]: time="2026-02-10T13:19:49+07:00" level=debug msg="app state loaded" Feb 10 13:19:49 volumio go-librespot[23080]: time="2026-02-10T13:19:49+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 13:19:49 volumio sudo[23079]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 10 13:19:49 volumio sudo[23076]: pam_unix(sudo:session): session closed for user root Feb 10 13:19:49 volumio sudo[23079]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 13:19:49 volumio sudo[23088]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 10 13:19:49 volumio sudo[23088]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 13:19:49 volumio sudo[23079]: pam_unix(sudo:session): session closed for user root Feb 10 13:19:49 volumio volumio[22900]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 10 13:19:49 volumio volumio[22900]: info: ___________ START PLUGINS ___________ Feb 10 13:19:49 volumio volumio[22900]: info: ControllerMpd::onStart: Initializing MPD Feb 10 13:19:49 volumio volumio[22900]: info: Creating MPD Configuration file Feb 10 13:19:49 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 10 13:19:50 volumio volumio[22900]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 10 13:19:50 volumio volumio[22900]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 10 13:19:50 volumio volumio[22900]: info: [1770704390032] CoreMusicLibrary::Adding element Media Servers Feb 10 13:19:50 volumio volumio[22900]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 10 13:19:50 volumio sudo[23096]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 10 13:19:50 volumio sudo[23096]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 13:19:50 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 10 13:19:50 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 10 13:19:50 volumio systemd[1]: mpd.service: Consumed 7.195s CPU time. Feb 10 13:19:50 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 10 13:19:50 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 10 13:19:50 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 10 13:19:50 volumio volumio[22900]: info: UPNP Browser: Client initialized successfully Feb 10 13:19:50 volumio sudo[23096]: pam_unix(sudo:session): session closed for user root Feb 10 13:19:50 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 10 13:19:50 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 10 13:19:50 volumio sudo[23098]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 10 13:19:50 volumio sudo[23098]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 13:19:50 volumio volumio[22900]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:19:50 volumio volumio[22900]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 13:19:50 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 10 13:19:50 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 10 13:19:50 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 10 13:19:50 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 10 13:19:50 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 10 13:19:50 volumio volumio[22900]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 10 13:19:50 volumio volumio[22900]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:19:50 volumio volumio[22900]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 13:19:50 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 10 13:19:50 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 10 13:19:50 volumio volumio[22900]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 10 13:19:50 volumio volumio[22900]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 10 13:19:50 volumio volumio[22900]: info: [1770704390528] CoreMusicLibrary::Adding element Last_100 Feb 10 13:19:50 volumio volumio[22900]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 10 13:19:50 volumio volumio[22900]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 10 13:19:50 volumio volumio[22900]: info: [1770704390537] CoreMusicLibrary::Adding element Webradio Feb 10 13:19:50 volumio volumio[22900]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 10 13:19:50 volumio volumio[22900]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 10 13:19:50 volumio volumio[22900]: info: Initializing BBC Radios Feb 10 13:19:50 volumio go-librespot[23080]: time="2026-02-10T13:19:50+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 10 13:19:50 volumio go-librespot[23080]: time="2026-02-10T13:19:50+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 10 13:19:50 volumio go-librespot[23080]: time="2026-02-10T13:19:50+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 10 13:19:50 volumio go-librespot[23080]: time="2026-02-10T13:19:50+07:00" level=info msg="zeroconf server listening on port 36505" Feb 10 13:19:50 volumio volumio[22900]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 10 13:19:50 volumio volumio[22900]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 13:19:50 volumio volumio[22900]: info: Creating Spotify config file Feb 10 13:19:50 volumio volumio[22900]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:19:50 volumio go-librespot[23080]: time="2026-02-10T13:19:50+07:00" level=debug msg="obtained new client token: AAD3bt7r/bWCDIX7PFFbCvXEw8J5CVJ4/mjXd0iUWKjf2UJIaYdHyvqdUN/clN04AlUXv0wijTcDD4V/IU8rmJkwLbywiiccST2lsyur/JbDEDMYONuJX2Pu1l4iQKI9obsK17/jPqW+Ol1URCbGumikBUL+wZ1M5Uxl0N/hTbex3yhm9VT3VrzBP4CenS8d4xPJJObYFMOwNKTkvRZXnGr7z4Xvgb2p+uYWQKAEvHNsbrBOSsEMdDRKvQ==" Feb 10 13:19:50 volumio sudo[23114]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 10 13:19:50 volumio sudo[23114]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 10 13:19:50 volumio sudo[23114]: pam_unix(sudo:session): session closed for user root Feb 10 13:19:51 volumio go-librespot[23080]: time="2026-02-10T13:19:51+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 10 13:19:51 volumio go-librespot[23080]: time="2026-02-10T13:19:51+07:00" level=debug msg="completed keyexchange" Feb 10 13:19:51 volumio go-librespot[23080]: time="2026-02-10T13:19:51+07:00" level=debug msg="completed challenge" Feb 10 13:19:51 volumio go-librespot[23080]: time="2026-02-10T13:19: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 13:19:51 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 13:19:51 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 13:19:51 volumio volumio[23031]: Starting albumart workers Feb 10 13:19:51 volumio volumio[22900]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 10 13:19:51 volumio volumio[22900]: info: [1770704391936] CoreMusicLibrary::Adding element YouTube Music Feb 10 13:19:51 volumio volumio[22900]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 10 13:19:51 volumio volumio[22900]: Cannot find translation for source YouTube Music Feb 10 13:19:51 volumio volumio[22900]: info: Volumio Calling Home Feb 10 13:19:52 volumio sudo[23131]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Feb 10 13:19:52 volumio sudo[23131]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 13:19:52 volumio volumio[23028]: Starting albumart workers Feb 10 13:19:52 volumio sudo[23131]: pam_unix(sudo:session): session closed for user root Feb 10 13:19:52 volumio volumio[23029]: Starting albumart workers Feb 10 13:19:52 volumio volumio[22900]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Feb 10 13:19:52 volumio volumio[22900]: info: Discovery: Found device Volumio Feb 10 13:19:52 volumio volumio[22900]: info: CoreCommandRouter::volumioGetState Feb 10 13:19:52 volumio volumio[22900]: info: CorePlayQueue::getTrack 0 Feb 10 13:19:52 volumio volumio[22900]: info: MPD Permissions set Feb 10 13:19:52 volumio volumio[22900]: info: MPD Permissions set Feb 10 13:19:52 volumio volumio[22900]: info: Upmpdcli Daemon Started Feb 10 13:19:52 volumio volumio[22900]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Feb 10 13:19:52 volumio volumio[22900]: info: Discovery: Found device Volumio Feb 10 13:19:52 volumio volumio[22900]: info: CoreCommandRouter::volumioGetState Feb 10 13:19:52 volumio volumio[22900]: info: CorePlayQueue::getTrack 0 Feb 10 13:19:52 volumio volumio[22900]: info: Volumio called home Feb 10 13:19:52 volumio volumio[22900]: info: Spotify config file written Feb 10 13:19:53 volumio sudo[23137]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 10 13:19:53 volumio sudo[23137]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 13:19:53 volumio volumio[22900]: 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 13:19:53 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 13:19:53 volumio volumio[22900]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:19:53 volumio volumio[22900]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:19:53 volumio volumio[22900]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:19:53 volumio volumio[22900]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:19:53 volumio volumio[22900]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:19:53 volumio volumio[22900]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:19:53 volumio volumio[22900]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:19:53 volumio volumio[22900]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:19:53 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 13:19:53 volumio go-librespot[23140]: go-librespot daemon starting... Feb 10 13:19:53 volumio volumio[22900]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 13:19:53 volumio volumio[22900]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:19:53 volumio volumio[22900]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:19:53 volumio volumio[22900]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:19:53 volumio sudo[23137]: pam_unix(sudo:session): session closed for user root Feb 10 13:19:53 volumio volumio[22900]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:19:53 volumio volumio[22900]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:19:53 volumio volumio[22900]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:19:53 volumio volumio[22900]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:19:53 volumio volumio[22900]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:19:53 volumio volumio[22900]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:19:53 volumio go-librespot[23146]: time="2026-02-10T13:19:53+07:00" level=info msg="running go-librespot 0.4.0" Feb 10 13:19:53 volumio go-librespot[23146]: time="2026-02-10T13:19:53+07:00" level=debug msg="app state loaded" Feb 10 13:19:53 volumio go-librespot[23146]: time="2026-02-10T13:19:53+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 13:19:53 volumio volumio[22900]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 13:19:53 volumio volumio[22900]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:19:53 volumio volumio[22900]: info: No need to fix Spotify hosts Feb 10 13:19:54 volumio go-librespot[23146]: time="2026-02-10T13:19:54+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 10 13:19:54 volumio go-librespot[23146]: time="2026-02-10T13:19:54+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 13:19:54 volumio go-librespot[23146]: time="2026-02-10T13:19:54+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 13:19:54 volumio go-librespot[23146]: time="2026-02-10T13:19:54+07:00" level=info msg="zeroconf server listening on port 41657" Feb 10 13:19:54 volumio go-librespot[23146]: time="2026-02-10T13:19:54+07:00" level=debug msg="obtained new client token: AAClXjzoONzl88DfntcI1wB2jp7EwvKBQGzTO24SOmOHt9lAzIsWmYSxBpbxFD+9MxnI2dGii75guGYI8cLnkVY2jia+dFC5u8T9xXASuZGpHAecEluGENMPUWtTQkWXwRYhrLwsul+W2rvn1kqJYiqX9AB+yXQTRGmZOdnSo/ajO67jXWPP47OtMLTRrrUqRXpQMlh0Aye92nnAhbgreDHP9qWsnbPRgzlSLVCXya+FBT5ek65qqVYZtg==" Feb 10 13:19:54 volumio go-librespot[23146]: time="2026-02-10T13:19:54+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 10 13:19:54 volumio go-librespot[23146]: time="2026-02-10T13:19:54+07:00" level=debug msg="completed keyexchange" Feb 10 13:19:54 volumio go-librespot[23146]: time="2026-02-10T13:19:54+07:00" level=debug msg="completed challenge" Feb 10 13:19:54 volumio volumio[22900]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 10 13:19:54 volumio volumio[22900]: SPOTIFY: BQBhyzTl_Q5Ya_YOr526-D86fIMaqxEQcMLCPIy1RQUlpI6-aYmrJ7NVq0FjmUWf1mW3aS42c_ehgwIC1UHBJiL-hx1MmIkILQTxcdt7WeWOoaTYSrr9lBC-dWsv8ubE7HI_BH2bImZnhAJON4DTjhmNQMUXzLlEoqolugJfYZieT3uSYCcoPoUpfGHLzKCbcX8jhbJvc8aCpGy1fc4t52cMAXky7hEj1SseqWSMEInbjYB--sNxpke2BZTaePGo-PnMieDD819bDuooEjf7q39Rxbgji_LjvZYgvJuzOGEeZ-8FXy56UMvT Feb 10 13:19:54 volumio volumio[22900]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 10 13:19:54 volumio volumio[22900]: info: New Spotify access token = BQBhyzTl_Q5Ya_YOr526-D86fIMaqxEQcMLCPIy1RQUlpI6-aYmrJ7NVq0FjmUWf1mW3aS42c_ehgwIC1UHBJiL-hx1MmIkILQTxcdt7WeWOoaTYSrr9lBC-dWsv8ubE7HI_BH2bImZnhAJON4DTjhmNQMUXzLlEoqolugJfYZieT3uSYCcoPoUpfGHLzKCbcX8jhbJvc8aCpGy1fc4t52cMAXky7hEj1SseqWSMEInbjYB--sNxpke2BZTaePGo-PnMieDD819bDuooEjf7q39Rxbgji_LjvZYgvJuzOGEeZ-8FXy56UMvT Feb 10 13:19:54 volumio volumio[22900]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 10 13:19:54 volumio volumio[22900]: info: Starting Shairport Sync Feb 10 13:19:54 volumio go-librespot[23146]: time="2026-02-10T13:19:54+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 10 13:19:54 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 13:19:54 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 13:19:54 volumio volumio[22900]: info: Starting Shairport Sync Feb 10 13:19:54 volumio volumio[22900]: info: Starting Shairport Sync Feb 10 13:19:54 volumio sudo[23178]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 10 13:19:54 volumio sudo[23178]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 13:19:54 volumio sudo[23180]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 10 13:19:54 volumio sudo[23180]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 13:19:54 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 10 13:19:54 volumio sudo[23183]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 10 13:19:54 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 10 13:19:54 volumio sudo[23183]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 13:19:54 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 10 13:19:54 volumio systemd[1]: shairport-sync.service: Consumed 2.234s CPU time. Feb 10 13:19:55 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 10 13:19:55 volumio sudo[23178]: pam_unix(sudo:session): session closed for user root Feb 10 13:19:55 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 10 13:19:55 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 10 13:19:55 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 10 13:19:55 volumio volumio[22900]: info: Shairport-Sync Started Feb 10 13:19:55 volumio volumio[22900]: Error adding Membership: Error: addMembership EINVAL Feb 10 13:19:55 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 10 13:19:55 volumio sudo[23180]: pam_unix(sudo:session): session closed for user root Feb 10 13:19:55 volumio volumio[22900]: info: CoreCommandRouter::volumioGetState Feb 10 13:19:55 volumio volumio[22900]: info: CorePlayQueue::getTrack 0 Feb 10 13:19:55 volumio sudo[23183]: pam_unix(sudo:session): session closed for user root Feb 10 13:19:55 volumio volumio[22900]: info: Shairport-Sync Started Feb 10 13:19:55 volumio volumio[22900]: info: Shairport-Sync Started Feb 10 13:19:55 volumio volumio[22900]: 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 13:19:55 volumio volumio[22900]: info: Spotify Successfully logged in Feb 10 13:19:55 volumio volumio[22900]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 10 13:19:55 volumio volumio[22900]: info: [1770704395595] CoreMusicLibrary::Adding element Spotify Feb 10 13:19:55 volumio volumio[22900]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 10 13:19:55 volumio volumio[22900]: Cannot find translation for source YouTube Music Feb 10 13:19:55 volumio volumio[22900]: Cannot find translation for source Spotify Feb 10 13:19:56 volumio volumio[22900]: info: [yt-cast-receiver] DIAL server listening on port 8098 Feb 10 13:19:56 volumio volumio[22900]: info: CoreCommandRouter::volumioRetrievevolume Feb 10 13:19:56 volumio volumio[22900]: info: VolumeController:: Volume=100 Mute =false Feb 10 13:19:56 volumio volumio[22900]: info: CoreCommandRouter::volumioGetState Feb 10 13:19:56 volumio volumio[22900]: info: CorePlayQueue::getTrack 0 Feb 10 13:19:56 volumio volumio[22900]: info: CoreStateMachine::pushState Feb 10 13:19:56 volumio volumio[22900]: info: CorePlayQueue::getTrack 0 Feb 10 13:19:56 volumio volumio[22900]: info: CoreCommandRouter::volumioPushState Feb 10 13:19:57 volumio volumio[22900]: info: go-librespot daemon successfully initialized Feb 10 13:19:57 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 21. Feb 10 13:19:57 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 13:19:57 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 13:19:57 volumio go-librespot[23219]: go-librespot daemon starting... Feb 10 13:19:57 volumio go-librespot[23220]: time="2026-02-10T13:19:57+07:00" level=info msg="running go-librespot 0.4.0" Feb 10 13:19:57 volumio go-librespot[23220]: time="2026-02-10T13:19:57+07:00" level=debug msg="app state loaded" Feb 10 13:19:57 volumio go-librespot[23220]: time="2026-02-10T13:19:57+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 13:19:58 volumio mpd[23129]: 2026-02-10T13:19:58 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 10 13:19:58 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 10 13:19:58 volumio sudo[23088]: pam_unix(sudo:session): session closed for user root Feb 10 13:19:58 volumio sudo[23098]: pam_unix(sudo:session): session closed for user root Feb 10 13:19:58 volumio volumio[22900]: error: MPD error: The expression evaluated to a falsy value: Feb 10 13:19:58 volumio volumio[22900]: assert.ok(self.idling) Feb 10 13:19:58 volumio volumio[22900]: error: The expression evaluated to a falsy value: Feb 10 13:19:58 volumio volumio[22900]: assert.ok(self.idling) Feb 10 13:19:58 volumio volumio[22900]: info: MPD running with PID23129 Feb 10 13:19:58 volumio volumio[22900]: ,establishing connection Feb 10 13:19:58 volumio volumio[22900]: error: updateQueue error: null Feb 10 13:19:58 volumio volumio[22900]: info: Completed starting Core Plugins Feb 10 13:19:58 volumio volumio[22900]: info: ------------------------------------------- Feb 10 13:19:58 volumio volumio[22900]: info: ----- MyVolumio plugins startup ---- Feb 10 13:19:58 volumio volumio[22900]: info: ------------------------------------------- Feb 10 13:19:58 volumio volumio[22900]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 10 13:19:58 volumio go-librespot[23220]: time="2026-02-10T13:19:58+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 10 13:19:58 volumio go-librespot[23220]: time="2026-02-10T13:19:58+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 13:19:58 volumio go-librespot[23220]: time="2026-02-10T13:19:58+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 13:19:58 volumio volumio[22900]: error: updateQueue error: null Feb 10 13:19:58 volumio go-librespot[23220]: time="2026-02-10T13:19:58+07:00" level=info msg="zeroconf server listening on port 39981" Feb 10 13:19:58 volumio go-librespot[23220]: time="2026-02-10T13:19:58+07:00" level=debug msg="obtained new client token: AABHT7So5MBrguN68xa35S6LkYVExyGdEKD3ZfUFI5gLtDsB++s8VbGCnagbfPLJtDOmrxUZybR4UJyTBj2NnWvNnl5B9ESp8aK65OJ05Hq1708Lq9p0Q85wmetipXkZsPmqIPcIUk0KpnzcgBCihMekN7hAIIbozUpDtU6ceFsaJID72iBRYdPAgJ+edREDe1LP1KS0Wpqm6qXUHtg7rRE78szXGZZg55Fr0YVWzX1B4h8/ZivjkuL26w==" Feb 10 13:19:58 volumio go-librespot[23220]: time="2026-02-10T13:19:58+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 13:19:58 volumio go-librespot[23220]: time="2026-02-10T13:19:58+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 13:19:58 volumio go-librespot[23220]: time="2026-02-10T13:19:58+07:00" level=debug msg="connected to ap-gae2.spotify.com:80" Feb 10 13:19:59 volumio go-librespot[23220]: time="2026-02-10T13:19:59+07:00" level=debug msg="completed keyexchange" Feb 10 13:19:59 volumio go-librespot[23220]: time="2026-02-10T13:19:59+07:00" level=debug msg="completed challenge" Feb 10 13:19:59 volumio go-librespot[23220]: time="2026-02-10T13:19:59+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 10 13:19:59 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 13:19:59 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 13:20:00 volumio volumio[22900]: info: Initializing connection to go-librespot Websocket Feb 10 13:20:00 volumio volumio[22900]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 10 13:20:02 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 22. Feb 10 13:20:02 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 13:20:02 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 13:20:02 volumio go-librespot[23231]: go-librespot daemon starting... Feb 10 13:20:02 volumio go-librespot[23232]: time="2026-02-10T13:20:02+07:00" level=info msg="running go-librespot 0.4.0" Feb 10 13:20:02 volumio go-librespot[23232]: time="2026-02-10T13:20:02+07:00" level=debug msg="app state loaded" Feb 10 13:20:02 volumio go-librespot[23232]: time="2026-02-10T13:20:02+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 13:20:02 volumio go-librespot[23232]: time="2026-02-10T13:20:02+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 10 13:20:02 volumio go-librespot[23232]: time="2026-02-10T13:20:02+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 13:20:02 volumio go-librespot[23232]: time="2026-02-10T13:20:02+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 13:20:03 volumio go-librespot[23232]: time="2026-02-10T13:20:03+07:00" level=info msg="zeroconf server listening on port 42867" Feb 10 13:20:03 volumio go-librespot[23232]: time="2026-02-10T13:20:03+07:00" level=debug msg="obtained new client token: AACym1fyTdmdNkO7sBA7OxW5miHH0aLW3oYCWxDK5gdOI1q9WI/P778knyoiVdyoF6MRbUs9uU3JUJJAWclRxyHWI5H7Dt+5/zq1J0GP0KTEBanLz0sDUcGeZhcSkFbthQFPXMOuW4aoekKhzAOZLbXBt0WyCTlPt4yivt7bEF4MqV8tN7wC2e+nhixU3okwlDM98RXSDyrjw6j14dokr7yw5rDKwQ+PGoCkvIL024v4o5AQ2Jtbmzs=" Feb 10 13:20:03 volumio volumio[22900]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 10 13:20:03 volumio go-librespot[23232]: time="2026-02-10T13:20:03+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 10 13:20:03 volumio go-librespot[23232]: time="2026-02-10T13:20:03+07:00" level=debug msg="completed keyexchange" Feb 10 13:20:03 volumio go-librespot[23232]: time="2026-02-10T13:20:03+07:00" level=debug msg="completed challenge" Feb 10 13:20:03 volumio go-librespot[23232]: time="2026-02-10T13:20:03+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 10 13:20:03 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 13:20:03 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 13:20:03 volumio volumio[22900]: info: Initializing connection to go-librespot Websocket Feb 10 13:20:03 volumio volumio[22900]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 10 13:20:06 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 23. Feb 10 13:20:06 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 13:20:06 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 13:20:06 volumio go-librespot[23241]: go-librespot daemon starting... Feb 10 13:20:06 volumio go-librespot[23242]: time="2026-02-10T13:20:06+07:00" level=info msg="running go-librespot 0.4.0" Feb 10 13:20:06 volumio go-librespot[23242]: time="2026-02-10T13:20:06+07:00" level=debug msg="app state loaded" Feb 10 13:20:06 volumio go-librespot[23242]: time="2026-02-10T13:20:06+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 13:20:06 volumio volumio[22900]: info: Initializing connection to go-librespot Websocket Feb 10 13:20:06 volumio go-librespot[23242]: time="2026-02-10T13:20:06+07:00" level=debug msg="new websocket client" Feb 10 13:20:06 volumio volumio[22900]: info: Connection to go-librespot Websocket established Feb 10 13:20:07 volumio go-librespot[23242]: time="2026-02-10T13:20:07+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 10 13:20:07 volumio go-librespot[23242]: time="2026-02-10T13:20:07+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 13:20:07 volumio go-librespot[23242]: time="2026-02-10T13:20:07+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 13:20:07 volumio go-librespot[23242]: time="2026-02-10T13:20:07+07:00" level=info msg="zeroconf server listening on port 45627" Feb 10 13:20:07 volumio volumio[22900]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 10 13:20:07 volumio volumio[22900]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 10 13:20:07 volumio volumio[22900]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 10 13:20:07 volumio volumio[22900]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 10 13:20:07 volumio volumio[22900]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 10 13:20:07 volumio volumio[22900]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 10 13:20:07 volumio volumio[22900]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 10 13:20:07 volumio volumio[22900]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 10 13:20:07 volumio volumio[22900]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 10 13:20:07 volumio volumio[22900]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 10 13:20:07 volumio volumio[22900]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 10 13:20:07 volumio volumio[22900]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 10 13:20:07 volumio volumio[22900]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 10 13:20:07 volumio volumio[22900]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 10 13:20:07 volumio volumio[22900]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 10 13:20:07 volumio volumio[22900]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 10 13:20:07 volumio volumio[22900]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 10 13:20:07 volumio volumio[22900]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 10 13:20:07 volumio volumio[22900]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 10 13:20:07 volumio volumio[22900]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 10 13:20:07 volumio volumio[22900]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 10 13:20:07 volumio volumio[22900]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 10 13:20:07 volumio volumio[22900]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 10 13:20:07 volumio volumio[22900]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 10 13:20:07 volumio volumio[22900]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 10 13:20:07 volumio volumio[22900]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 10 13:20:07 volumio volumio[22900]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 10 13:20:07 volumio volumio[22900]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 10 13:20:07 volumio volumio[22900]: info: Adding plugin bluetooth to MyMusic Plugins Feb 10 13:20:07 volumio volumio[22900]: info: Adding plugin multiroom to MyMusic Plugins Feb 10 13:20:07 volumio volumio[22900]: info: Adding plugin metavolumio to MyMusic Plugins Feb 10 13:20:07 volumio volumio[22900]: info: Adding plugin cd_controller to MyMusic Plugins Feb 10 13:20:07 volumio volumio[22900]: info: Adding plugin qobuzconnect to MyMusic Plugins Feb 10 13:20:07 volumio volumio[22900]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 10 13:20:07 volumio volumio[22900]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 10 13:20:07 volumio volumio[22900]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 10 13:20:07 volumio go-librespot[23242]: time="2026-02-10T13:20:07+07:00" level=debug msg="obtained new client token: AABlZUyZwpxCq0LPW0NENfPnyoBWZ4/JqGiAAV6jl6+/3IUsjdeNvAvXRd0CJK9OBbHac79EsS8pRYNsMt+Hf4Y1c7eIbFIH4p4Sb6EXjgtIfYP+tYiwnBR0DcdUR3ed8CgT3egDBk51qcB9xaPUNyzweWWUNm8TqwiJ9OmZFK6MGhTCHA7pC0Jk/5lNAnFTFSnV+Eap9OMKC5VmG6epklURiOI2d/0GrchQ1b97uP42vyBL2CVJDS99Ig==" Feb 10 13:20:07 volumio go-librespot[23242]: time="2026-02-10T13:20:07+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 13:20:07 volumio go-librespot[23242]: time="2026-02-10T13:20:07+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Feb 10 13:20:07 volumio go-librespot[23242]: time="2026-02-10T13:20:07+07:00" level=debug msg="completed keyexchange" Feb 10 13:20:07 volumio go-librespot[23242]: time="2026-02-10T13:20:07+07:00" level=debug msg="completed challenge" Feb 10 13:20:07 volumio go-librespot[23242]: time="2026-02-10T13:20:07+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 10 13:20:07 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 13:20:07 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 13:20:09 volumio volumio[22900]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 10 13:20:09 volumio volumio[22900]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 10 13:20:09 volumio volumio[22900]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 13:20:09 volumio volumio[22900]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 13:20:09 volumio volumio[22900]: info: Starting MyVolumio Remote Streaming Endpoints Feb 10 13:20:09 volumio volumio[22900]: info: MyVolumio login type: Token Feb 10 13:20:09 volumio volumio[22900]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 10 13:20:09 volumio volumio[22900]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 10 13:20:10 volumio volumio[22900]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 10 13:20:10 volumio volumio[22900]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 10 13:20:10 volumio volumio[22900]: info: Streaming services startup Feb 10 13:20:10 volumio volumio[22900]: info: Starting Streaming Daemon Feb 10 13:20:10 volumio sudo[23265]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 10 13:20:10 volumio sudo[23265]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 13:20:10 volumio volumio[22900]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 10 13:20:11 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 24. Feb 10 13:20:11 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 13:20:11 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 13:20:11 volumio go-librespot[23271]: go-librespot daemon starting... Feb 10 13:20:11 volumio volumio[22900]: info: Getting Spotify volume Feb 10 13:20:11 volumio sudo[23265]: pam_unix(sudo:session): session closed for user root Feb 10 13:20:11 volumio go-librespot[23272]: time="2026-02-10T13:20:11+07:00" level=info msg="running go-librespot 0.4.0" Feb 10 13:20:11 volumio go-librespot[23272]: time="2026-02-10T13:20:11+07:00" level=debug msg="app state loaded" Feb 10 13:20:11 volumio volumio[22900]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 10 13:20:11 volumio go-librespot[23272]: time="2026-02-10T13:20:11+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 13:20:11 volumio volumio[22900]: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 10 13:20:11 volumio volumio[22900]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Feb 10 13:20:11 volumio volumio[22900]: errno: -111, Feb 10 13:20:11 volumio volumio[22900]: code: 'ECONNREFUSED', Feb 10 13:20:11 volumio volumio[22900]: syscall: 'connect', Feb 10 13:20:11 volumio volumio[22900]: address: '127.0.0.1', Feb 10 13:20:11 volumio volumio[22900]: port: 9879, Feb 10 13:20:11 volumio volumio[22900]: response: undefined Feb 10 13:20:11 volumio volumio[22900]: } Feb 10 13:20:11 volumio volumio[22900]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 10 13:20:11 volumio go-librespot[23272]: time="2026-02-10T13:20:11+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 10 13:20:11 volumio go-librespot[23272]: time="2026-02-10T13:20:11+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 10 13:20:11 volumio go-librespot[23272]: time="2026-02-10T13:20:11+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 10 13:20:11 volumio go-librespot[23272]: time="2026-02-10T13:20:11+07:00" level=info msg="zeroconf server listening on port 40651" Feb 10 13:20:11 volumio go-librespot[23272]: time="2026-02-10T13:20:11+07:00" level=debug msg="obtained new client token: AADOgprAC1KPebpAivIw736f+LpimiJ2ozGmeAOEitP2JoDOWq1e1z8ID/QiN8ko7RYLXdoBGm29sdoAcXIghizqD/Hj/GziU1eIHuYUvdkAXqWXKp7H4V0l/jDc9F+l9Dmvr62AzRwZC3UMJDEiSFvpz+6J7pFIQ3vOAGtzcIxMdqcOOp5ntRVd/PEqBi93vZFVYkR5k3UZS73hPDtmTeVF7m4zMAVd+Y1F6uYfS3EhAM2f0vwoZ50v1Q==" Feb 10 13:20:12 volumio go-librespot[23272]: time="2026-02-10T13:20:12+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 10 13:20:12 volumio go-librespot[23272]: time="2026-02-10T13:20:12+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 10 13:20:12 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 13:20:12 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 13:20:12 volumio sudo[23293]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-10 13:19' Feb 10 13:20:12 volumio sudo[23293]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 13:20:12 volumio sudo[23293]: pam_unix(sudo:session): session closed for user root Feb 10 13:20:13 volumio volumio-remote-updater[643]: [2026-02-10 13:20:12] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Feb 10 13:20:13 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Feb 10 13:20:13 volumio volumio-remote-updater[643]: [2026-02-10 13:20:13] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Feb 10 13:20:13 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Feb 10 13:20:13 volumio systemd[1]: volumio.service: Consumed 54.791s CPU time. Feb 10 13:20:13 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 10 13:20:13 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 10 13:20:13 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 10288. Feb 10 13:20:13 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 10 13:20:13 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Feb 10 13:20:13 volumio systemd[1]: volumio.service: Consumed 54.791s CPU time. Feb 10 13:20:13 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Feb 10 13:20:13 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 10 13:20:15 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 25. Feb 10 13:20:15 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 13:20:15 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 13:20:15 volumio go-librespot[23327]: go-librespot daemon starting... Feb 10 13:20:15 volumio go-librespot[23328]: time="2026-02-10T13:20:15+07:00" level=info msg="running go-librespot 0.4.0" Feb 10 13:20:15 volumio go-librespot[23328]: time="2026-02-10T13:20:15+07:00" level=debug msg="app state loaded" Feb 10 13:20:15 volumio go-librespot[23328]: time="2026-02-10T13:20:15+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 13:20:15 volumio go-librespot[23328]: time="2026-02-10T13:20:15+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 10 13:20:15 volumio go-librespot[23328]: time="2026-02-10T13:20:15+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 10 13:20:15 volumio go-librespot[23328]: time="2026-02-10T13:20:15+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 10 13:20:15 volumio go-librespot[23328]: time="2026-02-10T13:20:15+07:00" level=info msg="zeroconf server listening on port 45297" Feb 10 13:20:16 volumio go-librespot[23328]: time="2026-02-10T13:20:16+07:00" level=debug msg="obtained new client token: AAD/nEJzI8k4YK8KIlbRJBDFpu/OL8B8qKMz1D2uwuWiF3RpZWNP++bLJlwNoUQ/vRknd/64lETZ3WZ6fwNKixR7pX4pUf8UjXbbduBRovyIHxTmLAbpsXynCpdk7CKDS9vFu3LDsGaRGAytMVvjYXNW7eApg8adn7lHIFNwBH/x4l7spbvcehJ0dBg+mtGQceYfcjwoctuoFFBxSjmRrdlwpf7sB26tujZXcwcs6vDI4oNOzPXv8SY=" Feb 10 13:20:16 volumio go-librespot[23328]: time="2026-02-10T13:20:16+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 10 13:20:16 volumio go-librespot[23328]: time="2026-02-10T13:20:16+07:00" level=debug msg="completed keyexchange" Feb 10 13:20:16 volumio go-librespot[23328]: time="2026-02-10T13:20:16+07:00" level=debug msg="completed challenge" Feb 10 13:20:16 volumio go-librespot[23328]: time="2026-02-10T13:20:16+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 10 13:20:16 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 13:20:16 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 13:20:16 volumio volumio[23311]: info: ------------------------------------------- Feb 10 13:20:16 volumio volumio[23311]: info: ----- Volumio3 ---- Feb 10 13:20:16 volumio volumio[23311]: info: ------------------------------------------- Feb 10 13:20:16 volumio volumio[23311]: info: ----- System startup ---- Feb 10 13:20:16 volumio volumio[23311]: info: ------------------------------------------- Feb 10 13:20:18 volumio volumio-remote-updater[643]: [2026-02-10 13:20:18] [connect] Successful connection Feb 10 13:20:18 volumio volumio[23311]: info: MYVOLUMIO Environment detected Feb 10 13:20:18 volumio volumio[23311]: info: Plugin folders cleanup Feb 10 13:20:18 volumio volumio[23311]: info: Scanning into folder /volumio/app/plugins/ Feb 10 13:20:18 volumio volumio[23311]: info: Scanning category audio_interface Feb 10 13:20:18 volumio volumio[23311]: info: Scanning category miscellanea Feb 10 13:20:18 volumio volumio[23311]: info: Scanning category music_service Feb 10 13:20:18 volumio volumio[23311]: info: Scanning category plugins.json Feb 10 13:20:18 volumio volumio[23311]: info: Scanning category system_controller Feb 10 13:20:18 volumio volumio[23311]: info: Scanning category user_interface Feb 10 13:20:18 volumio volumio[23311]: info: Scanning into folder /data/plugins/ Feb 10 13:20:18 volumio volumio[23311]: info: Scanning category music_service Feb 10 13:20:18 volumio volumio[23311]: info: Plugin folders cleanup completed Feb 10 13:20:18 volumio volumio[23311]: info: ------------------------------------------- Feb 10 13:20:18 volumio volumio[23311]: info: ----- Core plugins startup ---- Feb 10 13:20:18 volumio volumio[23311]: info: ------------------------------------------- Feb 10 13:20:18 volumio volumio[23311]: info: Loading plugins from folder /volumio/app/plugins/ Feb 10 13:20:18 volumio volumio[23311]: info: Adding plugin upnp to MyMusic Plugins Feb 10 13:20:18 volumio volumio[23311]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 10 13:20:18 volumio volumio[23311]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 10 13:20:18 volumio volumio[23311]: info: Loading plugins from folder /data/plugins/ Feb 10 13:20:18 volumio volumio[23311]: info: Loading plugin "system"... Feb 10 13:20:18 volumio volumio[23311]: info: Loading plugin "appearance"... Feb 10 13:20:19 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 26. Feb 10 13:20:19 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 13:20:19 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 13:20:19 volumio go-librespot[23348]: go-librespot daemon starting... Feb 10 13:20:19 volumio go-librespot[23349]: time="2026-02-10T13:20:19+07:00" level=info msg="running go-librespot 0.4.0" Feb 10 13:20:19 volumio go-librespot[23349]: time="2026-02-10T13:20:19+07:00" level=debug msg="app state loaded" Feb 10 13:20:19 volumio go-librespot[23349]: time="2026-02-10T13:20:19+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 13:20:20 volumio go-librespot[23349]: time="2026-02-10T13:20:20+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 10 13:20:20 volumio go-librespot[23349]: time="2026-02-10T13:20:20+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 13:20:20 volumio go-librespot[23349]: time="2026-02-10T13:20:20+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 13:20:20 volumio go-librespot[23349]: time="2026-02-10T13:20:20+07:00" level=info msg="zeroconf server listening on port 34167" Feb 10 13:20:20 volumio volumio[23311]: info: Loading plugin "network"... Feb 10 13:20:20 volumio go-librespot[23349]: time="2026-02-10T13:20:20+07:00" level=debug msg="obtained new client token: AABhL1Ty/F3UXfha5y6UMn/dzzP+7eVkBZaFrRkqqXyR2OarfmTRGORACgJ/9vT5NteI1pq/TcIUCLg1a//tcRUEugvbNZ/d76LHmWPVocs48Chq+FO7Ujk/93wsVHRrlQb4vJD6n8ihW5cd+tGLrq3WUJU8v/5C43XZjBrcwM3rvG9y+U9OEb+jS28hGbjQ3PnPAyrSPc7dL97auBhFuiIfGg3j1cepzzCGTPDelCHPOoKCHfuT0ttp5A==" Feb 10 13:20:20 volumio volumio[23311]: info: Refreshing Cached IP Addresses Feb 10 13:20:20 volumio sudo[23357]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 10 13:20:20 volumio sudo[23357]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 13:20:20 volumio sudo[23357]: pam_unix(sudo:session): session closed for user root Feb 10 13:20:20 volumio sudo[23359]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 10 13:20:20 volumio sudo[23359]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 13:20:20 volumio go-librespot[23349]: time="2026-02-10T13:20:20+07:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:4070, retrying with a different AP" error="dial tcp 104.199.241.202:4070: connect: connection refused" Feb 10 13:20:20 volumio sudo[23359]: pam_unix(sudo:session): session closed for user root Feb 10 13:20:20 volumio volumio[23311]: info: Loading plugin "services"... Feb 10 13:20:20 volumio volumio[23311]: info: Loading plugin "alsa_controller"... Feb 10 13:20:20 volumio sudo[23369]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 10 13:20:20 volumio sudo[23369]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 13:20:20 volumio go-librespot[23349]: time="2026-02-10T13:20:20+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 13:20:20 volumio go-librespot[23349]: time="2026-02-10T13:20:20+07:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:80, retrying with a different AP" error="dial tcp 104.199.241.202:80: connect: connection refused" Feb 10 13:20:20 volumio volumio[23311]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 10 13:20:20 volumio volumio[23311]: info: Loading plugin "wizard"... Feb 10 13:20:20 volumio volumio[23311]: info: Loading plugin "networkfs"... Feb 10 13:20:20 volumio volumio[23311]: info: Starting Udev Watcher for removable devices Feb 10 13:20:20 volumio volumio[23311]: info: Ignoring mount for partition: boot Feb 10 13:20:20 volumio volumio[23311]: info: Ignoring mount for partition: volumio Feb 10 13:20:20 volumio volumio[23311]: info: Ignoring mount for partition: volumio_data Feb 10 13:20:20 volumio volumio[23311]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 10 13:20:20 volumio volumio[23311]: info: Loading plugin "volumio_command_line_client"... Feb 10 13:20:20 volumio volumio[23311]: info: Loading plugin "upnp"... Feb 10 13:20:20 volumio volumio[23311]: info: [1770704420861] Starting Upmpd Daemon Feb 10 13:20:20 volumio volumio[23311]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 10 13:20:20 volumio volumio[23311]: info: Loading plugin "my_music"... Feb 10 13:20:20 volumio volumio[23311]: info: Loading plugin "mpd"... Feb 10 13:20:21 volumio go-librespot[23349]: time="2026-02-10T13:20:21+07:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 10 13:20:21 volumio go-librespot[23349]: time="2026-02-10T13:20:21+07:00" level=debug msg="completed keyexchange" Feb 10 13:20:21 volumio go-librespot[23349]: time="2026-02-10T13:20:21+07:00" level=debug msg="completed challenge" Feb 10 13:20:21 volumio volumio[23311]: info: Loading plugin "upnp_browser"... Feb 10 13:20:21 volumio go-librespot[23349]: time="2026-02-10T13:20:21+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 10 13:20:21 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 13:20:21 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 13:20:23 volumio sudo[23369]: pam_unix(sudo:session): session closed for user root Feb 10 13:20:24 volumio volumio[23311]: info: Starting UPNP Browser Feb 10 13:20:24 volumio volumio[23311]: info: Loading plugin "alarm-clock"... Feb 10 13:20:24 volumio volumio[23311]: info: Loading plugin "airplay_emulation"... Feb 10 13:20:24 volumio volumio[23311]: info: Starting Shairport Sync Feb 10 13:20:24 volumio volumio[23311]: info: Loading plugin "last_100"... Feb 10 13:20:24 volumio volumio[23311]: info: Loading plugin "webradio"... Feb 10 13:20:24 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 27. Feb 10 13:20:24 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 13:20:24 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 13:20:24 volumio go-librespot[23390]: go-librespot daemon starting... Feb 10 13:20:24 volumio go-librespot[23391]: time="2026-02-10T13:20:24+07:00" level=info msg="running go-librespot 0.4.0" Feb 10 13:20:24 volumio go-librespot[23391]: time="2026-02-10T13:20:24+07:00" level=debug msg="app state loaded" Feb 10 13:20:24 volumio go-librespot[23391]: time="2026-02-10T13:20:24+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 13:20:24 volumio volumio[23311]: info: Loading plugin "i2s_dacs"... Feb 10 13:20:24 volumio volumio[23311]: info: Loading plugin "volumiodiscovery"... Feb 10 13:20:25 volumio volumio[23311]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 10 13:20:25 volumio volumio[23311]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 10 13:20:25 volumio volumio[23311]: *** WARNING *** For more information see Feb 10 13:20:25 volumio volumio[23311]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 10 13:20:25 volumio volumio[23311]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 10 13:20:25 volumio volumio[23311]: *** WARNING *** For more information see Feb 10 13:20:25 volumio node[23311]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 10 13:20:25 volumio node[23311]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 10 13:20:25 volumio node[23311]: *** WARNING *** For more information see Feb 10 13:20:25 volumio node[23311]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 10 13:20:25 volumio node[23311]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 10 13:20:25 volumio node[23311]: *** WARNING *** For more information see Feb 10 13:20:25 volumio volumio[23311]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 10 13:20:25 volumio volumio[23311]: info: Discovery: Started advertising with name: Volumio Feb 10 13:20:25 volumio volumio[23311]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 10 13:20:25 volumio volumio[23311]: info: Loading plugin "spop"... Feb 10 13:20:25 volumio go-librespot[23391]: time="2026-02-10T13:20:25+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 10 13:20:25 volumio go-librespot[23391]: time="2026-02-10T13:20:25+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 13:20:25 volumio go-librespot[23391]: time="2026-02-10T13:20:25+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 13:20:25 volumio go-librespot[23391]: time="2026-02-10T13:20:25+07:00" level=info msg="zeroconf server listening on port 35251" Feb 10 13:20:25 volumio go-librespot[23391]: time="2026-02-10T13:20:25+07:00" level=debug msg="obtained new client token: AAA7Mq5TAsJ2p4Am2JQETV8VsvENc2szdyxAYxnrR0qe0mrTylF7D9LapdwvEnaVj6oYS+rggNjt+eyG2qjLeiLYOE2O7W0Wh4J7/5QYXYAsY7KIkO95e159xbEDv0OADn8b2XbsQ9rYxoG+vd7OXKe8xHk4MQfyC9y5onGVKmaIfuutJU/YRSzfH2Wwz9LWb8yuV65bFdkQ3jsFLQjeieUO+l/ChvNDGMaSIQsDLk9UBUxfwdHBJdRWSw==" Feb 10 13:20:25 volumio go-librespot[23391]: time="2026-02-10T13:20:25+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 10 13:20:25 volumio go-librespot[23391]: time="2026-02-10T13:20:25+07:00" level=debug msg="completed keyexchange" Feb 10 13:20:25 volumio go-librespot[23391]: time="2026-02-10T13:20:25+07:00" level=debug msg="completed challenge" Feb 10 13:20:25 volumio go-librespot[23391]: time="2026-02-10T13:20:25+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 10 13:20:25 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 13:20:25 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 13:20:27 volumio volumio[23311]: info: Loading plugin "ytcr"... Feb 10 13:20:29 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 28. Feb 10 13:20:29 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 13:20:29 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 13:20:29 volumio go-librespot[23402]: go-librespot daemon starting... Feb 10 13:20:29 volumio go-librespot[23403]: time="2026-02-10T13:20:29+07:00" level=info msg="running go-librespot 0.4.0" Feb 10 13:20:29 volumio go-librespot[23403]: time="2026-02-10T13:20:29+07:00" level=debug msg="app state loaded" Feb 10 13:20:29 volumio go-librespot[23403]: time="2026-02-10T13:20:29+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 13:20:29 volumio volumio[23311]: info: Loading plugin "ytmusic"... Feb 10 13:20:29 volumio go-librespot[23403]: time="2026-02-10T13:20:29+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 10 13:20:29 volumio go-librespot[23403]: time="2026-02-10T13:20:29+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 13:20:29 volumio go-librespot[23403]: time="2026-02-10T13:20:29+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 13:20:29 volumio go-librespot[23403]: time="2026-02-10T13:20:29+07:00" level=info msg="zeroconf server listening on port 41413" Feb 10 13:20:30 volumio go-librespot[23403]: time="2026-02-10T13:20:30+07:00" level=debug msg="obtained new client token: AADV0KaUOrdNwqjLc/eoTjR7QroBliNH0WsyfolTas+eUBmSthGb7UcLqjlKn41OKH5b5EqPDDhGfDv7lSCySP1Qna+QQF5tbE0L/7zZK/IB/QzNTeYcK2foYKOnc56btDwPqc4HYUguKdsoPNJMLH3DyT+80JuF0gfSw4a+NaX5/y++cCHShVfeOKhfVe2yi3aP8/UwK6l6q9BUpPoshgQRfDVCddmSsFa7PqcZXPkeLY5aSko61KdWTA==" Feb 10 13:20:30 volumio go-librespot[23403]: time="2026-02-10T13:20:30+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 10 13:20:30 volumio go-librespot[23403]: time="2026-02-10T13:20:30+07:00" level=debug msg="completed keyexchange" Feb 10 13:20:30 volumio go-librespot[23403]: time="2026-02-10T13:20:30+07:00" level=debug msg="completed challenge" Feb 10 13:20:30 volumio go-librespot[23403]: time="2026-02-10T13:20:30+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 10 13:20:30 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 13:20:30 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 13:20:30 volumio volumio-remote-updater[643]: [2026-02-10 13:20:30] [connect] Successful connection Feb 10 13:20:30 volumio volumio[23311]: info: Loading plugin "outputs"... Feb 10 13:20:30 volumio volumio[23311]: info: Loading plugin "albumart"... Feb 10 13:20:30 volumio volumio[23311]: info: Plugin example_plugin is not enabled Feb 10 13:20:30 volumio volumio[23311]: info: Loading plugin "inputs"... Feb 10 13:20:30 volumio volumio[23311]: info: Loading plugin "updater_comm"... Feb 10 13:20:31 volumio volumio[23311]: info: Plugin mpdemulation is not enabled Feb 10 13:20:31 volumio volumio[23311]: info: Loading plugin "rest_api"... Feb 10 13:20:31 volumio volumio[23311]: info: Loading plugin "websocket"... Feb 10 13:20:31 volumio volumio[23311]: info: Starting Socket.io Server version 1.7.4 Feb 10 13:20:31 volumio volumio[23311]: info: Loading plugin "RoonBridge"... Feb 10 13:20:31 volumio volumio[23311]: info: Applying required configuration parameters for plugin RoonBridge Feb 10 13:20:31 volumio volumio[23311]: info: Loading i18n strings for locale en Feb 10 13:20:31 volumio volumio[23311]: Updating browse sources language Feb 10 13:20:31 volumio volumio[23311]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 10 13:20:31 volumio volumio[23311]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 10 13:20:31 volumio volumio[23311]: info: CoreCommandRouter::initPlayerControls Feb 10 13:20:31 volumio volumio[23311]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:20:31 volumio volumio[23311]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:20:31 volumio volumio[23311]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:20:31 volumio volumio[23311]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:20:31 volumio volumio[23311]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:20:31 volumio volumio[23311]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:20:31 volumio volumio[23311]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:20:31 volumio volumio[23311]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:20:31 volumio volumio[23311]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 10 13:20:31 volumio volumio[23311]: Express server listening on port 3000 Feb 10 13:20:31 volumio volumio[23311]: [Metrics] WebUI: 16s 43.87ms Feb 10 13:20:31 volumio volumio[23424]: Forking 3 albumart workers Feb 10 13:20:31 volumio volumio[23311]: info: CoreStateMachine::resetVolumioState Feb 10 13:20:31 volumio volumio[23311]: info: CoreStateMachine::getcurrentVolume Feb 10 13:20:31 volumio volumio[23311]: info: CoreCommandRouter::volumioRetrievevolume Feb 10 13:20:32 volumio sudo[23460]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 10 13:20:32 volumio sudo[23460]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 13:20:32 volumio sudo[23460]: pam_unix(sudo:session): session closed for user root Feb 10 13:20:32 volumio sudo[23470]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 10 13:20:32 volumio sudo[23470]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 13:20:32 volumio sudo[23470]: pam_unix(sudo:session): session closed for user root Feb 10 13:20:32 volumio volumio[23311]: info: Volumio Network Manager: Network status updated: 1 Feb 10 13:20:32 volumio volumio[23311]: info: VolumeController:: Volume=100 Mute =false Feb 10 13:20:32 volumio volumio[23311]: info: CoreStateMachine::pushState Feb 10 13:20:32 volumio volumio[23311]: info: CorePlayQueue::getTrack 0 Feb 10 13:20:32 volumio volumio[23311]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 10 13:20:32 volumio volumio[23311]: info: CoreCommandRouter::volumioPushState Feb 10 13:20:32 volumio volumio[23311]: info: CoreStateMachine::updateTrackBlock Feb 10 13:20:32 volumio volumio[23311]: info: CorePlayQueue::getTrackBlock Feb 10 13:20:32 volumio volumio[23311]: info: CoreCommandRouter::volumioRetrievevolume Feb 10 13:20:32 volumio volumio-remote-updater[643]: [2026-02-10 13:20:32] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1770704430 101 Feb 10 13:20:32 volumio volumio[23311]: 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 13:20:32 volumio volumio[23311]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 13:20:32 volumio volumio[23311]: info: Reloading queue from file Feb 10 13:20:32 volumio volumio[23311]: info: CoreStateMachine::setRepeat null single undefined Feb 10 13:20:32 volumio volumio[23311]: info: CoreStateMachine::pushState Feb 10 13:20:32 volumio volumio[23311]: info: CorePlayQueue::getTrack 0 Feb 10 13:20:32 volumio volumio[23311]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 10 13:20:32 volumio volumio[23311]: info: CoreCommandRouter::volumioPushState Feb 10 13:20:32 volumio volumio[23311]: info: CoreStateMachine::setRandom null Feb 10 13:20:32 volumio volumio[23311]: info: CoreStateMachine::pushState Feb 10 13:20:32 volumio volumio[23311]: info: CorePlayQueue::getTrack 0 Feb 10 13:20:32 volumio volumio[23311]: info: CoreCommandRouter::volumioPushState Feb 10 13:20:32 volumio volumio[23311]: info: Setting Device type: Raspberry PI Feb 10 13:20:32 volumio volumio[23311]: info: Completed loading Core Plugins Feb 10 13:20:32 volumio volumio[23311]: info: Preparing to generate the ALSA configuration file Feb 10 13:20:33 volumio volumio[23311]: info: VolumeController:: Volume=100 Mute =false Feb 10 13:20:33 volumio volumio[23311]: info: CoreStateMachine::pushState Feb 10 13:20:33 volumio volumio[23311]: info: CorePlayQueue::getTrack 0 Feb 10 13:20:33 volumio volumio[23311]: info: CoreCommandRouter::volumioPushState Feb 10 13:20:33 volumio volumio[23311]: info: Asound.conf file unchanged, so no further update is needed Feb 10 13:20:33 volumio volumio[23311]: info: Output device has changed, restarting MPD Feb 10 13:20:33 volumio volumio[23311]: info: Output device has changed, restarting Shairport Sync Feb 10 13:20:33 volumio volumio[23311]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:20:33 volumio volumio[23311]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 13:20:33 volumio sudo[23486]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 10 13:20:33 volumio sudo[23486]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 13:20:33 volumio sudo[23488]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 10 13:20:33 volumio sudo[23488]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 13:20:33 volumio sudo[23488]: pam_unix(sudo:session): session closed for user root Feb 10 13:20:33 volumio sudo[23490]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 10 13:20:33 volumio sudo[23490]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 13:20:33 volumio volumio[23311]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 10 13:20:33 volumio volumio[23311]: info: ___________ START PLUGINS ___________ Feb 10 13:20:33 volumio volumio[23311]: info: ControllerMpd::onStart: Initializing MPD Feb 10 13:20:33 volumio volumio[23311]: info: Creating MPD Configuration file Feb 10 13:20:33 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 29. Feb 10 13:20:33 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 13:20:33 volumio volumio[23311]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 10 13:20:33 volumio volumio[23311]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 10 13:20:33 volumio volumio[23311]: info: [1770704433456] CoreMusicLibrary::Adding element Media Servers Feb 10 13:20:33 volumio volumio[23311]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 10 13:20:33 volumio go-librespot[23501]: go-librespot daemon starting... Feb 10 13:20:33 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 13:20:33 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 10 13:20:33 volumio sudo[23486]: pam_unix(sudo:session): session closed for user root Feb 10 13:20:33 volumio sudo[23500]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 10 13:20:33 volumio sudo[23500]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 13:20:33 volumio sudo[23500]: pam_unix(sudo:session): session closed for user root Feb 10 13:20:33 volumio sudo[23503]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 10 13:20:33 volumio sudo[23503]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 13:20:33 volumio go-librespot[23504]: time="2026-02-10T13:20:33+07:00" level=info msg="running go-librespot 0.4.0" Feb 10 13:20:33 volumio go-librespot[23504]: time="2026-02-10T13:20:33+07:00" level=debug msg="app state loaded" Feb 10 13:20:33 volumio go-librespot[23504]: time="2026-02-10T13:20:33+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 13:20:33 volumio volumio[23311]: info: UPNP Browser: Client initialized successfully Feb 10 13:20:33 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 10 13:20:33 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 10 13:20:33 volumio systemd[1]: mpd.service: Consumed 7.200s CPU time. Feb 10 13:20:33 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 10 13:20:33 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 10 13:20:33 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 10 13:20:33 volumio volumio[23311]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:20:33 volumio volumio[23311]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 13:20:33 volumio volumio[23311]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 10 13:20:33 volumio volumio[23311]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:20:33 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 10 13:20:33 volumio volumio[23311]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 13:20:33 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 10 13:20:33 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 10 13:20:33 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 10 13:20:33 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 10 13:20:33 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 10 13:20:33 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 10 13:20:33 volumio volumio[23311]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 10 13:20:33 volumio volumio[23311]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 10 13:20:33 volumio volumio[23311]: info: [1770704433910] CoreMusicLibrary::Adding element Last_100 Feb 10 13:20:33 volumio volumio[23311]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 10 13:20:33 volumio volumio[23311]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 10 13:20:33 volumio volumio[23311]: info: [1770704433931] CoreMusicLibrary::Adding element Webradio Feb 10 13:20:33 volumio volumio[23311]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 10 13:20:33 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 10 13:20:33 volumio volumio[23311]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 10 13:20:33 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 10 13:20:34 volumio volumio[23311]: info: Initializing BBC Radios Feb 10 13:20:34 volumio volumio[23311]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 10 13:20:34 volumio volumio[23311]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 13:20:34 volumio volumio[23311]: info: Creating Spotify config file Feb 10 13:20:34 volumio volumio[23311]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:20:34 volumio go-librespot[23504]: time="2026-02-10T13:20:34+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 10 13:20:34 volumio go-librespot[23504]: time="2026-02-10T13:20:34+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 10 13:20:34 volumio go-librespot[23504]: time="2026-02-10T13:20:34+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 10 13:20:34 volumio go-librespot[23504]: time="2026-02-10T13:20:34+07:00" level=info msg="zeroconf server listening on port 44795" Feb 10 13:20:34 volumio sudo[23523]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 10 13:20:34 volumio sudo[23523]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 10 13:20:34 volumio sudo[23523]: pam_unix(sudo:session): session closed for user root Feb 10 13:20:34 volumio go-librespot[23504]: time="2026-02-10T13:20:34+07:00" level=debug msg="obtained new client token: AABbSgU82kbTh9MD2a04NtIX0YxLC47nI7hvzehfUpQ8BW2Bz6QFeZoDCINugldfvdUtRtp5J3FMtFGTW1CCtcjKrYhOKkeHSTXH1GiabZQYASxOxO8yL5CXp1iEQkL4QZ6BN+0TEtknH4zMaBe75P7Fj+JSY+BMV38Fa8gVjLriSFeam7Ncw3kfm20NVeOzAtT8mt9S+6qxqjXlzyxAqVW5Dh27TylfYyZ249qY5xykYawYmat/xAOo8w==" Feb 10 13:20:34 volumio go-librespot[23504]: time="2026-02-10T13:20:34+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 10 13:20:34 volumio go-librespot[23504]: time="2026-02-10T13:20:34+07:00" level=debug msg="completed keyexchange" Feb 10 13:20:34 volumio go-librespot[23504]: time="2026-02-10T13:20:34+07:00" level=debug msg="completed challenge" Feb 10 13:20:35 volumio go-librespot[23504]: time="2026-02-10T13:20:35+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 10 13:20:35 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 13:20:35 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 13:20:35 volumio volumio[23439]: Starting albumart workers Feb 10 13:20:35 volumio volumio[23440]: Starting albumart workers Feb 10 13:20:35 volumio volumio[23311]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 10 13:20:35 volumio volumio[23311]: info: [1770704435530] CoreMusicLibrary::Adding element YouTube Music Feb 10 13:20:35 volumio volumio[23311]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 10 13:20:35 volumio volumio[23311]: Cannot find translation for source YouTube Music Feb 10 13:20:35 volumio volumio[23441]: Starting albumart workers Feb 10 13:20:35 volumio volumio[23311]: info: Volumio Calling Home Feb 10 13:20:35 volumio sudo[23542]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Feb 10 13:20:35 volumio sudo[23542]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 13:20:35 volumio sudo[23542]: pam_unix(sudo:session): session closed for user root Feb 10 13:20:36 volumio volumio[23311]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Feb 10 13:20:36 volumio volumio[23311]: info: Discovery: Found device Volumio Feb 10 13:20:36 volumio volumio[23311]: info: CoreCommandRouter::volumioGetState Feb 10 13:20:36 volumio volumio[23311]: info: CorePlayQueue::getTrack 0 Feb 10 13:20:36 volumio volumio[23311]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Feb 10 13:20:36 volumio volumio[23311]: info: Discovery: Found device Volumio Feb 10 13:20:36 volumio volumio[23311]: info: CoreCommandRouter::volumioGetState Feb 10 13:20:36 volumio volumio[23311]: info: CorePlayQueue::getTrack 0 Feb 10 13:20:36 volumio volumio[23311]: info: MPD Permissions set Feb 10 13:20:36 volumio volumio[23311]: info: MPD Permissions set Feb 10 13:20:36 volumio volumio[23311]: info: Upmpdcli Daemon Started Feb 10 13:20:36 volumio volumio[23311]: info: Volumio called home Feb 10 13:20:36 volumio volumio[23311]: info: Spotify config file written Feb 10 13:20:36 volumio volumio[23311]: 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 13:20:36 volumio volumio[23311]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:20:36 volumio volumio[23311]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:20:36 volumio volumio[23311]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:20:36 volumio volumio[23311]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:20:36 volumio volumio[23311]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:20:36 volumio volumio[23311]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:20:36 volumio volumio[23311]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:20:36 volumio volumio[23311]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:20:36 volumio sudo[23548]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 10 13:20:36 volumio sudo[23548]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 13:20:37 volumio volumio[23311]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 13:20:37 volumio volumio[23311]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:20:37 volumio volumio[23311]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:20:37 volumio volumio[23311]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:20:37 volumio volumio[23311]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:20:37 volumio volumio[23311]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:20:37 volumio volumio[23311]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:20:37 volumio volumio[23311]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:20:37 volumio volumio[23311]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:20:37 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 13:20:37 volumio volumio[23311]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:20:37 volumio volumio[23311]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 13:20:37 volumio volumio[23311]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 10 13:20:37 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 13:20:37 volumio volumio[23311]: info: No need to fix Spotify hosts Feb 10 13:20:37 volumio go-librespot[23562]: go-librespot daemon starting... Feb 10 13:20:37 volumio sudo[23548]: pam_unix(sudo:session): session closed for user root Feb 10 13:20:37 volumio go-librespot[23570]: time="2026-02-10T13:20:37+07:00" level=info msg="running go-librespot 0.4.0" Feb 10 13:20:37 volumio go-librespot[23570]: time="2026-02-10T13:20:37+07:00" level=debug msg="app state loaded" Feb 10 13:20:37 volumio go-librespot[23570]: time="2026-02-10T13:20:37+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 13:20:37 volumio go-librespot[23570]: time="2026-02-10T13:20: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 10 13:20:37 volumio go-librespot[23570]: time="2026-02-10T13:20:37+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 13:20:37 volumio go-librespot[23570]: time="2026-02-10T13:20:37+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 13:20:37 volumio go-librespot[23570]: time="2026-02-10T13:20:37+07:00" level=info msg="zeroconf server listening on port 38717" Feb 10 13:20:38 volumio go-librespot[23570]: time="2026-02-10T13:20:38+07:00" level=debug msg="obtained new client token: AACWUCIQK/itfSgsYPvHvQCQ5NQ9S+vs/jjCwi4VXoC4648Ecg9LBu1wdwc/FqPihPNLa7DoRfGT6eST6YHu/iKGzuFnUfF2bcGiGsMTI/Hr0isxuDqHLJkCBaP6FKocudnsaO/XIg4GVMtC2IYENLp1lko1XMkIBzwpBFeX1ZmxR4i60arX7bJbg0qTyV38ARTbatzA0H0YloYqUZlfcuDhYWZm399PRvxK6wRWXyHbT0YvInSz9IQ=" Feb 10 13:20:38 volumio volumio[23311]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 10 13:20:38 volumio volumio[23311]: SPOTIFY: BQARyF4MR8h9TXRQA6CEIKlKbIa1DxwWTT34QOiFBwBvbgsOps9STMoNauleFXK-hHrKiIOFQu7bMO2FaQbHoso94weLTd5m67JoOagXF0aEvSR5vt8o_CjNGn4SbOmWUuUGFnsihp6nOv-4PKI21a47NTyK3DpW51Ie8J7kTzWxL8UWSKEtEmqz16lm3azJsZ_lxrKHATjcisUiOF1eMu8yir2B2HofddbUndbEXqJR-88SkSHPWbKD4ML0kPA20lb06C-0u2k2_9bD7omojgROf3zOFCCY9aEniWx3UmC0ni8cAWfPXG7F Feb 10 13:20:38 volumio volumio[23311]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 10 13:20:38 volumio volumio[23311]: info: New Spotify access token = BQARyF4MR8h9TXRQA6CEIKlKbIa1DxwWTT34QOiFBwBvbgsOps9STMoNauleFXK-hHrKiIOFQu7bMO2FaQbHoso94weLTd5m67JoOagXF0aEvSR5vt8o_CjNGn4SbOmWUuUGFnsihp6nOv-4PKI21a47NTyK3DpW51Ie8J7kTzWxL8UWSKEtEmqz16lm3azJsZ_lxrKHATjcisUiOF1eMu8yir2B2HofddbUndbEXqJR-88SkSHPWbKD4ML0kPA20lb06C-0u2k2_9bD7omojgROf3zOFCCY9aEniWx3UmC0ni8cAWfPXG7F Feb 10 13:20:38 volumio volumio[23311]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 10 13:20:38 volumio go-librespot[23570]: time="2026-02-10T13:20:38+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 10 13:20:38 volumio go-librespot[23570]: time="2026-02-10T13:20:38+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 10 13:20:38 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 13:20:38 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 13:20:38 volumio volumio[23311]: info: Starting Shairport Sync Feb 10 13:20:38 volumio volumio[23311]: info: Starting Shairport Sync Feb 10 13:20:38 volumio volumio[23311]: info: Starting Shairport Sync Feb 10 13:20:38 volumio sudo[23589]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 10 13:20:38 volumio sudo[23589]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 13:20:38 volumio sudo[23591]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 10 13:20:38 volumio sudo[23591]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 13:20:38 volumio sudo[23594]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 10 13:20:38 volumio sudo[23594]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 13:20:38 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 10 13:20:38 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 10 13:20:38 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 10 13:20:38 volumio systemd[1]: shairport-sync.service: Consumed 2.294s CPU time. Feb 10 13:20:38 volumio volumio[23311]: info: CoreCommandRouter::volumioGetState Feb 10 13:20:38 volumio volumio[23311]: info: CorePlayQueue::getTrack 0 Feb 10 13:20:38 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 10 13:20:38 volumio sudo[23589]: pam_unix(sudo:session): session closed for user root Feb 10 13:20:38 volumio sudo[23591]: pam_unix(sudo:session): session closed for user root Feb 10 13:20:38 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 10 13:20:38 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 10 13:20:38 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 10 13:20:38 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 10 13:20:39 volumio sudo[23594]: pam_unix(sudo:session): session closed for user root Feb 10 13:20:39 volumio volumio[23311]: info: Shairport-Sync Started Feb 10 13:20:39 volumio volumio[23311]: Error adding Membership: Error: addMembership EINVAL Feb 10 13:20:39 volumio volumio[23311]: info: Shairport-Sync Started Feb 10 13:20:39 volumio volumio[23311]: info: Shairport-Sync Started Feb 10 13:20:39 volumio volumio[23311]: 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 13:20:39 volumio volumio[23311]: info: Spotify Successfully logged in Feb 10 13:20:39 volumio volumio[23311]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 10 13:20:39 volumio volumio[23311]: info: [1770704439276] CoreMusicLibrary::Adding element Spotify Feb 10 13:20:39 volumio volumio[23311]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 10 13:20:39 volumio volumio[23311]: Cannot find translation for source YouTube Music Feb 10 13:20:39 volumio volumio[23311]: Cannot find translation for source Spotify Feb 10 13:20:39 volumio volumio[23311]: info: [yt-cast-receiver] DIAL server listening on port 8098 Feb 10 13:20:39 volumio volumio[23311]: info: CoreCommandRouter::volumioRetrievevolume Feb 10 13:20:39 volumio volumio[23311]: info: VolumeController:: Volume=100 Mute =false Feb 10 13:20:39 volumio volumio[23311]: info: CoreCommandRouter::volumioGetState Feb 10 13:20:39 volumio volumio[23311]: info: CorePlayQueue::getTrack 0 Feb 10 13:20:39 volumio volumio[23311]: info: CoreStateMachine::pushState Feb 10 13:20:39 volumio volumio[23311]: info: CorePlayQueue::getTrack 0 Feb 10 13:20:39 volumio volumio[23311]: info: CoreCommandRouter::volumioPushState Feb 10 13:20:41 volumio volumio[23311]: info: go-librespot daemon successfully initialized Feb 10 13:20:41 volumio mpd[23540]: 2026-02-10T13:20:41 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 10 13:20:41 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 30. Feb 10 13:20:41 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 10 13:20:41 volumio sudo[23490]: pam_unix(sudo:session): session closed for user root Feb 10 13:20:41 volumio sudo[23503]: pam_unix(sudo:session): session closed for user root Feb 10 13:20:41 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 13:20:41 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 13:20:41 volumio go-librespot[23631]: go-librespot daemon starting... Feb 10 13:20:41 volumio go-librespot[23634]: time="2026-02-10T13:20:41+07:00" level=info msg="running go-librespot 0.4.0" Feb 10 13:20:41 volumio go-librespot[23634]: time="2026-02-10T13:20:41+07:00" level=debug msg="app state loaded" Feb 10 13:20:41 volumio go-librespot[23634]: time="2026-02-10T13:20:41+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 13:20:41 volumio volumio[23311]: error: MPD error: The expression evaluated to a falsy value: Feb 10 13:20:41 volumio volumio[23311]: assert.ok(self.idling) Feb 10 13:20:41 volumio volumio[23311]: error: The expression evaluated to a falsy value: Feb 10 13:20:41 volumio volumio[23311]: assert.ok(self.idling) Feb 10 13:20:41 volumio volumio[23311]: error: updateQueue error: null Feb 10 13:20:41 volumio volumio[23311]: info: MPD running with PID23540 Feb 10 13:20:41 volumio volumio[23311]: ,establishing connection Feb 10 13:20:41 volumio volumio[23311]: info: Completed starting Core Plugins Feb 10 13:20:41 volumio volumio[23311]: info: ------------------------------------------- Feb 10 13:20:41 volumio volumio[23311]: info: ----- MyVolumio plugins startup ---- Feb 10 13:20:41 volumio volumio[23311]: info: ------------------------------------------- Feb 10 13:20:41 volumio volumio[23311]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 10 13:20:41 volumio volumio[23311]: error: updateQueue error: null Feb 10 13:20:42 volumio go-librespot[23634]: time="2026-02-10T13:20:42+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 10 13:20:42 volumio go-librespot[23634]: time="2026-02-10T13:20:42+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 10 13:20:42 volumio go-librespot[23634]: time="2026-02-10T13:20:42+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 10 13:20:42 volumio go-librespot[23634]: time="2026-02-10T13:20:42+07:00" level=info msg="zeroconf server listening on port 41593" Feb 10 13:20:42 volumio go-librespot[23634]: time="2026-02-10T13:20:42+07:00" level=debug msg="obtained new client token: AADe5Dr3OCqI8P2MAny6YBp3BIsGJin+QRSVYOJmF7QJh/gew6MZwgcXBgv8LEwiDVV1oK+Z3kdu+7Fz2sgcpD9W5nJc6iJjsighnyp+pRNOJxj3/QyQGNnWFXrju+U99snDHZK1q8V0diPAVFzKi3ruwMVTlbnOvdxC1pt3dMx5CxC3NeJ2sXRLU+p1AiyO417m+x3+Z9L1jssgh41LDjrHE2Fv5uyug7uOOP8heDp3eNNhEWzUUI9bHA==" Feb 10 13:20:42 volumio go-librespot[23634]: time="2026-02-10T13:20:42+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 10 13:20:42 volumio go-librespot[23634]: time="2026-02-10T13:20:42+07:00" level=debug msg="completed keyexchange" Feb 10 13:20:42 volumio go-librespot[23634]: time="2026-02-10T13:20:42+07:00" level=debug msg="completed challenge" Feb 10 13:20:42 volumio go-librespot[23634]: time="2026-02-10T13:20:42+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 10 13:20:42 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 13:20:42 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 13:20:44 volumio volumio[23311]: info: Initializing connection to go-librespot Websocket Feb 10 13:20:44 volumio volumio[23311]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 10 13:20:45 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 31. Feb 10 13:20:45 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 13:20:45 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 13:20:45 volumio go-librespot[23642]: go-librespot daemon starting... Feb 10 13:20:45 volumio go-librespot[23643]: time="2026-02-10T13:20:45+07:00" level=info msg="running go-librespot 0.4.0" Feb 10 13:20:45 volumio go-librespot[23643]: time="2026-02-10T13:20:45+07:00" level=debug msg="app state loaded" Feb 10 13:20:45 volumio go-librespot[23643]: time="2026-02-10T13:20:45+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 13:20:46 volumio go-librespot[23643]: time="2026-02-10T13:20: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-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 10 13:20:46 volumio go-librespot[23643]: time="2026-02-10T13:20:46+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 13:20:46 volumio go-librespot[23643]: time="2026-02-10T13:20:46+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 13:20:46 volumio go-librespot[23643]: time="2026-02-10T13:20:46+07:00" level=info msg="zeroconf server listening on port 34787" Feb 10 13:20:46 volumio volumio[23311]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 10 13:20:46 volumio go-librespot[23643]: time="2026-02-10T13:20:46+07:00" level=debug msg="obtained new client token: AAAmnEAwjRoFBPpPtlZIo/ZJ3CDJQK71iJGBqqU+oFrPDUPfdR38P+GEUIHUEDk4JFfTOkJy1T+TEyL09YByJiVmrke02cWrs07pf3guY5ll8Gys73fOXZAmvFJ/FEghYsp0qouvnR/1BlnbLiGxdYaa/mW0tv48HjA45xpt2zYdcu7SKKNLOOUJDaNazuZScNPFPGGnm/QGHLB4lH/f331mChMheQdpzMV97VMbrPBVprz0LN4kZJI9UA==" Feb 10 13:20:46 volumio go-librespot[23643]: time="2026-02-10T13:20:46+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 10 13:20:46 volumio go-librespot[23643]: time="2026-02-10T13:20:46+07:00" level=debug msg="completed keyexchange" Feb 10 13:20:46 volumio go-librespot[23643]: time="2026-02-10T13:20:46+07:00" level=debug msg="completed challenge" Feb 10 13:20:46 volumio go-librespot[23643]: time="2026-02-10T13:20:46+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 10 13:20:46 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 13:20:46 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 13:20:47 volumio volumio[23311]: info: Initializing connection to go-librespot Websocket Feb 10 13:20:47 volumio volumio[23311]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 10 13:20:50 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 32. Feb 10 13:20:50 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 13:20:50 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 13:20:50 volumio go-librespot[23650]: go-librespot daemon starting... Feb 10 13:20:50 volumio go-librespot[23651]: time="2026-02-10T13:20:50+07:00" level=info msg="running go-librespot 0.4.0" Feb 10 13:20:50 volumio go-librespot[23651]: time="2026-02-10T13:20:50+07:00" level=debug msg="app state loaded" Feb 10 13:20:50 volumio go-librespot[23651]: time="2026-02-10T13:20:50+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 13:20:50 volumio volumio[23311]: info: Initializing connection to go-librespot Websocket Feb 10 13:20:50 volumio go-librespot[23651]: time="2026-02-10T13:20:50+07:00" level=debug msg="new websocket client" Feb 10 13:20:50 volumio volumio[23311]: info: Connection to go-librespot Websocket established Feb 10 13:20:50 volumio go-librespot[23651]: time="2026-02-10T13:20:50+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 10 13:20:50 volumio go-librespot[23651]: time="2026-02-10T13:20:50+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 13:20:50 volumio go-librespot[23651]: time="2026-02-10T13:20:50+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 13:20:50 volumio volumio[23311]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 10 13:20:50 volumio volumio[23311]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 10 13:20:50 volumio volumio[23311]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 10 13:20:50 volumio volumio[23311]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 10 13:20:50 volumio volumio[23311]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 10 13:20:50 volumio volumio[23311]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 10 13:20:50 volumio volumio[23311]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 10 13:20:50 volumio volumio[23311]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 10 13:20:50 volumio volumio[23311]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 10 13:20:50 volumio volumio[23311]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 10 13:20:50 volumio volumio[23311]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 10 13:20:50 volumio volumio[23311]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 10 13:20:50 volumio volumio[23311]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 10 13:20:50 volumio volumio[23311]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 10 13:20:50 volumio volumio[23311]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 10 13:20:50 volumio volumio[23311]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 10 13:20:50 volumio volumio[23311]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 10 13:20:50 volumio volumio[23311]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 10 13:20:50 volumio volumio[23311]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 10 13:20:50 volumio volumio[23311]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 10 13:20:50 volumio volumio[23311]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 10 13:20:50 volumio volumio[23311]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 10 13:20:50 volumio volumio[23311]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 10 13:20:50 volumio volumio[23311]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 10 13:20:50 volumio volumio[23311]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 10 13:20:50 volumio volumio[23311]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 10 13:20:50 volumio volumio[23311]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 10 13:20:50 volumio volumio[23311]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 10 13:20:50 volumio volumio[23311]: info: Adding plugin bluetooth to MyMusic Plugins Feb 10 13:20:50 volumio go-librespot[23651]: time="2026-02-10T13:20:50+07:00" level=info msg="zeroconf server listening on port 36331" Feb 10 13:20:50 volumio volumio[23311]: info: Adding plugin multiroom to MyMusic Plugins Feb 10 13:20:50 volumio volumio[23311]: info: Adding plugin metavolumio to MyMusic Plugins Feb 10 13:20:50 volumio volumio[23311]: info: Adding plugin cd_controller to MyMusic Plugins Feb 10 13:20:50 volumio volumio[23311]: info: Adding plugin qobuzconnect to MyMusic Plugins Feb 10 13:20:50 volumio volumio[23311]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 10 13:20:50 volumio volumio[23311]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 10 13:20:50 volumio volumio[23311]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 10 13:20:50 volumio go-librespot[23651]: time="2026-02-10T13:20:50+07:00" level=debug msg="obtained new client token: AADJnw7dx0B51YgBBw2e1+ko8UZ+nrrjs/cI23bvZV7yezyhdbpYGLW/CLMcJhPbaaVS43r0lS9pkPm7InGZpkk4P7krkARXuUmET3IN4RXUtZCPDCfvy/FzNHPqTXQNGcQg7/9Ib5HjhmNFTaGw8AUBg4w9BhEo7sSGb6yTmcjWROI3Yw9kwgkdM58sJUHKPYrXmMbhqHrImfIU+rULm2PbJlTBZ35+LuGXzuhbk2e6rC2CIrNHY3nHtw==" Feb 10 13:20:51 volumio go-librespot[23651]: time="2026-02-10T13:20:51+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 10 13:20:51 volumio go-librespot[23651]: time="2026-02-10T13:20:51+07:00" level=debug msg="completed keyexchange" Feb 10 13:20:51 volumio go-librespot[23651]: time="2026-02-10T13:20:51+07:00" level=debug msg="completed challenge" Feb 10 13:20:51 volumio go-librespot[23651]: time="2026-02-10T13:20: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 13:20:51 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 13:20:51 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 13:20:52 volumio volumio[23311]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 10 13:20:52 volumio volumio[23311]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 10 13:20:52 volumio volumio[23311]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 13:20:52 volumio volumio[23311]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 10 13:20:52 volumio volumio[23311]: info: Starting MyVolumio Remote Streaming Endpoints Feb 10 13:20:52 volumio volumio[23311]: info: MyVolumio login type: Token Feb 10 13:20:52 volumio volumio[23311]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 10 13:20:52 volumio volumio[23311]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 10 13:20:54 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 33. Feb 10 13:20:54 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 10 13:20:54 volumio volumio[23311]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 10 13:20:54 volumio volumio[23311]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 10 13:20:54 volumio volumio[23311]: info: Streaming services startup Feb 10 13:20:54 volumio volumio[23311]: info: Starting Streaming Daemon Feb 10 13:20:54 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 10 13:20:54 volumio go-librespot[23673]: go-librespot daemon starting... Feb 10 13:20:54 volumio go-librespot[23675]: time="2026-02-10T13:20:54+07:00" level=info msg="running go-librespot 0.4.0" Feb 10 13:20:54 volumio go-librespot[23675]: time="2026-02-10T13:20:54+07:00" level=debug msg="app state loaded" Feb 10 13:20:54 volumio go-librespot[23675]: time="2026-02-10T13:20:54+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 10 13:20:54 volumio sudo[23676]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 10 13:20:54 volumio volumio[23311]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 10 13:20:54 volumio sudo[23676]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 10 13:20:54 volumio sudo[23676]: pam_unix(sudo:session): session closed for user root Feb 10 13:20:54 volumio volumio[23311]: info: Getting Spotify volume Feb 10 13:20:54 volumio volumio[23311]: info: Connection to go-librespot Websocket closed Feb 10 13:20:54 volumio volumio[23311]: error: Cannot start Volumio Streaming Daemon Feb 10 13:20:54 volumio volumio[23311]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 10 13:20:54 volumio volumio[23311]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 10 13:20:54 volumio volumio[23311]: 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 13:20:54 volumio volumio[23311]: info: CoreCommandRouter::volumioGetState Feb 10 13:20:54 volumio volumio[23311]: info: CorePlayQueue::getTrack 0 Feb 10 13:20:54 volumio volumio[23311]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Feb 10 13:20:54 volumio volumio[23311]: SPOTIFY: SPOTIFY VOLUME undefined Feb 10 13:20:54 volumio volumio[23311]: SPOTIFY: VOLUMIO VOLUME 100 Feb 10 13:20:54 volumio volumio[23311]: info: Aligning Spotify Volume to Volumio Volume Feb 10 13:20:54 volumio volumio[23311]: info: CoreCommandRouter::volumioGetState Feb 10 13:20:54 volumio volumio[23311]: info: CorePlayQueue::getTrack 0 Feb 10 13:20:54 volumio volumio[23311]: info: Setting Spotify Volume from Volumio: 100 Feb 10 13:20:54 volumio go-librespot[23675]: time="2026-02-10T13:20:54+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 10 13:20:54 volumio go-librespot[23675]: time="2026-02-10T13:20:54+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 13:20:54 volumio go-librespot[23675]: time="2026-02-10T13:20:54+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 13:20:54 volumio go-librespot[23675]: time="2026-02-10T13:20:54+07:00" level=info msg="zeroconf server listening on port 37535" Feb 10 13:20:55 volumio go-librespot[23675]: time="2026-02-10T13:20:55+07:00" level=debug msg="obtained new client token: AADjZRP9WNKitmRJO8Gd0RCwzFIi+mY7mLViuUuGxg7Ul5skEa1G2kfiJzS6f0JAQdzkiJubpBgdLeAhbwt4KPHCSt9Pa0spKhHVTbp1uGsVzueEIwx4yGckbsL70Yv8xY0tljJmr9WJNkosgQR58pXVTUfA2b06Bgh5+/7B3NohFDsd84W3862G2C7Tvj/bD0Cx5D7ulKbIg/q4AzTpaf1Em7kLfl1PofW1Q26EP+qGGMvhMUMlC0E=" Feb 10 13:20:55 volumio go-librespot[23675]: time="2026-02-10T13:20:55+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 10 13:20:55 volumio go-librespot[23675]: time="2026-02-10T13:20:55+07:00" level=debug msg="completed keyexchange" Feb 10 13:20:55 volumio go-librespot[23675]: time="2026-02-10T13:20:55+07:00" level=debug msg="completed challenge" Feb 10 13:20:55 volumio go-librespot[23675]: time="2026-02-10T13:20: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 13:20:55 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 10 13:20:55 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 10 13:20:55 volumio volumio[23311]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 10 13:20:55 volumio volumio[23311]: Error: socket hang up Feb 10 13:20:55 volumio volumio[23311]: at connResetException (node:internal/errors:720:14) Feb 10 13:20:55 volumio volumio[23311]: at Socket.socketOnEnd (node:_http_client:519:23) Feb 10 13:20:55 volumio volumio[23311]: at Socket.emit (node:events:526:35) Feb 10 13:20:55 volumio volumio[23311]: at endReadableNT (node:internal/streams/readable:1376:12) Feb 10 13:20:55 volumio volumio[23311]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Feb 10 13:20:55 volumio volumio[23311]: code: 'ECONNRESET', Feb 10 13:20:55 volumio volumio[23311]: response: undefined Feb 10 13:20:55 volumio volumio[23311]: } Feb 10 13:20:55 volumio volumio[23311]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 10 13:20:56 volumio sudo[23703]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-10 13:19' Feb 10 13:20:56 volumio sudo[23703]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) PRETTY_NAME="Raspbian GNU/Linux 12 (bookworm)" NAME="Raspbian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="b05a530ca81d05eb9a84d0acf82089f0a60b8ee6" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="4ad85e2147d972f0b838d33c21382d2d813b2ae8" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu Dec 25 09:13:19 UTC 2025" VOLUMIO_VERSION="4.084" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="792f09af7488531aecd1aadcaa9b175e"