Feb 08 02:38:01 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 32. Feb 08 02:38:01 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 08 02:38:01 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 08 02:38:01 volumio go-librespot[24205]: go-librespot daemon starting... Feb 08 02:38:01 volumio go-librespot[24206]: time="2026-02-08T02:38:01+07:00" level=info msg="running go-librespot 0.4.0" Feb 08 02:38:01 volumio go-librespot[24206]: time="2026-02-08T02:38:01+07:00" level=debug msg="app state loaded" Feb 08 02:38:01 volumio go-librespot[24206]: time="2026-02-08T02:38:01+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 08 02:38:01 volumio go-librespot[24206]: time="2026-02-08T02:38:01+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 08 02:38:01 volumio go-librespot[24206]: time="2026-02-08T02:38:01+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 08 02:38:01 volumio go-librespot[24206]: time="2026-02-08T02:38:01+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 08 02:38:01 volumio go-librespot[24206]: time="2026-02-08T02:38:01+07:00" level=info msg="zeroconf server listening on port 36687" Feb 08 02:38:02 volumio go-librespot[24206]: time="2026-02-08T02:38:02+07:00" level=debug msg="obtained new client token: AABMAs8d/PgMyy3TcjdNnQ/Fbvu6KTaW/i7lCDVlBxukuGX6nT/rVdCbl7eb5lwfCzjL/vdVIgqs25VB5E0nFX3QGYRXceAfLkWPX/taMk3PqiCsjhHYxuqUnMplqSxEzOmao+/zZyks6pbbHWUSsn2Iz5qi6yeDL62swVjxz5H4LzJ+kNV8fozixFTv0eo5DI8/S16ShG9CY2im9OSJzSjiS0WSOViB5Zt0ml0T5rtw06K3cyoOXGU=" Feb 08 02:38:02 volumio go-librespot[24206]: time="2026-02-08T02:38:02+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 08 02:38:02 volumio go-librespot[24206]: time="2026-02-08T02:38:02+07:00" level=debug msg="completed keyexchange" Feb 08 02:38:02 volumio go-librespot[24206]: time="2026-02-08T02:38:02+07:00" level=debug msg="completed challenge" Feb 08 02:38:02 volumio go-librespot[24206]: time="2026-02-08T02:38:02+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 08 02:38:02 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 08 02:38:02 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 08 02:38:02 volumio volumio[24117]: info: Loading plugin "ytmusic"... Feb 08 02:38:03 volumio volumio-remote-updater[643]: [2026-02-08 02:38:03] [connect] Successful connection Feb 08 02:38:03 volumio volumio[24117]: info: Loading plugin "outputs"... Feb 08 02:38:03 volumio volumio[24117]: info: Loading plugin "albumart"... Feb 08 02:38:03 volumio volumio[24117]: info: Plugin example_plugin is not enabled Feb 08 02:38:03 volumio volumio[24117]: info: Loading plugin "inputs"... Feb 08 02:38:03 volumio volumio[24117]: info: Loading plugin "updater_comm"... Feb 08 02:38:03 volumio volumio[24117]: info: Plugin mpdemulation is not enabled Feb 08 02:38:03 volumio volumio[24117]: info: Loading plugin "rest_api"... Feb 08 02:38:04 volumio volumio[24117]: info: Loading plugin "websocket"... Feb 08 02:38:04 volumio volumio[24117]: info: Starting Socket.io Server version 1.7.4 Feb 08 02:38:04 volumio volumio[24117]: info: Loading plugin "RoonBridge"... Feb 08 02:38:04 volumio volumio[24117]: info: Applying required configuration parameters for plugin RoonBridge Feb 08 02:38:04 volumio volumio[24117]: info: Loading i18n strings for locale en Feb 08 02:38:04 volumio volumio[24117]: Updating browse sources language Feb 08 02:38:04 volumio volumio[24117]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 08 02:38:04 volumio volumio[24227]: Forking 3 albumart workers Feb 08 02:38:04 volumio volumio[24117]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 08 02:38:04 volumio volumio[24117]: info: CoreCommandRouter::initPlayerControls Feb 08 02:38:04 volumio volumio[24117]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 02:38:04 volumio volumio[24117]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 02:38:04 volumio volumio[24117]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 02:38:04 volumio volumio[24117]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 02:38:04 volumio volumio[24117]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 02:38:04 volumio volumio[24117]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 02:38:04 volumio volumio[24117]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 02:38:04 volumio volumio[24117]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 02:38:04 volumio volumio[24117]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 08 02:38:04 volumio volumio[24117]: Express server listening on port 3000 Feb 08 02:38:04 volumio volumio[24117]: [Metrics] WebUI: 16s 12.64ms Feb 08 02:38:05 volumio volumio[24117]: info: CoreStateMachine::resetVolumioState Feb 08 02:38:05 volumio volumio[24117]: info: CoreStateMachine::getcurrentVolume Feb 08 02:38:05 volumio volumio[24117]: info: CoreCommandRouter::volumioRetrievevolume Feb 08 02:38:05 volumio sudo[24270]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 08 02:38:05 volumio sudo[24270]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 02:38:05 volumio sudo[24270]: pam_unix(sudo:session): session closed for user root Feb 08 02:38:05 volumio sudo[24273]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 08 02:38:05 volumio sudo[24273]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 02:38:05 volumio sudo[24273]: pam_unix(sudo:session): session closed for user root Feb 08 02:38:05 volumio volumio[24117]: info: Volumio Network Manager: Network status updated: 1 Feb 08 02:38:05 volumio volumio[24117]: info: VolumeController:: Volume=100 Mute =false Feb 08 02:38:05 volumio volumio[24117]: info: CoreStateMachine::pushState Feb 08 02:38:05 volumio volumio[24117]: info: CorePlayQueue::getTrack 0 Feb 08 02:38:05 volumio volumio[24117]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 08 02:38:05 volumio volumio[24117]: info: CoreCommandRouter::volumioPushState Feb 08 02:38:05 volumio volumio[24117]: info: CoreStateMachine::updateTrackBlock Feb 08 02:38:05 volumio volumio[24117]: info: CorePlayQueue::getTrackBlock Feb 08 02:38:05 volumio volumio[24117]: info: CoreCommandRouter::volumioRetrievevolume Feb 08 02:38:05 volumio volumio-remote-updater[643]: [2026-02-08 02:38:05] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1770493083 101 Feb 08 02:38:05 volumio volumio[24117]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 1 Feb 08 02:38:05 volumio volumio[24117]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 08 02:38:05 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 33. Feb 08 02:38:05 volumio volumio[24117]: info: Reloading queue from file Feb 08 02:38:05 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 08 02:38:05 volumio volumio[24117]: info: CoreStateMachine::setRepeat null single undefined Feb 08 02:38:05 volumio volumio[24117]: info: CoreStateMachine::pushState Feb 08 02:38:05 volumio volumio[24117]: info: CorePlayQueue::getTrack 0 Feb 08 02:38:05 volumio volumio[24117]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 08 02:38:05 volumio volumio[24117]: info: CoreCommandRouter::volumioPushState Feb 08 02:38:05 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 08 02:38:05 volumio go-librespot[24284]: go-librespot daemon starting... Feb 08 02:38:05 volumio volumio[24117]: info: CoreStateMachine::setRandom null Feb 08 02:38:05 volumio volumio[24117]: info: CoreStateMachine::pushState Feb 08 02:38:05 volumio volumio[24117]: info: CorePlayQueue::getTrack 0 Feb 08 02:38:05 volumio volumio[24117]: info: CoreCommandRouter::volumioPushState Feb 08 02:38:05 volumio volumio[24117]: info: Setting Device type: Raspberry PI Feb 08 02:38:05 volumio go-librespot[24286]: time="2026-02-08T02:38:05+07:00" level=info msg="running go-librespot 0.4.0" Feb 08 02:38:05 volumio go-librespot[24286]: time="2026-02-08T02:38:05+07:00" level=debug msg="app state loaded" Feb 08 02:38:05 volumio go-librespot[24286]: time="2026-02-08T02:38:05+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 08 02:38:06 volumio volumio[24117]: info: Completed loading Core Plugins Feb 08 02:38:06 volumio volumio[24117]: info: Preparing to generate the ALSA configuration file Feb 08 02:38:06 volumio volumio[24117]: info: VolumeController:: Volume=100 Mute =false Feb 08 02:38:06 volumio volumio[24117]: info: CoreStateMachine::pushState Feb 08 02:38:06 volumio volumio[24117]: info: CorePlayQueue::getTrack 0 Feb 08 02:38:06 volumio volumio[24117]: info: CoreCommandRouter::volumioPushState Feb 08 02:38:06 volumio volumio[24117]: info: Asound.conf file unchanged, so no further update is needed Feb 08 02:38:06 volumio volumio[24117]: info: Output device has changed, restarting MPD Feb 08 02:38:06 volumio sudo[24296]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 08 02:38:06 volumio sudo[24296]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 02:38:06 volumio volumio[24117]: info: Output device has changed, restarting Shairport Sync Feb 08 02:38:06 volumio volumio[24117]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 02:38:06 volumio volumio[24117]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 08 02:38:06 volumio sudo[24298]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 08 02:38:06 volumio sudo[24298]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 02:38:06 volumio sudo[24296]: pam_unix(sudo:session): session closed for user root Feb 08 02:38:06 volumio sudo[24298]: pam_unix(sudo:session): session closed for user root Feb 08 02:38:06 volumio sudo[24301]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 08 02:38:06 volumio volumio[24117]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 08 02:38:06 volumio sudo[24301]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 02:38:06 volumio volumio[24117]: info: ___________ START PLUGINS ___________ Feb 08 02:38:06 volumio volumio[24117]: info: ControllerMpd::onStart: Initializing MPD Feb 08 02:38:06 volumio volumio[24117]: info: Creating MPD Configuration file Feb 08 02:38:06 volumio volumio[24117]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 08 02:38:06 volumio volumio[24117]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 08 02:38:06 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 08 02:38:06 volumio volumio[24117]: info: [1770493086635] CoreMusicLibrary::Adding element Media Servers Feb 08 02:38:06 volumio volumio[24117]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 08 02:38:06 volumio go-librespot[24286]: time="2026-02-08T02:38:06+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 08 02:38:06 volumio go-librespot[24286]: time="2026-02-08T02:38:06+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 08 02:38:06 volumio go-librespot[24286]: time="2026-02-08T02:38:06+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 08 02:38:06 volumio volumio[24117]: info: UPNP Browser: Client initialized successfully Feb 08 02:38:06 volumio sudo[24309]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 08 02:38:06 volumio go-librespot[24286]: time="2026-02-08T02:38:06+07:00" level=info msg="zeroconf server listening on port 38287" Feb 08 02:38:06 volumio sudo[24309]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 02:38:06 volumio sudo[24309]: pam_unix(sudo:session): session closed for user root Feb 08 02:38:06 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 08 02:38:06 volumio sudo[24311]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 08 02:38:06 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 08 02:38:06 volumio systemd[1]: mpd.service: Consumed 7.100s CPU time. Feb 08 02:38:06 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 08 02:38:06 volumio sudo[24311]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 02:38:06 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 08 02:38:06 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 08 02:38:06 volumio volumio[24117]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 02:38:06 volumio volumio[24117]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 08 02:38:06 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 08 02:38:06 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 08 02:38:06 volumio volumio[24117]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 08 02:38:06 volumio go-librespot[24286]: time="2026-02-08T02:38:06+07:00" level=debug msg="obtained new client token: AACOARvMXgpRmwBNl1bEyDE9Cajg+GyHlNxEk1ziFpRkYFNF2ziT6ecvvIHSyqZreV4kH8G0z/iOBjKYHQFzC0akRinfZAzFiULQJfgfK0A1m+NANd6xTjw61dWcvuZSPzPIEF83tROrNgoOki0V+Tfy30Vy+WwCplz6g5vNPFjr7LjcyCUkbIlleC6a7bN5FR0UH+qhhwo8RqX1T0Ev3pf19jls7bESUc2589+daTbTUATOCwRXn0sO8g==" Feb 08 02:38:06 volumio volumio[24117]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 02:38:06 volumio volumio[24117]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 08 02:38:06 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 08 02:38:06 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 08 02:38:06 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 08 02:38:06 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 08 02:38:06 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 08 02:38:07 volumio volumio[24117]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 08 02:38:07 volumio volumio[24117]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 08 02:38:07 volumio volumio[24117]: info: [1770493087032] CoreMusicLibrary::Adding element Last_100 Feb 08 02:38:07 volumio volumio[24117]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 08 02:38:07 volumio volumio[24117]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 08 02:38:07 volumio volumio[24117]: info: [1770493087042] CoreMusicLibrary::Adding element Webradio Feb 08 02:38:07 volumio volumio[24117]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 08 02:38:07 volumio volumio[24117]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 08 02:38:07 volumio go-librespot[24286]: time="2026-02-08T02:38:07+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 08 02:38:07 volumio volumio[24117]: info: Initializing BBC Radios Feb 08 02:38:07 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 08 02:38:07 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 08 02:38:07 volumio go-librespot[24286]: time="2026-02-08T02:38:07+07:00" level=debug msg="completed keyexchange" Feb 08 02:38:07 volumio go-librespot[24286]: time="2026-02-08T02:38:07+07:00" level=debug msg="completed challenge" Feb 08 02:38:07 volumio go-librespot[24286]: time="2026-02-08T02:38:07+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 08 02:38:07 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 08 02:38:07 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 08 02:38:07 volumio volumio[24117]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 08 02:38:07 volumio volumio[24117]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 08 02:38:07 volumio volumio[24117]: info: Creating Spotify config file Feb 08 02:38:07 volumio volumio[24117]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 02:38:07 volumio sudo[24327]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 08 02:38:07 volumio sudo[24327]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 08 02:38:07 volumio sudo[24327]: pam_unix(sudo:session): session closed for user root Feb 08 02:38:08 volumio volumio[24238]: Starting albumart workers Feb 08 02:38:08 volumio volumio[24240]: Starting albumart workers Feb 08 02:38:08 volumio volumio[24239]: Starting albumart workers Feb 08 02:38:08 volumio volumio[24117]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 08 02:38:08 volumio volumio[24117]: info: [1770493088576] CoreMusicLibrary::Adding element YouTube Music Feb 08 02:38:08 volumio volumio[24117]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 08 02:38:08 volumio volumio[24117]: Cannot find translation for source YouTube Music Feb 08 02:38:08 volumio volumio[24117]: info: Volumio Calling Home Feb 08 02:38:08 volumio sudo[24342]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Feb 08 02:38:08 volumio sudo[24342]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 02:38:08 volumio sudo[24342]: pam_unix(sudo:session): session closed for user root Feb 08 02:38:09 volumio volumio[24117]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Feb 08 02:38:09 volumio volumio[24117]: info: Discovery: Found device Volumio Feb 08 02:38:09 volumio volumio[24117]: info: CoreCommandRouter::volumioGetState Feb 08 02:38:09 volumio volumio[24117]: info: CorePlayQueue::getTrack 0 Feb 08 02:38:09 volumio volumio[24117]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Feb 08 02:38:09 volumio volumio[24117]: info: Discovery: Found device Volumio Feb 08 02:38:09 volumio volumio[24117]: info: CoreCommandRouter::volumioGetState Feb 08 02:38:09 volumio volumio[24117]: info: CorePlayQueue::getTrack 0 Feb 08 02:38:09 volumio volumio[24117]: info: MPD Permissions set Feb 08 02:38:09 volumio volumio[24117]: info: MPD Permissions set Feb 08 02:38:09 volumio volumio[24117]: info: Upmpdcli Daemon Started Feb 08 02:38:09 volumio volumio[24117]: info: Volumio called home Feb 08 02:38:10 volumio volumio[24117]: info: Spotify config file written Feb 08 02:38:10 volumio sudo[24354]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 08 02:38:10 volumio sudo[24354]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 02:38:10 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 08 02:38:10 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 08 02:38:10 volumio go-librespot[24365]: go-librespot daemon starting... Feb 08 02:38:10 volumio sudo[24354]: pam_unix(sudo:session): session closed for user root Feb 08 02:38:10 volumio go-librespot[24369]: time="2026-02-08T02:38:10+07:00" level=info msg="running go-librespot 0.4.0" Feb 08 02:38:10 volumio go-librespot[24369]: time="2026-02-08T02:38:10+07:00" level=debug msg="app state loaded" Feb 08 02:38:10 volumio go-librespot[24369]: time="2026-02-08T02:38:10+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 08 02:38:10 volumio volumio[24117]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Feb 08 02:38:10 volumio volumio[24117]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 02:38:10 volumio volumio[24117]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 02:38:10 volumio volumio[24117]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 02:38:10 volumio volumio[24117]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 02:38:10 volumio volumio[24117]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 02:38:10 volumio volumio[24117]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 02:38:10 volumio volumio[24117]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 02:38:10 volumio volumio[24117]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 02:38:10 volumio volumio[24117]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 08 02:38:10 volumio volumio[24117]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 02:38:10 volumio volumio[24117]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 02:38:10 volumio volumio[24117]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 02:38:10 volumio volumio[24117]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 02:38:10 volumio volumio[24117]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 02:38:10 volumio volumio[24117]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 02:38:10 volumio volumio[24117]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 02:38:10 volumio volumio[24117]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 02:38:10 volumio volumio[24117]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 02:38:10 volumio volumio[24117]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 08 02:38:10 volumio volumio[24117]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 02:38:10 volumio volumio[24117]: info: No need to fix Spotify hosts Feb 08 02:38:10 volumio go-librespot[24369]: time="2026-02-08T02:38:10+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 08 02:38:10 volumio go-librespot[24369]: time="2026-02-08T02:38:10+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 08 02:38:10 volumio go-librespot[24369]: time="2026-02-08T02:38:10+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 08 02:38:11 volumio go-librespot[24369]: time="2026-02-08T02:38:11+07:00" level=info msg="zeroconf server listening on port 40001" Feb 08 02:38:11 volumio go-librespot[24369]: time="2026-02-08T02:38:11+07:00" level=debug msg="obtained new client token: AACSQulIp5PzEIUtSpYsEVVkXl3ZEnJyqsZJoiyWE+bFBJpbwuW4ckbTZiVXnaFfokk1EtB4M2lSuFJyPnuL5JEerLEigYqYVdtmHADE1UoN7g1ntKanHCRi/pS8BETUAQoDSTQd2p0X6Zjlj8aaBoGpgrxg0qedO8ycqF/ohJeoosdx57dWiD/umxrgv29JyqJZ0J5AaDUvhDqvzrpparLtpvnAcad42Cujn44kIyEusRoc5yYKs5E=" Feb 08 02:38:11 volumio volumio[24117]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 08 02:38:11 volumio volumio[24117]: SPOTIFY: BQASJFsXDjEoEpKADpE6ygmau8fbMLphsU2PE4hB2L8hV0LXmHqoRiwimRmujuIiL8rj7daa_lXV08_lLU283xW9vqisgS9jdEffngse1rrWtFUnN7qFKYmwk7Hyz250WHDtBQKZ7OvKZ14Gn9CEpBhg8PLoLfdIN5xwgEHJr7AMNn4m9fxdKiAz2VP59a4YnLlsofl5r5vpsatw9pehqUOit50VW2AIerqXSDWLkqvQOYUbaFu17vlNLYE0Rdn9fVpW5i7GmGh7iMi8Ylq_GoUsQhOi_QLwU2OXQZFX33v-4rmTPkLze-Qh Feb 08 02:38:11 volumio volumio[24117]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 08 02:38:11 volumio volumio[24117]: info: New Spotify access token = BQASJFsXDjEoEpKADpE6ygmau8fbMLphsU2PE4hB2L8hV0LXmHqoRiwimRmujuIiL8rj7daa_lXV08_lLU283xW9vqisgS9jdEffngse1rrWtFUnN7qFKYmwk7Hyz250WHDtBQKZ7OvKZ14Gn9CEpBhg8PLoLfdIN5xwgEHJr7AMNn4m9fxdKiAz2VP59a4YnLlsofl5r5vpsatw9pehqUOit50VW2AIerqXSDWLkqvQOYUbaFu17vlNLYE0Rdn9fVpW5i7GmGh7iMi8Ylq_GoUsQhOi_QLwU2OXQZFX33v-4rmTPkLze-Qh Feb 08 02:38:11 volumio volumio[24117]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 08 02:38:11 volumio go-librespot[24369]: time="2026-02-08T02:38:11+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 08 02:38:11 volumio volumio[24117]: info: Starting Shairport Sync Feb 08 02:38:11 volumio volumio[24117]: info: Starting Shairport Sync Feb 08 02:38:11 volumio volumio[24117]: info: Starting Shairport Sync Feb 08 02:38:11 volumio sudo[24388]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 08 02:38:11 volumio sudo[24388]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 02:38:11 volumio go-librespot[24369]: time="2026-02-08T02:38:11+07:00" level=debug msg="completed keyexchange" Feb 08 02:38:11 volumio go-librespot[24369]: time="2026-02-08T02:38:11+07:00" level=debug msg="completed challenge" Feb 08 02:38:11 volumio sudo[24390]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 08 02:38:11 volumio sudo[24393]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 08 02:38:11 volumio sudo[24393]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 02:38:11 volumio sudo[24390]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 02:38:11 volumio go-librespot[24369]: time="2026-02-08T02:38:11+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 08 02:38:11 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 08 02:38:11 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 08 02:38:11 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 08 02:38:11 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 08 02:38:11 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 08 02:38:11 volumio systemd[1]: shairport-sync.service: Consumed 2.261s CPU time. Feb 08 02:38:11 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 08 02:38:11 volumio sudo[24388]: pam_unix(sudo:session): session closed for user root Feb 08 02:38:11 volumio sudo[24393]: pam_unix(sudo:session): session closed for user root Feb 08 02:38:11 volumio volumio[24117]: info: CoreCommandRouter::volumioGetState Feb 08 02:38:11 volumio volumio[24117]: info: CorePlayQueue::getTrack 0 Feb 08 02:38:11 volumio sudo[24390]: pam_unix(sudo:session): session closed for user root Feb 08 02:38:11 volumio volumio[24117]: info: Shairport-Sync Started Feb 08 02:38:11 volumio volumio[24117]: Error adding Membership: Error: addMembership EINVAL Feb 08 02:38:11 volumio volumio[24117]: info: Shairport-Sync Started Feb 08 02:38:11 volumio volumio[24117]: info: Shairport-Sync Started Feb 08 02:38:12 volumio volumio[24117]: SPOTIFY: User informations: {"country":"PK","display_name":"215mmgea6kss3jxeqsqdquvji","email":"linh.ngotran@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/215mmgea6kss3jxeqsqdquvji"},"followers":{"href":null,"total":1},"href":"https://api.spotify.com/v1/users/215mmgea6kss3jxeqsqdquvji","id":"215mmgea6kss3jxeqsqdquvji","images":[],"product":"premium","type":"user","uri":"spotify:user:215mmgea6kss3jxeqsqdquvji"} Feb 08 02:38:12 volumio volumio[24117]: info: Spotify Successfully logged in Feb 08 02:38:12 volumio volumio[24117]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 08 02:38:12 volumio volumio[24117]: info: [1770493092190] CoreMusicLibrary::Adding element Spotify Feb 08 02:38:12 volumio volumio[24117]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 08 02:38:12 volumio volumio[24117]: Cannot find translation for source YouTube Music Feb 08 02:38:12 volumio volumio[24117]: Cannot find translation for source Spotify Feb 08 02:38:12 volumio volumio[24117]: info: [yt-cast-receiver] DIAL server listening on port 8098 Feb 08 02:38:12 volumio volumio[24117]: info: CoreCommandRouter::volumioRetrievevolume Feb 08 02:38:13 volumio volumio[24117]: info: VolumeController:: Volume=100 Mute =false Feb 08 02:38:13 volumio volumio[24117]: info: CoreCommandRouter::volumioGetState Feb 08 02:38:13 volumio volumio[24117]: info: CorePlayQueue::getTrack 0 Feb 08 02:38:13 volumio volumio[24117]: info: CoreStateMachine::pushState Feb 08 02:38:13 volumio volumio[24117]: info: CorePlayQueue::getTrack 0 Feb 08 02:38:13 volumio volumio[24117]: info: CoreCommandRouter::volumioPushState Feb 08 02:38:14 volumio volumio[24117]: info: go-librespot daemon successfully initialized Feb 08 02:38:14 volumio mpd[24340]: 2026-02-08T02:38:14 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 08 02:38:14 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 08 02:38:14 volumio sudo[24311]: pam_unix(sudo:session): session closed for user root Feb 08 02:38:14 volumio sudo[24301]: pam_unix(sudo:session): session closed for user root Feb 08 02:38:14 volumio volumio[24117]: error: MPD error: The expression evaluated to a falsy value: Feb 08 02:38:14 volumio volumio[24117]: assert.ok(self.idling) Feb 08 02:38:14 volumio volumio[24117]: error: The expression evaluated to a falsy value: Feb 08 02:38:14 volumio volumio[24117]: assert.ok(self.idling) Feb 08 02:38:14 volumio volumio[24117]: info: MPD running with PID24340 Feb 08 02:38:14 volumio volumio[24117]: ,establishing connection Feb 08 02:38:14 volumio volumio[24117]: error: updateQueue error: null Feb 08 02:38:14 volumio volumio[24117]: info: Completed starting Core Plugins Feb 08 02:38:14 volumio volumio[24117]: info: ------------------------------------------- Feb 08 02:38:14 volumio volumio[24117]: info: ----- MyVolumio plugins startup ---- Feb 08 02:38:14 volumio volumio[24117]: info: ------------------------------------------- Feb 08 02:38:14 volumio volumio[24117]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 08 02:38:14 volumio volumio[24117]: error: updateQueue error: null Feb 08 02:38:14 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 34. Feb 08 02:38:14 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 08 02:38:14 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 08 02:38:14 volumio go-librespot[24432]: go-librespot daemon starting... Feb 08 02:38:14 volumio go-librespot[24433]: time="2026-02-08T02:38:14+07:00" level=info msg="running go-librespot 0.4.0" Feb 08 02:38:14 volumio go-librespot[24433]: time="2026-02-08T02:38:14+07:00" level=debug msg="app state loaded" Feb 08 02:38:14 volumio go-librespot[24433]: time="2026-02-08T02:38:14+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 08 02:38:15 volumio go-librespot[24433]: time="2026-02-08T02:38:15+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 08 02:38:15 volumio go-librespot[24433]: time="2026-02-08T02:38:15+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 08 02:38:15 volumio go-librespot[24433]: time="2026-02-08T02:38:15+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 08 02:38:15 volumio go-librespot[24433]: time="2026-02-08T02:38:15+07:00" level=info msg="zeroconf server listening on port 41175" Feb 08 02:38:15 volumio go-librespot[24433]: time="2026-02-08T02:38:15+07:00" level=debug msg="obtained new client token: AABuSrZQDqH4TCwWda8M9LJQcXmB3sukhI59xthN0yxYe4fBRpgCKJ/3QMo+4fS1KCbuqHXTG8Vo0E0jTJxi7b0gfAXfp8q+Y9cbHNXzfrGQ9gF/xE1PrdX59QbGw6mg2G/pQfoVQoAqrvRgRLHLz5JevdltHFNMfuaYiqX7VIB/h91fCAldfPcDPe0ZEo3XiRbFzCo6m4spnXkQhcG3k8D2POULNUCj46OK1sPU5I8dndJnoAIyAmXplQ==" Feb 08 02:38:15 volumio go-librespot[24433]: time="2026-02-08T02:38:15+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 08 02:38:15 volumio go-librespot[24433]: time="2026-02-08T02:38:15+07:00" level=debug msg="completed keyexchange" Feb 08 02:38:15 volumio go-librespot[24433]: time="2026-02-08T02:38:15+07:00" level=debug msg="completed challenge" Feb 08 02:38:15 volumio go-librespot[24433]: time="2026-02-08T02:38:15+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 08 02:38:15 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 08 02:38:15 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 08 02:38:17 volumio volumio[24117]: info: Initializing connection to go-librespot Websocket Feb 08 02:38:17 volumio volumio[24117]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 08 02:38:19 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 35. Feb 08 02:38:19 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 08 02:38:19 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 08 02:38:19 volumio go-librespot[24441]: go-librespot daemon starting... Feb 08 02:38:19 volumio go-librespot[24442]: time="2026-02-08T02:38:19+07:00" level=info msg="running go-librespot 0.4.0" Feb 08 02:38:19 volumio go-librespot[24442]: time="2026-02-08T02:38:19+07:00" level=debug msg="app state loaded" Feb 08 02:38:19 volumio go-librespot[24442]: time="2026-02-08T02:38:19+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 08 02:38:19 volumio volumio[24117]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 08 02:38:19 volumio go-librespot[24442]: time="2026-02-08T02:38:19+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 08 02:38:19 volumio go-librespot[24442]: time="2026-02-08T02:38:19+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 08 02:38:19 volumio go-librespot[24442]: time="2026-02-08T02:38:19+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 08 02:38:19 volumio go-librespot[24442]: time="2026-02-08T02:38:19+07:00" level=info msg="zeroconf server listening on port 34895" Feb 08 02:38:19 volumio go-librespot[24442]: time="2026-02-08T02:38:19+07:00" level=debug msg="obtained new client token: AADc3BNTOCGa2t3ydd6T6M9iqNFmLd//qOTzi5iZtaoN7HxdCzkZC53fDlAacDC7RdTB5UHZnpx+UBoXev+H6+5wVVttX6vKr+jwWH3kxxhjIqMUf++K/IRm51J1GsTg47Kdy65KwJL+rfv4krLUoTrH5iFcIxe7kSCfLL9uNTJcxTFCc4cz2c+Sr/d1ZBzDblQIRVcy0+W9hUTDqGqvkjy4vBMm4RnkEs7wmcv4GG0YY54rNjL9nXUIfQ==" Feb 08 02:38:20 volumio go-librespot[24442]: time="2026-02-08T02:38:20+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 08 02:38:20 volumio go-librespot[24442]: time="2026-02-08T02:38:20+07:00" level=debug msg="completed keyexchange" Feb 08 02:38:20 volumio go-librespot[24442]: time="2026-02-08T02:38:20+07:00" level=debug msg="completed challenge" Feb 08 02:38:20 volumio volumio[24117]: info: Initializing connection to go-librespot Websocket Feb 08 02:38:20 volumio go-librespot[24442]: time="2026-02-08T02:38:20+07:00" level=debug msg="new websocket client" Feb 08 02:38:20 volumio go-librespot[24442]: time="2026-02-08T02:38:20+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 08 02:38:20 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 08 02:38:20 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 08 02:38:20 volumio volumio[24117]: info: Connection to go-librespot Websocket established Feb 08 02:38:20 volumio volumio[24117]: info: Connection to go-librespot Websocket closed Feb 08 02:38:23 volumio volumio[24117]: info: Getting Spotify volume Feb 08 02:38:23 volumio volumio[24117]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 08 02:38:23 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 36. Feb 08 02:38:23 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 08 02:38:23 volumio volumio[24117]: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 08 02:38:23 volumio volumio[24117]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Feb 08 02:38:23 volumio volumio[24117]: errno: -111, Feb 08 02:38:23 volumio volumio[24117]: code: 'ECONNREFUSED', Feb 08 02:38:23 volumio volumio[24117]: syscall: 'connect', Feb 08 02:38:23 volumio volumio[24117]: address: '127.0.0.1', Feb 08 02:38:23 volumio volumio[24117]: port: 9879, Feb 08 02:38:23 volumio volumio[24117]: response: undefined Feb 08 02:38:23 volumio volumio[24117]: } Feb 08 02:38:23 volumio volumio[24117]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 08 02:38:23 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 08 02:38:23 volumio go-librespot[24449]: go-librespot daemon starting... Feb 08 02:38:23 volumio go-librespot[24453]: time="2026-02-08T02:38:23+07:00" level=info msg="running go-librespot 0.4.0" Feb 08 02:38:23 volumio go-librespot[24453]: time="2026-02-08T02:38:23+07:00" level=debug msg="app state loaded" Feb 08 02:38:23 volumio go-librespot[24453]: time="2026-02-08T02:38:23+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 08 02:38:24 volumio go-librespot[24453]: time="2026-02-08T02:38: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 08 02:38:24 volumio go-librespot[24453]: time="2026-02-08T02:38: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 08 02:38:24 volumio go-librespot[24453]: time="2026-02-08T02:38: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 08 02:38:24 volumio go-librespot[24453]: time="2026-02-08T02:38:24+07:00" level=info msg="zeroconf server listening on port 45003" Feb 08 02:38:24 volumio go-librespot[24453]: time="2026-02-08T02:38:24+07:00" level=debug msg="obtained new client token: AAB0BMtUxi+3CwoGdhOY9N5ExJvzkxS8sLnwCqQO2Uig3/ORUhj4qaO/OvJMVYtAn8tcyzQ8XH233xp0v1H6yBOk0LIqg7xZE9mQrSji/j5WLvTJPGIWhUpbFN3+gcRe11u+dODrXUJ5XRTg7gPt78KWAbtLw1j7EhHR9UqQ4AjSKJNLusYeiLVlMpt7sTjWc8H9X9Hm7Aqdf8/2awqg/D76P+FsJVaSUsmxmnGyxgGBE2TgKJxH3oY=" Feb 08 02:38:24 volumio go-librespot[24453]: time="2026-02-08T02:38:24+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 08 02:38:24 volumio go-librespot[24453]: time="2026-02-08T02:38:24+07:00" level=debug msg="completed keyexchange" Feb 08 02:38:24 volumio go-librespot[24453]: time="2026-02-08T02:38:24+07:00" level=debug msg="completed challenge" Feb 08 02:38:24 volumio go-librespot[24453]: time="2026-02-08T02:38:24+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 08 02:38:24 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 08 02:38:24 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 08 02:38:24 volumio sudo[24485]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-08 02:37' Feb 08 02:38:24 volumio sudo[24485]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 02:38:25 volumio sudo[24485]: pam_unix(sudo:session): session closed for user root Feb 08 02:38:25 volumio volumio-remote-updater[643]: [2026-02-08 02:38:25] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Feb 08 02:38:25 volumio volumio-remote-updater[643]: [2026-02-08 02:38:25] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Feb 08 02:38:25 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Feb 08 02:38:25 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Feb 08 02:38:25 volumio systemd[1]: volumio.service: Consumed 49.326s CPU time. Feb 08 02:38:25 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 08 02:38:25 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 08 02:38:25 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 6673. Feb 08 02:38:25 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 08 02:38:25 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Feb 08 02:38:25 volumio systemd[1]: volumio.service: Consumed 49.326s CPU time. Feb 08 02:38:25 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Feb 08 02:38:25 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 08 02:38:27 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 37. Feb 08 02:38:27 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 08 02:38:27 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 08 02:38:27 volumio go-librespot[24519]: go-librespot daemon starting... Feb 08 02:38:27 volumio go-librespot[24520]: time="2026-02-08T02:38:27+07:00" level=info msg="running go-librespot 0.4.0" Feb 08 02:38:27 volumio go-librespot[24520]: time="2026-02-08T02:38:27+07:00" level=debug msg="app state loaded" Feb 08 02:38:27 volumio go-librespot[24520]: time="2026-02-08T02:38:27+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 08 02:38:28 volumio go-librespot[24520]: time="2026-02-08T02:38: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-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 08 02:38:28 volumio go-librespot[24520]: time="2026-02-08T02:38:28+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 08 02:38:28 volumio go-librespot[24520]: time="2026-02-08T02:38:28+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 08 02:38:28 volumio go-librespot[24520]: time="2026-02-08T02:38:28+07:00" level=info msg="zeroconf server listening on port 34997" Feb 08 02:38:28 volumio go-librespot[24520]: time="2026-02-08T02:38:28+07:00" level=debug msg="obtained new client token: AAC0QYL5zpZI9/mcIMjL2FMNBvoR5edtCPKspfOoShcHDadmsRHgClrgfJU6/McZqhG8vA/mMMMt/my+om1J1wFqIVYwJdZeAN4NYrkRSp3aY/cIjxAmdleU/M+7bZyJ2lrCqFvYtaTnxsZ5sLvMVYvNKYRp35pS9pKlXsXKJaBjhDBdUVzMHWYDGb+BgjHwLuET6cuRDQcVLswicX5tF7SLxUcimt/xVw/Zfe/N2qr4l0Q1stYrA0jUFA==" Feb 08 02:38:28 volumio go-librespot[24520]: time="2026-02-08T02:38:28+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 08 02:38:28 volumio go-librespot[24520]: time="2026-02-08T02:38:28+07:00" level=debug msg="completed keyexchange" Feb 08 02:38:28 volumio go-librespot[24520]: time="2026-02-08T02:38:28+07:00" level=debug msg="completed challenge" Feb 08 02:38:28 volumio go-librespot[24520]: time="2026-02-08T02:38:28+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 08 02:38:28 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 08 02:38:28 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 08 02:38:29 volumio volumio[24504]: info: ------------------------------------------- Feb 08 02:38:29 volumio volumio[24504]: info: ----- Volumio3 ---- Feb 08 02:38:29 volumio volumio[24504]: info: ------------------------------------------- Feb 08 02:38:29 volumio volumio[24504]: info: ----- System startup ---- Feb 08 02:38:29 volumio volumio[24504]: info: ------------------------------------------- Feb 08 02:38:30 volumio volumio-remote-updater[643]: [2026-02-08 02:38:30] [connect] Successful connection Feb 08 02:38:30 volumio volumio[24504]: info: MYVOLUMIO Environment detected Feb 08 02:38:30 volumio volumio[24504]: info: Plugin folders cleanup Feb 08 02:38:30 volumio volumio[24504]: info: Scanning into folder /volumio/app/plugins/ Feb 08 02:38:30 volumio volumio[24504]: info: Scanning category audio_interface Feb 08 02:38:30 volumio volumio[24504]: info: Scanning category miscellanea Feb 08 02:38:30 volumio volumio[24504]: info: Scanning category music_service Feb 08 02:38:30 volumio volumio[24504]: info: Scanning category plugins.json Feb 08 02:38:30 volumio volumio[24504]: info: Scanning category system_controller Feb 08 02:38:30 volumio volumio[24504]: info: Scanning category user_interface Feb 08 02:38:30 volumio volumio[24504]: info: Scanning into folder /data/plugins/ Feb 08 02:38:30 volumio volumio[24504]: info: Scanning category music_service Feb 08 02:38:30 volumio volumio[24504]: info: Plugin folders cleanup completed Feb 08 02:38:30 volumio volumio[24504]: info: ------------------------------------------- Feb 08 02:38:30 volumio volumio[24504]: info: ----- Core plugins startup ---- Feb 08 02:38:30 volumio volumio[24504]: info: ------------------------------------------- Feb 08 02:38:30 volumio volumio[24504]: info: Loading plugins from folder /volumio/app/plugins/ Feb 08 02:38:30 volumio volumio[24504]: info: Adding plugin upnp to MyMusic Plugins Feb 08 02:38:30 volumio volumio[24504]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 08 02:38:30 volumio volumio[24504]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 08 02:38:30 volumio volumio[24504]: info: Loading plugins from folder /data/plugins/ Feb 08 02:38:30 volumio volumio[24504]: info: Loading plugin "system"... Feb 08 02:38:30 volumio volumio[24504]: info: Loading plugin "appearance"... Feb 08 02:38:32 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 38. Feb 08 02:38:32 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 08 02:38:32 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 08 02:38:32 volumio go-librespot[24539]: go-librespot daemon starting... Feb 08 02:38:32 volumio go-librespot[24540]: time="2026-02-08T02:38:32+07:00" level=info msg="running go-librespot 0.4.0" Feb 08 02:38:32 volumio go-librespot[24540]: time="2026-02-08T02:38:32+07:00" level=debug msg="app state loaded" Feb 08 02:38:32 volumio go-librespot[24540]: time="2026-02-08T02:38:32+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 08 02:38:32 volumio go-librespot[24540]: time="2026-02-08T02:38:32+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 08 02:38:32 volumio go-librespot[24540]: time="2026-02-08T02:38:32+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 08 02:38:32 volumio go-librespot[24540]: time="2026-02-08T02:38:32+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 08 02:38:32 volumio go-librespot[24540]: time="2026-02-08T02:38:32+07:00" level=info msg="zeroconf server listening on port 40109" Feb 08 02:38:32 volumio volumio[24504]: info: Loading plugin "network"... Feb 08 02:38:32 volumio volumio[24504]: info: Refreshing Cached IP Addresses Feb 08 02:38:32 volumio go-librespot[24540]: time="2026-02-08T02:38:32+07:00" level=debug msg="obtained new client token: AAAgSLcmHVEAhJH7OKcdV8TqCOpLsCXACDvs5lnYhnC9KrG3W0v4Eb4XIkQY+OX92zdJXkwWocAIbLk8y3JvoXl4BlmB3819PMlWrM1GPxXqojlRPPzu22HVUnuYsrlBpUwytnjsjytG604vqgtpeMa/GGaZ2glQ0UBM2/M9xoY+DFT7phjA8nzPWQmyBn7ZfDZrM/BOOXVrX/3EvQ2lsdJPARSIiqgREOIAcVYWI3i9CNPzhN8jnMjtag==" Feb 08 02:38:33 volumio sudo[24551]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 08 02:38:33 volumio sudo[24551]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 02:38:33 volumio volumio[24504]: info: Loading plugin "services"... Feb 08 02:38:33 volumio sudo[24549]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 08 02:38:33 volumio sudo[24549]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 02:38:33 volumio volumio[24504]: info: Loading plugin "alsa_controller"... Feb 08 02:38:33 volumio sudo[24549]: pam_unix(sudo:session): session closed for user root Feb 08 02:38:33 volumio sudo[24551]: pam_unix(sudo:session): session closed for user root Feb 08 02:38:33 volumio sudo[24558]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 08 02:38:33 volumio sudo[24558]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 02:38:33 volumio go-librespot[24540]: time="2026-02-08T02:38:33+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 08 02:38:33 volumio volumio[24504]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 08 02:38:33 volumio volumio[24504]: info: Loading plugin "wizard"... Feb 08 02:38:33 volumio volumio[24504]: info: Loading plugin "networkfs"... Feb 08 02:38:33 volumio go-librespot[24540]: time="2026-02-08T02:38:33+07:00" level=debug msg="completed keyexchange" Feb 08 02:38:33 volumio go-librespot[24540]: time="2026-02-08T02:38:33+07:00" level=debug msg="completed challenge" Feb 08 02:38:33 volumio volumio[24504]: info: Starting Udev Watcher for removable devices Feb 08 02:38:33 volumio go-librespot[24540]: time="2026-02-08T02:38:33+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 08 02:38:33 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 08 02:38:33 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 08 02:38:33 volumio volumio[24504]: info: Ignoring mount for partition: boot Feb 08 02:38:33 volumio volumio[24504]: info: Ignoring mount for partition: volumio Feb 08 02:38:33 volumio volumio[24504]: info: Ignoring mount for partition: volumio_data Feb 08 02:38:33 volumio volumio[24504]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 08 02:38:33 volumio volumio[24504]: info: Loading plugin "volumio_command_line_client"... Feb 08 02:38:33 volumio volumio[24504]: info: Loading plugin "upnp"... Feb 08 02:38:33 volumio volumio[24504]: info: [1770493113346] Starting Upmpd Daemon Feb 08 02:38:33 volumio volumio[24504]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 08 02:38:33 volumio volumio[24504]: info: Loading plugin "my_music"... Feb 08 02:38:33 volumio volumio[24504]: info: Loading plugin "mpd"... Feb 08 02:38:34 volumio volumio[24504]: info: Loading plugin "upnp_browser"... Feb 08 02:38:35 volumio sudo[24558]: pam_unix(sudo:session): session closed for user root Feb 08 02:38:36 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 39. Feb 08 02:38:36 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 08 02:38:36 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 08 02:38:36 volumio go-librespot[24583]: go-librespot daemon starting... Feb 08 02:38:36 volumio go-librespot[24584]: time="2026-02-08T02:38:36+07:00" level=info msg="running go-librespot 0.4.0" Feb 08 02:38:36 volumio go-librespot[24584]: time="2026-02-08T02:38:36+07:00" level=debug msg="app state loaded" Feb 08 02:38:36 volumio go-librespot[24584]: time="2026-02-08T02:38:36+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 08 02:38:36 volumio volumio[24504]: info: Starting UPNP Browser Feb 08 02:38:36 volumio volumio[24504]: info: Loading plugin "alarm-clock"... Feb 08 02:38:37 volumio go-librespot[24584]: time="2026-02-08T02:38:37+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 08 02:38:37 volumio go-librespot[24584]: time="2026-02-08T02:38:37+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 08 02:38:37 volumio go-librespot[24584]: time="2026-02-08T02:38:37+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 08 02:38:37 volumio go-librespot[24584]: time="2026-02-08T02:38:37+07:00" level=info msg="zeroconf server listening on port 38715" Feb 08 02:38:37 volumio volumio[24504]: info: Loading plugin "airplay_emulation"... Feb 08 02:38:37 volumio volumio[24504]: info: Starting Shairport Sync Feb 08 02:38:37 volumio volumio[24504]: info: Loading plugin "last_100"... Feb 08 02:38:37 volumio volumio[24504]: info: Loading plugin "webradio"... Feb 08 02:38:37 volumio go-librespot[24584]: time="2026-02-08T02:38:37+07:00" level=debug msg="obtained new client token: AADYK2gLO2e9CDis/onEYkRRltK4dJOR8mkFpqMOimXfHL3zJ2m59BkSpS3dRQIQyw7mRBj6zPDrEam/mzILPu1s0mZNT/4MmxUDDkV7ApIyEkSWU14/fnO9eEFfbLplsz7mpO2GosFMVFsApKvf2W1rc0EZGzSksYcxX6djI6e/uV9kqYdSWCDFvt3Zr+q4uriwuWy5dzPUeLSgKtYgIiIZXjrOJ/AQ8WKJAK9V1WSCBQsNK9Cf7VbcIA==" Feb 08 02:38:37 volumio volumio[24504]: info: Loading plugin "i2s_dacs"... Feb 08 02:38:37 volumio volumio[24504]: info: Loading plugin "volumiodiscovery"... Feb 08 02:38:37 volumio go-librespot[24584]: time="2026-02-08T02:38:37+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 08 02:38:37 volumio volumio[24504]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 08 02:38:37 volumio volumio[24504]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 08 02:38:37 volumio volumio[24504]: *** WARNING *** For more information see Feb 08 02:38:37 volumio volumio[24504]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 08 02:38:37 volumio volumio[24504]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 08 02:38:37 volumio volumio[24504]: *** WARNING *** For more information see Feb 08 02:38:37 volumio node[24504]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 08 02:38:37 volumio node[24504]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 08 02:38:37 volumio node[24504]: *** WARNING *** For more information see Feb 08 02:38:37 volumio node[24504]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 08 02:38:37 volumio node[24504]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 08 02:38:37 volumio node[24504]: *** WARNING *** For more information see Feb 08 02:38:37 volumio volumio[24504]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 08 02:38:37 volumio volumio[24504]: info: Discovery: Started advertising with name: Volumio Feb 08 02:38:37 volumio volumio[24504]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 08 02:38:37 volumio volumio[24504]: info: Loading plugin "spop"... Feb 08 02:38:37 volumio go-librespot[24584]: time="2026-02-08T02:38:37+07:00" level=debug msg="completed keyexchange" Feb 08 02:38:37 volumio go-librespot[24584]: time="2026-02-08T02:38:37+07:00" level=debug msg="completed challenge" Feb 08 02:38:37 volumio go-librespot[24584]: time="2026-02-08T02:38:37+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 08 02:38:37 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 08 02:38:37 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 08 02:38:39 volumio volumio[24504]: info: Loading plugin "ytcr"... Feb 08 02:38:41 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 40. Feb 08 02:38:41 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 08 02:38:41 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 08 02:38:41 volumio go-librespot[24593]: go-librespot daemon starting... Feb 08 02:38:41 volumio go-librespot[24594]: time="2026-02-08T02:38:41+07:00" level=info msg="running go-librespot 0.4.0" Feb 08 02:38:41 volumio go-librespot[24594]: time="2026-02-08T02:38:41+07:00" level=debug msg="app state loaded" Feb 08 02:38:41 volumio go-librespot[24594]: time="2026-02-08T02:38:41+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 08 02:38:41 volumio go-librespot[24594]: time="2026-02-08T02:38:41+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 08 02:38:41 volumio go-librespot[24594]: time="2026-02-08T02:38:41+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 08 02:38:41 volumio go-librespot[24594]: time="2026-02-08T02:38:41+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 08 02:38:41 volumio go-librespot[24594]: time="2026-02-08T02:38:41+07:00" level=info msg="zeroconf server listening on port 46753" Feb 08 02:38:41 volumio go-librespot[24594]: time="2026-02-08T02:38:41+07:00" level=debug msg="obtained new client token: AABRVxVb6QY0Arwnt1vzg/QqPwN8p+bh9twXyav/Go3CG5Z6TIvBZ9cRe3EAlo8NMlVFXbe3wFHZrzMhhpAa9wuJP6wx5e4JipXhYO3qmjDPqnogkIFAdbrwT3OD3A07UYH1SRCmB6l8KzcEm1wuJeqr42P48KnTmyKR/AivX6aa4xXZywsvSz9Ms8MqpVuwt8fK3hS2tdoCK5BVlAN/KPRGdle7zwCt745EAlqwUA+9KUu/QEpNXJeyPQ==" Feb 08 02:38:42 volumio go-librespot[24594]: time="2026-02-08T02:38:42+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 08 02:38:42 volumio go-librespot[24594]: time="2026-02-08T02:38:42+07:00" level=debug msg="completed keyexchange" Feb 08 02:38:42 volumio go-librespot[24594]: time="2026-02-08T02:38:42+07:00" level=debug msg="completed challenge" Feb 08 02:38:42 volumio go-librespot[24594]: time="2026-02-08T02:38: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 08 02:38:42 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 08 02:38:42 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 08 02:38:42 volumio volumio[24504]: info: Loading plugin "ytmusic"... Feb 08 02:38:42 volumio volumio-remote-updater[643]: [2026-02-08 02:38:42] [connect] Successful connection Feb 08 02:38:43 volumio volumio[24504]: info: Loading plugin "outputs"... Feb 08 02:38:43 volumio volumio[24504]: info: Loading plugin "albumart"... Feb 08 02:38:43 volumio volumio[24504]: info: Plugin example_plugin is not enabled Feb 08 02:38:43 volumio volumio[24504]: info: Loading plugin "inputs"... Feb 08 02:38:43 volumio volumio[24504]: info: Loading plugin "updater_comm"... Feb 08 02:38:43 volumio volumio[24504]: info: Plugin mpdemulation is not enabled Feb 08 02:38:43 volumio volumio[24504]: info: Loading plugin "rest_api"... Feb 08 02:38:43 volumio volumio[24504]: info: Loading plugin "websocket"... Feb 08 02:38:43 volumio volumio[24504]: info: Starting Socket.io Server version 1.7.4 Feb 08 02:38:43 volumio volumio[24504]: info: Loading plugin "RoonBridge"... Feb 08 02:38:44 volumio volumio[24504]: info: Applying required configuration parameters for plugin RoonBridge Feb 08 02:38:44 volumio volumio[24504]: info: Loading i18n strings for locale en Feb 08 02:38:44 volumio volumio[24504]: Updating browse sources language Feb 08 02:38:44 volumio volumio[24504]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 08 02:38:44 volumio volumio[24504]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 08 02:38:44 volumio volumio[24504]: info: CoreCommandRouter::initPlayerControls Feb 08 02:38:44 volumio volumio[24504]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 02:38:44 volumio volumio[24504]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 02:38:44 volumio volumio[24504]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 02:38:44 volumio volumio[24504]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 02:38:44 volumio volumio[24504]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 02:38:44 volumio volumio[24504]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 02:38:44 volumio volumio[24504]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 02:38:44 volumio volumio[24504]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 02:38:44 volumio volumio[24504]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 08 02:38:44 volumio volumio[24504]: Express server listening on port 3000 Feb 08 02:38:44 volumio volumio[24504]: [Metrics] WebUI: 16s 138.85ms Feb 08 02:38:44 volumio volumio[24615]: Forking 3 albumart workers Feb 08 02:38:44 volumio volumio[24504]: info: CoreStateMachine::resetVolumioState Feb 08 02:38:44 volumio volumio[24504]: info: CoreStateMachine::getcurrentVolume Feb 08 02:38:44 volumio volumio[24504]: info: CoreCommandRouter::volumioRetrievevolume Feb 08 02:38:44 volumio sudo[24633]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 08 02:38:44 volumio sudo[24633]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 02:38:44 volumio sudo[24633]: pam_unix(sudo:session): session closed for user root Feb 08 02:38:44 volumio sudo[24643]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 08 02:38:44 volumio sudo[24643]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 02:38:44 volumio sudo[24643]: pam_unix(sudo:session): session closed for user root Feb 08 02:38:44 volumio volumio[24504]: info: Volumio Network Manager: Network status updated: 1 Feb 08 02:38:45 volumio volumio[24504]: info: VolumeController:: Volume=100 Mute =false Feb 08 02:38:45 volumio volumio[24504]: info: CoreStateMachine::pushState Feb 08 02:38:45 volumio volumio[24504]: info: CorePlayQueue::getTrack 0 Feb 08 02:38:45 volumio volumio[24504]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 08 02:38:45 volumio volumio[24504]: info: CoreCommandRouter::volumioPushState Feb 08 02:38:45 volumio volumio[24504]: info: CoreStateMachine::updateTrackBlock Feb 08 02:38:45 volumio volumio[24504]: info: CorePlayQueue::getTrackBlock Feb 08 02:38:45 volumio volumio[24504]: info: CoreCommandRouter::volumioRetrievevolume Feb 08 02:38:45 volumio volumio-remote-updater[643]: [2026-02-08 02:38:45] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1770493122 101 Feb 08 02:38:45 volumio volumio[24504]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 1 Feb 08 02:38:45 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 41. Feb 08 02:38:45 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 08 02:38:45 volumio volumio[24504]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 08 02:38:45 volumio volumio[24504]: info: Reloading queue from file Feb 08 02:38:45 volumio volumio[24504]: info: CoreStateMachine::setRepeat null single undefined Feb 08 02:38:45 volumio volumio[24504]: info: CoreStateMachine::pushState Feb 08 02:38:45 volumio volumio[24504]: info: CorePlayQueue::getTrack 0 Feb 08 02:38:45 volumio volumio[24504]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 08 02:38:45 volumio volumio[24504]: info: CoreCommandRouter::volumioPushState Feb 08 02:38:45 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 08 02:38:45 volumio go-librespot[24671]: go-librespot daemon starting... Feb 08 02:38:45 volumio volumio[24504]: info: CoreStateMachine::setRandom null Feb 08 02:38:45 volumio volumio[24504]: info: CoreStateMachine::pushState Feb 08 02:38:45 volumio volumio[24504]: info: CorePlayQueue::getTrack 0 Feb 08 02:38:45 volumio volumio[24504]: info: CoreCommandRouter::volumioPushState Feb 08 02:38:45 volumio go-librespot[24673]: time="2026-02-08T02:38:45+07:00" level=info msg="running go-librespot 0.4.0" Feb 08 02:38:45 volumio go-librespot[24673]: time="2026-02-08T02:38:45+07:00" level=debug msg="app state loaded" Feb 08 02:38:45 volumio volumio[24504]: info: Setting Device type: Raspberry PI Feb 08 02:38:45 volumio go-librespot[24673]: time="2026-02-08T02:38:45+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 08 02:38:45 volumio volumio[24504]: info: Completed loading Core Plugins Feb 08 02:38:45 volumio volumio[24504]: info: Preparing to generate the ALSA configuration file Feb 08 02:38:45 volumio volumio[24504]: info: VolumeController:: Volume=100 Mute =false Feb 08 02:38:45 volumio volumio[24504]: info: CoreStateMachine::pushState Feb 08 02:38:45 volumio volumio[24504]: info: CorePlayQueue::getTrack 0 Feb 08 02:38:45 volumio volumio[24504]: info: CoreCommandRouter::volumioPushState Feb 08 02:38:45 volumio volumio[24504]: info: Asound.conf file unchanged, so no further update is needed Feb 08 02:38:45 volumio volumio[24504]: info: Output device has changed, restarting MPD Feb 08 02:38:45 volumio volumio[24504]: info: Output device has changed, restarting Shairport Sync Feb 08 02:38:45 volumio volumio[24504]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 02:38:45 volumio volumio[24504]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 08 02:38:45 volumio sudo[24682]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 08 02:38:45 volumio sudo[24682]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 02:38:45 volumio sudo[24684]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 08 02:38:45 volumio sudo[24684]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 02:38:45 volumio volumio[24504]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 08 02:38:46 volumio sudo[24684]: pam_unix(sudo:session): session closed for user root Feb 08 02:38:46 volumio volumio[24504]: info: ___________ START PLUGINS ___________ Feb 08 02:38:46 volumio sudo[24682]: pam_unix(sudo:session): session closed for user root Feb 08 02:38:46 volumio volumio[24504]: info: ControllerMpd::onStart: Initializing MPD Feb 08 02:38:46 volumio sudo[24686]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 08 02:38:46 volumio sudo[24686]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 02:38:46 volumio volumio[24504]: info: Creating MPD Configuration file Feb 08 02:38:46 volumio volumio[24504]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 08 02:38:46 volumio volumio[24504]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 08 02:38:46 volumio volumio[24504]: info: [1770493126166] CoreMusicLibrary::Adding element Media Servers Feb 08 02:38:46 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 08 02:38:46 volumio volumio[24504]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 08 02:38:46 volumio sudo[24697]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 08 02:38:46 volumio sudo[24697]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 02:38:46 volumio go-librespot[24673]: time="2026-02-08T02:38:46+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 08 02:38:46 volumio go-librespot[24673]: time="2026-02-08T02:38:46+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 08 02:38:46 volumio go-librespot[24673]: time="2026-02-08T02:38:46+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 08 02:38:46 volumio sudo[24697]: pam_unix(sudo:session): session closed for user root Feb 08 02:38:46 volumio go-librespot[24673]: time="2026-02-08T02:38:46+07:00" level=info msg="zeroconf server listening on port 35813" Feb 08 02:38:46 volumio volumio[24504]: info: UPNP Browser: Client initialized successfully Feb 08 02:38:46 volumio sudo[24699]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 08 02:38:46 volumio sudo[24699]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 02:38:46 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 08 02:38:46 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 08 02:38:46 volumio systemd[1]: mpd.service: Consumed 7.074s CPU time. Feb 08 02:38:46 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 08 02:38:46 volumio volumio[24504]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 02:38:46 volumio volumio[24504]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 08 02:38:46 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 08 02:38:46 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 08 02:38:46 volumio volumio[24504]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 08 02:38:46 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 08 02:38:46 volumio volumio[24504]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 02:38:46 volumio volumio[24504]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 08 02:38:46 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 08 02:38:46 volumio go-librespot[24673]: time="2026-02-08T02:38:46+07:00" level=debug msg="obtained new client token: AADG/T4QbaOnHrVsqH6tWKQdWxwBB4DCU+ZFxBRKLxF1B8HYiC3Yoe5SLK6RcLDtNo2c4HZpX6pJV/i7xrRKXe/mHNFv3V8EhCx3G8q+IbdveBfE3gw+nXV065ssfqxVrF0d9cP0JrN6DJot46Y/vouzgZ2dw0+Vh2/Sjh0JHN92PI16Ld9LKn3aQ6VIR9WPr9XYV7kqj9QTH7RnKecwla4vbiuYljbMFEMDMGSYevYltxoAS4d0Wddnbg==" Feb 08 02:38:46 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 08 02:38:46 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 08 02:38:46 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 08 02:38:46 volumio volumio[24504]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 08 02:38:46 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 08 02:38:46 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 08 02:38:46 volumio volumio[24504]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 08 02:38:46 volumio volumio[24504]: info: [1770493126573] CoreMusicLibrary::Adding element Last_100 Feb 08 02:38:46 volumio volumio[24504]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 08 02:38:46 volumio volumio[24504]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 08 02:38:46 volumio volumio[24504]: info: [1770493126593] CoreMusicLibrary::Adding element Webradio Feb 08 02:38:46 volumio volumio[24504]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 08 02:38:46 volumio go-librespot[24673]: time="2026-02-08T02:38:46+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 08 02:38:46 volumio volumio[24504]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 08 02:38:46 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 08 02:38:46 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 08 02:38:46 volumio volumio[24504]: info: Initializing BBC Radios Feb 08 02:38:46 volumio go-librespot[24673]: time="2026-02-08T02:38:46+07:00" level=debug msg="completed keyexchange" Feb 08 02:38:46 volumio go-librespot[24673]: time="2026-02-08T02:38:46+07:00" level=debug msg="completed challenge" Feb 08 02:38:46 volumio go-librespot[24673]: time="2026-02-08T02:38:46+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 08 02:38:46 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 08 02:38:46 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 08 02:38:46 volumio volumio[24504]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 08 02:38:46 volumio volumio[24504]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 08 02:38:46 volumio volumio[24504]: info: Creating Spotify config file Feb 08 02:38:46 volumio volumio[24504]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 02:38:47 volumio sudo[24714]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 08 02:38:47 volumio sudo[24714]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 08 02:38:47 volumio sudo[24714]: pam_unix(sudo:session): session closed for user root Feb 08 02:38:47 volumio volumio[24629]: Starting albumart workers Feb 08 02:38:47 volumio volumio[24504]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 08 02:38:47 volumio volumio[24504]: info: [1770493127977] CoreMusicLibrary::Adding element YouTube Music Feb 08 02:38:47 volumio volumio[24504]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 08 02:38:47 volumio volumio[24504]: Cannot find translation for source YouTube Music Feb 08 02:38:48 volumio volumio[24504]: info: Volumio Calling Home Feb 08 02:38:48 volumio volumio[24630]: Starting albumart workers Feb 08 02:38:48 volumio sudo[24731]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Feb 08 02:38:48 volumio sudo[24731]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 02:38:48 volumio sudo[24731]: pam_unix(sudo:session): session closed for user root Feb 08 02:38:48 volumio volumio[24631]: Starting albumart workers Feb 08 02:38:48 volumio volumio[24504]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Feb 08 02:38:48 volumio volumio[24504]: info: Discovery: Found device Volumio Feb 08 02:38:48 volumio volumio[24504]: info: CoreCommandRouter::volumioGetState Feb 08 02:38:48 volumio volumio[24504]: info: CorePlayQueue::getTrack 0 Feb 08 02:38:48 volumio volumio[24504]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Feb 08 02:38:48 volumio volumio[24504]: info: Discovery: Found device Volumio Feb 08 02:38:48 volumio volumio[24504]: info: CoreCommandRouter::volumioGetState Feb 08 02:38:48 volumio volumio[24504]: info: CorePlayQueue::getTrack 0 Feb 08 02:38:48 volumio volumio[24504]: info: MPD Permissions set Feb 08 02:38:48 volumio volumio[24504]: info: MPD Permissions set Feb 08 02:38:48 volumio volumio[24504]: info: Upmpdcli Daemon Started Feb 08 02:38:49 volumio volumio[24504]: info: Volumio called home Feb 08 02:38:49 volumio volumio[24504]: info: Spotify config file written Feb 08 02:38:49 volumio sudo[24737]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 08 02:38:49 volumio sudo[24737]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 02:38:49 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 08 02:38:49 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 08 02:38:49 volumio go-librespot[24740]: go-librespot daemon starting... Feb 08 02:38:49 volumio sudo[24737]: pam_unix(sudo:session): session closed for user root Feb 08 02:38:49 volumio go-librespot[24746]: time="2026-02-08T02:38:49+07:00" level=info msg="running go-librespot 0.4.0" Feb 08 02:38:49 volumio go-librespot[24746]: time="2026-02-08T02:38:49+07:00" level=debug msg="app state loaded" Feb 08 02:38:49 volumio go-librespot[24746]: time="2026-02-08T02:38:49+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 08 02:38:49 volumio volumio[24504]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Feb 08 02:38:50 volumio volumio[24504]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 02:38:50 volumio volumio[24504]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 02:38:50 volumio volumio[24504]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 02:38:50 volumio volumio[24504]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 02:38:50 volumio volumio[24504]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 02:38:50 volumio volumio[24504]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 02:38:50 volumio volumio[24504]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 02:38:50 volumio volumio[24504]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 02:38:50 volumio volumio[24504]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 08 02:38:50 volumio volumio[24504]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 02:38:50 volumio volumio[24504]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 02:38:50 volumio volumio[24504]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 02:38:50 volumio volumio[24504]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 02:38:50 volumio volumio[24504]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 02:38:50 volumio volumio[24504]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 02:38:50 volumio volumio[24504]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 02:38:50 volumio volumio[24504]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 02:38:50 volumio volumio[24504]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 02:38:50 volumio volumio[24504]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 08 02:38:50 volumio volumio[24504]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 02:38:50 volumio volumio[24504]: info: No need to fix Spotify hosts Feb 08 02:38:50 volumio go-librespot[24746]: time="2026-02-08T02:38: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-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 08 02:38:50 volumio go-librespot[24746]: time="2026-02-08T02:38:50+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 08 02:38:50 volumio go-librespot[24746]: time="2026-02-08T02:38:50+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 08 02:38:50 volumio go-librespot[24746]: time="2026-02-08T02:38:50+07:00" level=info msg="zeroconf server listening on port 44569" Feb 08 02:38:50 volumio go-librespot[24746]: time="2026-02-08T02:38:50+07:00" level=debug msg="obtained new client token: AACqVGWsvrZcTeR9Ks8BLewD2bx8rXhes9Y1lXQLt/c8wGMqu8KSnAEHj8qxfBfpwv9oaIomg0GdSRbeTKAIbCEu7E2/dcLQOEKwdr9Uw/zMl/brtaPeWw8JgAgL5T5DOGRCcZzj4O8sTOkJT41VNFB5FrAiideBVRGzvM9JHBVQn1lfpxZ1WE6ZVY0z8o7ZG7yjOpCuWdDxncAma94bD9iVmwrU4X9FaqE4AaWck/4hajUCtmu2qFoZcA==" Feb 08 02:38:50 volumio go-librespot[24746]: time="2026-02-08T02:38:50+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 08 02:38:50 volumio volumio[24504]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 08 02:38:50 volumio volumio[24504]: SPOTIFY: BQALiZi_lqDJ4BCdghrwijWyDCEIpXrCvmChVkkDU3XBND0L4drkdiPIBU81DZKvIEw2kn7D-7rnaujRNiFHHF9phI4XisYP4AZW6nYOkk0fztK7GKoDnQdz8SLgojaVQo16UrxH1RcDjeeJADpwtMubM2vdgpAkIC1KbPnVrfnMdAhADr2U9DfATPeNeJhPUvvVywF6we76BdNm0KqUcEqjIEa-INjf4vm-0HlaqZ7_fJchKp_NIoC9IZSS6Czt_Q91jHn42jWlYHQb3nPNupgU6qWDHfc8SaWRfVJLzBxzhbRW7p2XDJZ7 Feb 08 02:38:50 volumio volumio[24504]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 08 02:38:50 volumio volumio[24504]: info: New Spotify access token = BQALiZi_lqDJ4BCdghrwijWyDCEIpXrCvmChVkkDU3XBND0L4drkdiPIBU81DZKvIEw2kn7D-7rnaujRNiFHHF9phI4XisYP4AZW6nYOkk0fztK7GKoDnQdz8SLgojaVQo16UrxH1RcDjeeJADpwtMubM2vdgpAkIC1KbPnVrfnMdAhADr2U9DfATPeNeJhPUvvVywF6we76BdNm0KqUcEqjIEa-INjf4vm-0HlaqZ7_fJchKp_NIoC9IZSS6Czt_Q91jHn42jWlYHQb3nPNupgU6qWDHfc8SaWRfVJLzBxzhbRW7p2XDJZ7 Feb 08 02:38:50 volumio volumio[24504]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 08 02:38:50 volumio go-librespot[24746]: time="2026-02-08T02:38:50+07:00" level=debug msg="completed keyexchange" Feb 08 02:38:50 volumio go-librespot[24746]: time="2026-02-08T02:38:50+07:00" level=debug msg="completed challenge" Feb 08 02:38:50 volumio volumio[24504]: info: Starting Shairport Sync Feb 08 02:38:50 volumio go-librespot[24746]: time="2026-02-08T02:38:50+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 08 02:38:50 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 08 02:38:50 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 08 02:38:50 volumio volumio[24504]: info: Starting Shairport Sync Feb 08 02:38:51 volumio volumio[24504]: info: Starting Shairport Sync Feb 08 02:38:51 volumio sudo[24777]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 08 02:38:51 volumio sudo[24777]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 02:38:51 volumio sudo[24779]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 08 02:38:51 volumio sudo[24779]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 02:38:51 volumio sudo[24782]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 08 02:38:51 volumio sudo[24782]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 02:38:51 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 08 02:38:51 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 08 02:38:51 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 08 02:38:51 volumio systemd[1]: shairport-sync.service: Consumed 2.182s CPU time. Feb 08 02:38:51 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 08 02:38:51 volumio sudo[24779]: pam_unix(sudo:session): session closed for user root Feb 08 02:38:51 volumio sudo[24782]: pam_unix(sudo:session): session closed for user root Feb 08 02:38:51 volumio sudo[24777]: pam_unix(sudo:session): session closed for user root Feb 08 02:38:51 volumio volumio[24504]: info: CoreCommandRouter::volumioGetState Feb 08 02:38:51 volumio volumio[24504]: info: CorePlayQueue::getTrack 0 Feb 08 02:38:51 volumio volumio[24504]: info: Shairport-Sync Started Feb 08 02:38:51 volumio volumio[24504]: Error adding Membership: Error: addMembership EINVAL Feb 08 02:38:51 volumio volumio[24504]: info: Shairport-Sync Started Feb 08 02:38:51 volumio volumio[24504]: info: Shairport-Sync Started Feb 08 02:38:51 volumio volumio[24504]: SPOTIFY: User informations: {"country":"PK","display_name":"215mmgea6kss3jxeqsqdquvji","email":"linh.ngotran@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/215mmgea6kss3jxeqsqdquvji"},"followers":{"href":null,"total":1},"href":"https://api.spotify.com/v1/users/215mmgea6kss3jxeqsqdquvji","id":"215mmgea6kss3jxeqsqdquvji","images":[],"product":"premium","type":"user","uri":"spotify:user:215mmgea6kss3jxeqsqdquvji"} Feb 08 02:38:51 volumio volumio[24504]: info: Spotify Successfully logged in Feb 08 02:38:51 volumio volumio[24504]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 08 02:38:51 volumio volumio[24504]: info: [1770493131786] CoreMusicLibrary::Adding element Spotify Feb 08 02:38:51 volumio volumio[24504]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 08 02:38:51 volumio volumio[24504]: Cannot find translation for source YouTube Music Feb 08 02:38:51 volumio volumio[24504]: Cannot find translation for source Spotify Feb 08 02:38:52 volumio volumio[24504]: info: [yt-cast-receiver] DIAL server listening on port 8098 Feb 08 02:38:52 volumio volumio[24504]: info: CoreCommandRouter::volumioRetrievevolume Feb 08 02:38:52 volumio volumio[24504]: info: VolumeController:: Volume=100 Mute =false Feb 08 02:38:52 volumio volumio[24504]: info: CoreCommandRouter::volumioGetState Feb 08 02:38:52 volumio volumio[24504]: info: CorePlayQueue::getTrack 0 Feb 08 02:38:52 volumio volumio[24504]: info: CoreStateMachine::pushState Feb 08 02:38:52 volumio volumio[24504]: info: CorePlayQueue::getTrack 0 Feb 08 02:38:52 volumio volumio[24504]: info: CoreCommandRouter::volumioPushState Feb 08 02:38:53 volumio volumio[24504]: info: go-librespot daemon successfully initialized Feb 08 02:38:54 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 42. Feb 08 02:38:54 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 08 02:38:54 volumio mpd[24729]: 2026-02-08T02:38:54 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 08 02:38:54 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 08 02:38:54 volumio go-librespot[24818]: go-librespot daemon starting... Feb 08 02:38:54 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 08 02:38:54 volumio sudo[24699]: pam_unix(sudo:session): session closed for user root Feb 08 02:38:54 volumio sudo[24686]: pam_unix(sudo:session): session closed for user root Feb 08 02:38:54 volumio go-librespot[24821]: time="2026-02-08T02:38:54+07:00" level=info msg="running go-librespot 0.4.0" Feb 08 02:38:54 volumio go-librespot[24821]: time="2026-02-08T02:38:54+07:00" level=debug msg="app state loaded" Feb 08 02:38:54 volumio go-librespot[24821]: time="2026-02-08T02:38:54+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 08 02:38:54 volumio volumio[24504]: error: MPD error: The expression evaluated to a falsy value: Feb 08 02:38:54 volumio volumio[24504]: assert.ok(self.idling) Feb 08 02:38:54 volumio volumio[24504]: error: The expression evaluated to a falsy value: Feb 08 02:38:54 volumio volumio[24504]: assert.ok(self.idling) Feb 08 02:38:54 volumio volumio[24504]: error: updateQueue error: null Feb 08 02:38:54 volumio volumio[24504]: info: Completed starting Core Plugins Feb 08 02:38:54 volumio volumio[24504]: info: ------------------------------------------- Feb 08 02:38:54 volumio volumio[24504]: info: ----- MyVolumio plugins startup ---- Feb 08 02:38:54 volumio volumio[24504]: info: ------------------------------------------- Feb 08 02:38:54 volumio volumio[24504]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 08 02:38:54 volumio volumio[24504]: info: MPD running with PID24729 Feb 08 02:38:54 volumio volumio[24504]: ,establishing connection Feb 08 02:38:54 volumio volumio[24504]: error: updateQueue error: null Feb 08 02:38:54 volumio go-librespot[24821]: time="2026-02-08T02:38:54+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 08 02:38:54 volumio go-librespot[24821]: time="2026-02-08T02:38:54+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 08 02:38:54 volumio go-librespot[24821]: time="2026-02-08T02:38:54+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 08 02:38:54 volumio go-librespot[24821]: time="2026-02-08T02:38:54+07:00" level=info msg="zeroconf server listening on port 34857" Feb 08 02:38:54 volumio go-librespot[24821]: time="2026-02-08T02:38:54+07:00" level=debug msg="obtained new client token: AACaCKYroamk94goHnZEtDMgK1W0LAXXFzTjNNtR0zqXPcV+xWRDChDXwas6UbefgI0G3w2co9fdOrJbXdd+evkNvQbHRmqDEF3ap7Cm5q3+z5bcpquXAGth5GxFMY/5PQhuoQ/L3jKXKKSHtVpOwgUzsDTTvZHwEdRhBQtFdmhIkvwlyjhBZdQTTs/pgws4fJ7aTD93ydlYKTKezUruz1fF74V9YG+ueAiQeE+l5Fsh2ojC0acp4Xgv3g==" Feb 08 02:38:55 volumio go-librespot[24821]: time="2026-02-08T02:38:55+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 08 02:38:55 volumio go-librespot[24821]: time="2026-02-08T02:38:55+07:00" level=debug msg="completed keyexchange" Feb 08 02:38:55 volumio go-librespot[24821]: time="2026-02-08T02:38:55+07:00" level=debug msg="completed challenge" Feb 08 02:38:55 volumio go-librespot[24821]: time="2026-02-08T02:38: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 08 02:38:55 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 08 02:38:55 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 08 02:38:56 volumio volumio[24504]: info: Initializing connection to go-librespot Websocket Feb 08 02:38:56 volumio volumio[24504]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 08 02:38:58 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 43. Feb 08 02:38:58 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 08 02:38:58 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 08 02:38:58 volumio go-librespot[24833]: go-librespot daemon starting... Feb 08 02:38:58 volumio go-librespot[24834]: time="2026-02-08T02:38:58+07:00" level=info msg="running go-librespot 0.4.0" Feb 08 02:38:58 volumio go-librespot[24834]: time="2026-02-08T02:38:58+07:00" level=debug msg="app state loaded" Feb 08 02:38:58 volumio go-librespot[24834]: time="2026-02-08T02:38:58+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 08 02:38:58 volumio go-librespot[24834]: time="2026-02-08T02:38:58+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 08 02:38:58 volumio go-librespot[24834]: time="2026-02-08T02:38:58+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 08 02:38:58 volumio go-librespot[24834]: time="2026-02-08T02:38:58+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 08 02:38:58 volumio go-librespot[24834]: time="2026-02-08T02:38:58+07:00" level=info msg="zeroconf server listening on port 38333" Feb 08 02:38:59 volumio go-librespot[24834]: time="2026-02-08T02:38:59+07:00" level=debug msg="obtained new client token: AADl3PQUocc2/7UAQG7ApV9jds8nhqm0r2KJl55slUTjH5I8JB2AfJd7d9JaUUMMxj7w/FMlM13jqpCCofGujvyXZimzNnJ9bshyBYir0o5jQq6aQX4v2ptDqRwxzEE+2GHva/uQl4+NxesRUcDQYE9B645iKdl9q1mOusUjvrppsAukPNXqB8FtYA0zvkZSCeJ1vrYf9zTeokrkplrW/vH+tviOfokK77zxdQLzVkG2kVuSIN+7lQM=" Feb 08 02:38:59 volumio volumio[24504]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 08 02:38:59 volumio go-librespot[24834]: time="2026-02-08T02:38:59+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 08 02:38:59 volumio go-librespot[24834]: time="2026-02-08T02:38:59+07:00" level=debug msg="completed keyexchange" Feb 08 02:38:59 volumio go-librespot[24834]: time="2026-02-08T02:38:59+07:00" level=debug msg="completed challenge" Feb 08 02:38:59 volumio go-librespot[24834]: time="2026-02-08T02:38:59+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 08 02:38:59 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 08 02:38:59 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 08 02:38:59 volumio volumio[24504]: info: Initializing connection to go-librespot Websocket Feb 08 02:38:59 volumio volumio[24504]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 08 02:39:02 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 44. Feb 08 02:39:02 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 08 02:39:02 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 08 02:39:02 volumio go-librespot[24842]: go-librespot daemon starting... Feb 08 02:39:02 volumio go-librespot[24843]: time="2026-02-08T02:39:02+07:00" level=info msg="running go-librespot 0.4.0" Feb 08 02:39:02 volumio go-librespot[24843]: time="2026-02-08T02:39:02+07:00" level=debug msg="app state loaded" Feb 08 02:39:02 volumio go-librespot[24843]: time="2026-02-08T02:39:02+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 08 02:39:02 volumio volumio[24504]: info: Initializing connection to go-librespot Websocket Feb 08 02:39:02 volumio go-librespot[24843]: time="2026-02-08T02:39:02+07:00" level=debug msg="new websocket client" Feb 08 02:39:02 volumio volumio[24504]: info: Connection to go-librespot Websocket established Feb 08 02:39:03 volumio go-librespot[24843]: time="2026-02-08T02:39:03+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 08 02:39:03 volumio go-librespot[24843]: time="2026-02-08T02:39:03+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 08 02:39:03 volumio go-librespot[24843]: time="2026-02-08T02:39:03+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 08 02:39:03 volumio go-librespot[24843]: time="2026-02-08T02:39:03+07:00" level=info msg="zeroconf server listening on port 39847" Feb 08 02:39:03 volumio volumio[24504]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 08 02:39:03 volumio volumio[24504]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 08 02:39:03 volumio volumio[24504]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 08 02:39:03 volumio volumio[24504]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 08 02:39:03 volumio volumio[24504]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 08 02:39:03 volumio volumio[24504]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 08 02:39:03 volumio volumio[24504]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 08 02:39:03 volumio volumio[24504]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 08 02:39:03 volumio volumio[24504]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 08 02:39:03 volumio volumio[24504]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 08 02:39:03 volumio volumio[24504]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 08 02:39:03 volumio volumio[24504]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 08 02:39:03 volumio volumio[24504]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 08 02:39:03 volumio volumio[24504]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 08 02:39:03 volumio volumio[24504]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 08 02:39:03 volumio volumio[24504]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 08 02:39:03 volumio volumio[24504]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 08 02:39:03 volumio volumio[24504]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 08 02:39:03 volumio volumio[24504]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 08 02:39:03 volumio volumio[24504]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 08 02:39:03 volumio volumio[24504]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 08 02:39:03 volumio volumio[24504]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 08 02:39:03 volumio volumio[24504]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 08 02:39:03 volumio volumio[24504]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 08 02:39:03 volumio volumio[24504]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 08 02:39:03 volumio volumio[24504]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 08 02:39:03 volumio volumio[24504]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 08 02:39:03 volumio volumio[24504]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 08 02:39:03 volumio volumio[24504]: info: Adding plugin bluetooth to MyMusic Plugins Feb 08 02:39:03 volumio volumio[24504]: info: Adding plugin multiroom to MyMusic Plugins Feb 08 02:39:03 volumio volumio[24504]: info: Adding plugin metavolumio to MyMusic Plugins Feb 08 02:39:03 volumio volumio[24504]: info: Adding plugin cd_controller to MyMusic Plugins Feb 08 02:39:03 volumio volumio[24504]: info: Adding plugin qobuzconnect to MyMusic Plugins Feb 08 02:39:03 volumio volumio[24504]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 08 02:39:03 volumio volumio[24504]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 08 02:39:03 volumio volumio[24504]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 08 02:39:03 volumio go-librespot[24843]: time="2026-02-08T02:39:03+07:00" level=debug msg="obtained new client token: AAB6+V9ZTKG1HJpH28GfJHIJY9esyioi+SYhYztpn+tSM3nEwOtDOjCnEC/k2B3XY5BAmcjTN7P88dX3Vfh/n5+eCvu+rWyqsoDK1hDIO0c67Q7JV/R9xYMTO7eH+vgMBgMwvpemhJmab5BIlfJ0qK19pylTIfHGCT2Fa9w6N5Fhe3FLbF9exNsIHKGvlJQi+EdDdLjtm02IzdRGhpfbNL0a9l2zVoUwn8U5A67JJbYl7FMb7ozguPmyeQ==" Feb 08 02:39:03 volumio go-librespot[24843]: time="2026-02-08T02:39:03+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 08 02:39:03 volumio go-librespot[24843]: time="2026-02-08T02:39:03+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Feb 08 02:39:03 volumio go-librespot[24843]: time="2026-02-08T02:39:03+07:00" level=debug msg="completed keyexchange" Feb 08 02:39:03 volumio go-librespot[24843]: time="2026-02-08T02:39:03+07:00" level=debug msg="completed challenge" Feb 08 02:39:03 volumio go-librespot[24843]: time="2026-02-08T02:39:03+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 08 02:39:03 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 08 02:39:03 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 08 02:39:05 volumio volumio[24504]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 08 02:39:05 volumio volumio[24504]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 08 02:39:05 volumio volumio[24504]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 08 02:39:05 volumio volumio[24504]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 08 02:39:05 volumio volumio[24504]: info: Starting MyVolumio Remote Streaming Endpoints Feb 08 02:39:05 volumio volumio[24504]: info: MyVolumio login type: Token Feb 08 02:39:05 volumio volumio[24504]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 08 02:39:05 volumio volumio[24504]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 08 02:39:06 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 45. Feb 08 02:39:06 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 08 02:39:06 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 08 02:39:06 volumio go-librespot[24864]: go-librespot daemon starting... Feb 08 02:39:06 volumio go-librespot[24865]: time="2026-02-08T02:39:06+07:00" level=info msg="running go-librespot 0.4.0" Feb 08 02:39:06 volumio go-librespot[24865]: time="2026-02-08T02:39:06+07:00" level=debug msg="app state loaded" Feb 08 02:39:06 volumio go-librespot[24865]: time="2026-02-08T02:39:06+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 08 02:39:07 volumio volumio[24504]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 08 02:39:07 volumio volumio[24504]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 08 02:39:07 volumio volumio[24504]: info: Streaming services startup Feb 08 02:39:07 volumio volumio[24504]: info: Starting Streaming Daemon Feb 08 02:39:07 volumio sudo[24873]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 08 02:39:07 volumio sudo[24873]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 02:39:07 volumio volumio[24504]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 08 02:39:07 volumio sudo[24873]: pam_unix(sudo:session): session closed for user root Feb 08 02:39:07 volumio volumio[24504]: info: Getting Spotify volume Feb 08 02:39:07 volumio volumio[24504]: info: Connection to go-librespot Websocket closed Feb 08 02:39:07 volumio volumio[24504]: error: Cannot start Volumio Streaming Daemon Feb 08 02:39:07 volumio volumio[24504]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 08 02:39:07 volumio volumio[24504]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 08 02:39:07 volumio volumio[24504]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Feb 08 02:39:07 volumio go-librespot[24865]: time="2026-02-08T02:39:07+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 08 02:39:07 volumio go-librespot[24865]: time="2026-02-08T02:39: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 08 02:39:07 volumio go-librespot[24865]: time="2026-02-08T02:39: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 08 02:39:07 volumio go-librespot[24865]: time="2026-02-08T02:39:07+07:00" level=info msg="zeroconf server listening on port 33663" Feb 08 02:39:07 volumio volumio[24504]: info: CoreCommandRouter::volumioGetState Feb 08 02:39:07 volumio volumio[24504]: info: CorePlayQueue::getTrack 0 Feb 08 02:39:07 volumio volumio[24504]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Feb 08 02:39:07 volumio volumio[24504]: SPOTIFY: SPOTIFY VOLUME undefined Feb 08 02:39:07 volumio volumio[24504]: SPOTIFY: VOLUMIO VOLUME 100 Feb 08 02:39:07 volumio volumio[24504]: info: Aligning Spotify Volume to Volumio Volume Feb 08 02:39:07 volumio volumio[24504]: info: CoreCommandRouter::volumioGetState Feb 08 02:39:07 volumio volumio[24504]: info: CorePlayQueue::getTrack 0 Feb 08 02:39:07 volumio volumio[24504]: info: Setting Spotify Volume from Volumio: 100 Feb 08 02:39:07 volumio go-librespot[24865]: time="2026-02-08T02:39:07+07:00" level=debug msg="obtained new client token: AABtrINFBMqHEVP24k923V53rwAGcZXbUyqRe/H4nJZBfDdxHTmnvyjqpVWJ7bch0VyUhyFd8/5a4eWOgTLlZ9N3d/hF7CdMzu328VI9nwfjsRYzXewTfz2thRJavtKU3y0Nb1x55xVJzupOpg/4dcybHPxZj6xnm/zoT88a/AIhQbNGrvim0r1w939t88B4Q/tKh+Uk378/pCRBgYZ0V7ZiX5mJoeoOesFoCYrrcbg/99wONFShDkC+pg==" Feb 08 02:39:07 volumio go-librespot[24865]: time="2026-02-08T02:39:07+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 08 02:39:07 volumio go-librespot[24865]: time="2026-02-08T02:39:07+07:00" level=debug msg="completed keyexchange" Feb 08 02:39:07 volumio go-librespot[24865]: time="2026-02-08T02:39:07+07:00" level=debug msg="completed challenge" Feb 08 02:39:07 volumio go-librespot[24865]: time="2026-02-08T02:39:07+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 08 02:39:08 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 08 02:39:08 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 08 02:39:08 volumio volumio[24504]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 08 02:39:08 volumio volumio[24504]: Error: socket hang up Feb 08 02:39:08 volumio volumio[24504]: at connResetException (node:internal/errors:720:14) Feb 08 02:39:08 volumio volumio[24504]: at Socket.socketOnEnd (node:_http_client:519:23) Feb 08 02:39:08 volumio volumio[24504]: at Socket.emit (node:events:526:35) Feb 08 02:39:08 volumio volumio[24504]: at endReadableNT (node:internal/streams/readable:1376:12) Feb 08 02:39:08 volumio volumio[24504]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Feb 08 02:39:08 volumio volumio[24504]: code: 'ECONNRESET', Feb 08 02:39:08 volumio volumio[24504]: response: undefined Feb 08 02:39:08 volumio volumio[24504]: } Feb 08 02:39:08 volumio volumio[24504]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 08 02:39:09 volumio sudo[24893]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-08 02:38' Feb 08 02:39:09 volumio sudo[24893]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 02:39:09 volumio sudo[24893]: pam_unix(sudo:session): session closed for user root Feb 08 02:39:11 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 46. Feb 08 02:39:11 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 08 02:39:11 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 08 02:39:11 volumio go-librespot[24901]: go-librespot daemon starting... Feb 08 02:39:11 volumio go-librespot[24902]: time="2026-02-08T02:39:11+07:00" level=info msg="running go-librespot 0.4.0" Feb 08 02:39:11 volumio go-librespot[24902]: time="2026-02-08T02:39:11+07:00" level=debug msg="app state loaded" Feb 08 02:39:11 volumio go-librespot[24902]: time="2026-02-08T02:39:11+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 08 02:39:11 volumio volumio-remote-updater[643]: [2026-02-08 02:39:11] [error] handle_read_frame error: asio.system:104 (Connection reset by peer) Feb 08 02:39:11 volumio volumio-remote-updater[643]: [2026-02-08 02:39:11] [disconnect] Disconnect close local:[1006,Connection reset by peer] remote:[1006] Feb 08 02:39:11 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Feb 08 02:39:11 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Feb 08 02:39:11 volumio systemd[1]: volumio.service: Consumed 55.651s CPU time. Feb 08 02:39:11 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 08 02:39:11 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 08 02:39:11 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 6674. Feb 08 02:39:11 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 08 02:39:11 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Feb 08 02:39:11 volumio systemd[1]: volumio.service: Consumed 55.651s CPU time. Feb 08 02:39:11 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Feb 08 02:39:11 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 08 02:39:11 volumio go-librespot[24902]: time="2026-02-08T02:39:11+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 08 02:39:11 volumio go-librespot[24902]: time="2026-02-08T02:39: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 08 02:39:11 volumio go-librespot[24902]: time="2026-02-08T02:39: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 08 02:39:11 volumio go-librespot[24902]: time="2026-02-08T02:39:11+07:00" level=info msg="zeroconf server listening on port 33541" Feb 08 02:39:11 volumio go-librespot[24902]: time="2026-02-08T02:39:11+07:00" level=debug msg="obtained new client token: AABLP3EkmErmhBcB8QZ+5UkYZGY32CdehqB4A488w3jtCmcEVsQJ6CGe+427u5/Uh2dGffnHsrL24SOX2VlUwMpYvGWTNXugb2KgHi6UBpEGhG+DL2bVmLM2j9scwKnoaUhAzv1v0puNIaFmFyE4Kdwf6tqrFoNJ4bCTK7N9kzh3krQmZVco50u/URV9PNkNgLn/4yXzD917Vp+oKDqqYWrXUoHvszVJu3FoO8yxNkpQyB38IlJqGtbqJA==" Feb 08 02:39:12 volumio go-librespot[24902]: time="2026-02-08T02:39:12+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 08 02:39:12 volumio go-librespot[24902]: time="2026-02-08T02:39:12+07:00" level=debug msg="completed keyexchange" Feb 08 02:39:12 volumio go-librespot[24902]: time="2026-02-08T02:39:12+07:00" level=debug msg="completed challenge" Feb 08 02:39:12 volumio go-librespot[24902]: time="2026-02-08T02:39:12+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 08 02:39:12 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 08 02:39:12 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 08 02:39:15 volumio volumio[24915]: info: ------------------------------------------- Feb 08 02:39:15 volumio volumio[24915]: info: ----- Volumio3 ---- Feb 08 02:39:15 volumio volumio[24915]: info: ------------------------------------------- Feb 08 02:39:15 volumio volumio[24915]: info: ----- System startup ---- Feb 08 02:39:15 volumio volumio[24915]: info: ------------------------------------------- Feb 08 02:39:15 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 47. Feb 08 02:39:15 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 08 02:39:15 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 08 02:39:15 volumio go-librespot[24939]: go-librespot daemon starting... Feb 08 02:39:15 volumio go-librespot[24940]: time="2026-02-08T02:39:15+07:00" level=info msg="running go-librespot 0.4.0" Feb 08 02:39:15 volumio go-librespot[24940]: time="2026-02-08T02:39:15+07:00" level=debug msg="app state loaded" Feb 08 02:39:15 volumio go-librespot[24940]: time="2026-02-08T02:39:15+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 08 02:39:15 volumio go-librespot[24940]: time="2026-02-08T02:39: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 08 02:39:15 volumio go-librespot[24940]: time="2026-02-08T02:39:15+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 08 02:39:15 volumio go-librespot[24940]: time="2026-02-08T02:39:15+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 08 02:39:15 volumio go-librespot[24940]: time="2026-02-08T02:39:15+07:00" level=info msg="zeroconf server listening on port 39819" Feb 08 02:39:16 volumio go-librespot[24940]: time="2026-02-08T02:39:16+07:00" level=debug msg="obtained new client token: AAAVc8hUnyv9HH4mKHme/RBZrrKFXuFz7mwg0L9murz4Ji3E/9bYVidjkwhIA7uWk3kKrZhGh9xNlDcFgfxsqFD/VWWhRsAHXKfGzZhMpxC/Ztrb8QtaOn/LnNXmtfZNLKc772HlO6dZa0m424GR2eqncMvRKXVzNNI9vPIhnBCIyJCgXvkA+cRuj8UOpgh9uW4FXq45i8+knjOzzJb0a1EvwmnNEJwl5cg7d2dbB5s13iR+hg/Ai3E=" Feb 08 02:39:16 volumio volumio-remote-updater[643]: [2026-02-08 02:39:16] [connect] Successful connection Feb 08 02:39:16 volumio go-librespot[24940]: time="2026-02-08T02:39:16+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 08 02:39:16 volumio go-librespot[24940]: time="2026-02-08T02:39:16+07:00" level=debug msg="completed keyexchange" Feb 08 02:39:16 volumio go-librespot[24940]: time="2026-02-08T02:39:16+07:00" level=debug msg="completed challenge" Feb 08 02:39:16 volumio go-librespot[24940]: time="2026-02-08T02:39:16+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 08 02:39:16 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 08 02:39:16 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 08 02:39:16 volumio volumio[24915]: info: MYVOLUMIO Environment detected Feb 08 02:39:16 volumio volumio[24915]: info: Plugin folders cleanup Feb 08 02:39:16 volumio volumio[24915]: info: Scanning into folder /volumio/app/plugins/ Feb 08 02:39:16 volumio volumio[24915]: info: Scanning category audio_interface Feb 08 02:39:16 volumio volumio[24915]: info: Scanning category miscellanea Feb 08 02:39:16 volumio volumio[24915]: info: Scanning category music_service Feb 08 02:39:16 volumio volumio[24915]: info: Scanning category plugins.json Feb 08 02:39:16 volumio volumio[24915]: info: Scanning category system_controller Feb 08 02:39:16 volumio volumio[24915]: info: Scanning category user_interface Feb 08 02:39:16 volumio volumio[24915]: info: Scanning into folder /data/plugins/ Feb 08 02:39:16 volumio volumio[24915]: info: Scanning category music_service Feb 08 02:39:16 volumio volumio[24915]: info: Plugin folders cleanup completed Feb 08 02:39:16 volumio volumio[24915]: info: ------------------------------------------- Feb 08 02:39:16 volumio volumio[24915]: info: ----- Core plugins startup ---- Feb 08 02:39:16 volumio volumio[24915]: info: ------------------------------------------- Feb 08 02:39:16 volumio volumio[24915]: info: Loading plugins from folder /volumio/app/plugins/ Feb 08 02:39:16 volumio volumio[24915]: info: Adding plugin upnp to MyMusic Plugins Feb 08 02:39:16 volumio volumio[24915]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 08 02:39:16 volumio volumio[24915]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 08 02:39:16 volumio volumio[24915]: info: Loading plugins from folder /data/plugins/ Feb 08 02:39:16 volumio volumio[24915]: info: Loading plugin "system"... Feb 08 02:39:16 volumio volumio[24915]: info: Loading plugin "appearance"... Feb 08 02:39:18 volumio volumio[24915]: info: Loading plugin "network"... Feb 08 02:39:18 volumio volumio[24915]: info: Refreshing Cached IP Addresses Feb 08 02:39:18 volumio sudo[24956]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 08 02:39:18 volumio sudo[24956]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 02:39:18 volumio sudo[24958]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 08 02:39:18 volumio sudo[24958]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 02:39:18 volumio volumio[24915]: info: Loading plugin "services"... Feb 08 02:39:18 volumio volumio[24915]: info: Loading plugin "alsa_controller"... Feb 08 02:39:18 volumio sudo[24956]: pam_unix(sudo:session): session closed for user root Feb 08 02:39:18 volumio sudo[24958]: pam_unix(sudo:session): session closed for user root Feb 08 02:39:18 volumio sudo[24965]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 08 02:39:18 volumio sudo[24965]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 02:39:18 volumio volumio[24915]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 08 02:39:18 volumio volumio[24915]: info: Loading plugin "wizard"... Feb 08 02:39:18 volumio volumio[24915]: info: Loading plugin "networkfs"... Feb 08 02:39:19 volumio volumio[24915]: info: Starting Udev Watcher for removable devices Feb 08 02:39:19 volumio volumio[24915]: info: Ignoring mount for partition: boot Feb 08 02:39:19 volumio volumio[24915]: info: Ignoring mount for partition: volumio Feb 08 02:39:19 volumio volumio[24915]: info: Ignoring mount for partition: volumio_data Feb 08 02:39:19 volumio volumio[24915]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 08 02:39:19 volumio volumio[24915]: info: Loading plugin "volumio_command_line_client"... Feb 08 02:39:19 volumio volumio[24915]: info: Loading plugin "upnp"... Feb 08 02:39:19 volumio volumio[24915]: info: [1770493159103] Starting Upmpd Daemon Feb 08 02:39:19 volumio volumio[24915]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 08 02:39:19 volumio volumio[24915]: info: Loading plugin "my_music"... Feb 08 02:39:19 volumio volumio[24915]: info: Loading plugin "mpd"... Feb 08 02:39:19 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 48. Feb 08 02:39:19 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 08 02:39:19 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 08 02:39:19 volumio go-librespot[24989]: go-librespot daemon starting... Feb 08 02:39:19 volumio go-librespot[24990]: time="2026-02-08T02:39:19+07:00" level=info msg="running go-librespot 0.4.0" Feb 08 02:39:19 volumio go-librespot[24990]: time="2026-02-08T02:39:19+07:00" level=debug msg="app state loaded" Feb 08 02:39:19 volumio go-librespot[24990]: time="2026-02-08T02:39:19+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 08 02:39:19 volumio volumio[24915]: info: Loading plugin "upnp_browser"... Feb 08 02:39:20 volumio go-librespot[24990]: time="2026-02-08T02:39:20+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 08 02:39:20 volumio go-librespot[24990]: time="2026-02-08T02:39:20+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 08 02:39:20 volumio go-librespot[24990]: time="2026-02-08T02:39:20+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 08 02:39:20 volumio go-librespot[24990]: time="2026-02-08T02:39:20+07:00" level=info msg="zeroconf server listening on port 35015" Feb 08 02:39:20 volumio go-librespot[24990]: time="2026-02-08T02:39:20+07:00" level=debug msg="obtained new client token: AAA6IIsqcHibHY09OJ+C26rrrHYcZl+k2Qk/TJDlHdiDMOEiaV/UA0GhpjExX6m3YcZApAgBptmnbhuEgvcB2Oz4oaeAjdWwS9pYDH5NF6qBGSdW9vlBFoSLnoDkisdiDoFKsQBob7OrvWGv+wiQ1wp1iGj7uaDUzH+T6ZUcv3qp4cLGBQyt4GVsCLQrrAJXFVx52zHjBNaXSDC7JcNllYk989N3wWRD/MCD3vca2w844aSWZseboGelyg==" Feb 08 02:39:20 volumio go-librespot[24990]: time="2026-02-08T02:39:20+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 08 02:39:20 volumio go-librespot[24990]: time="2026-02-08T02:39:20+07:00" level=debug msg="completed keyexchange" Feb 08 02:39:20 volumio go-librespot[24990]: time="2026-02-08T02:39:20+07:00" level=debug msg="completed challenge" Feb 08 02:39:20 volumio go-librespot[24990]: time="2026-02-08T02:39:20+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 08 02:39:20 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 08 02:39:20 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 08 02:39:21 volumio sudo[24965]: pam_unix(sudo:session): session closed for user root Feb 08 02:39:22 volumio volumio[24915]: info: Starting UPNP Browser Feb 08 02:39:22 volumio volumio[24915]: info: Loading plugin "alarm-clock"... Feb 08 02:39:23 volumio volumio[24915]: info: Loading plugin "airplay_emulation"... Feb 08 02:39:23 volumio volumio[24915]: info: Starting Shairport Sync Feb 08 02:39:23 volumio volumio[24915]: info: Loading plugin "last_100"... Feb 08 02:39:23 volumio volumio[24915]: info: Loading plugin "webradio"... Feb 08 02:39:23 volumio volumio[24915]: info: Loading plugin "i2s_dacs"... Feb 08 02:39:23 volumio volumio[24915]: info: Loading plugin "volumiodiscovery"... Feb 08 02:39:23 volumio volumio[24915]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 08 02:39:23 volumio volumio[24915]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 08 02:39:23 volumio node[24915]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 08 02:39:23 volumio volumio[24915]: *** WARNING *** For more information see Feb 08 02:39:23 volumio volumio[24915]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 08 02:39:23 volumio volumio[24915]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 08 02:39:23 volumio volumio[24915]: *** WARNING *** For more information see Feb 08 02:39:23 volumio node[24915]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 08 02:39:23 volumio node[24915]: *** WARNING *** For more information see Feb 08 02:39:23 volumio node[24915]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 08 02:39:23 volumio node[24915]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 08 02:39:23 volumio node[24915]: *** WARNING *** For more information see Feb 08 02:39:23 volumio volumio[24915]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 08 02:39:23 volumio volumio[24915]: info: Discovery: Started advertising with name: Volumio Feb 08 02:39:23 volumio volumio[24915]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 08 02:39:23 volumio volumio[24915]: info: Loading plugin "spop"... Feb 08 02:39:23 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 49. Feb 08 02:39:23 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 08 02:39:23 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 08 02:39:23 volumio go-librespot[24999]: go-librespot daemon starting... Feb 08 02:39:23 volumio go-librespot[25000]: time="2026-02-08T02:39:23+07:00" level=info msg="running go-librespot 0.4.0" Feb 08 02:39:23 volumio go-librespot[25000]: time="2026-02-08T02:39:23+07:00" level=debug msg="app state loaded" Feb 08 02:39:23 volumio go-librespot[25000]: time="2026-02-08T02:39:23+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 08 02:39:24 volumio go-librespot[25000]: time="2026-02-08T02:39:24+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 08 02:39:24 volumio go-librespot[25000]: time="2026-02-08T02:39:24+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 08 02:39:24 volumio go-librespot[25000]: time="2026-02-08T02:39:24+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 08 02:39:24 volumio go-librespot[25000]: time="2026-02-08T02:39:24+07:00" level=info msg="zeroconf server listening on port 33887" Feb 08 02:39:24 volumio go-librespot[25000]: time="2026-02-08T02:39:24+07:00" level=debug msg="obtained new client token: AADMwj2oYsyTlAMgGMF5l4Nb8DTJnbVUCoFYwiCmN1/LOj19HoWpQSrpNSJ/0X3AESoZRrFot+m3ptV80AzGNLhon0Q8XbaL+Dd9IRSCjoajXL0bG6T3Xx7QfMAJT1n09cGvsxg9J/8qdfk/rFbdOsMT+lgndahNmtFIJH+4c67Tx3p/83YQrJRBDwez6pzMJdvqC80zCE8PRORNZDy7+WzXXBHlEVn5Um4Br4qk0r6lzVaoNuMy0ztdQA==" Feb 08 02:39:24 volumio go-librespot[25000]: time="2026-02-08T02:39:24+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 08 02:39:24 volumio go-librespot[25000]: time="2026-02-08T02:39:24+07:00" level=debug msg="completed keyexchange" Feb 08 02:39:24 volumio go-librespot[25000]: time="2026-02-08T02:39:24+07:00" level=debug msg="completed challenge" Feb 08 02:39:24 volumio go-librespot[25000]: time="2026-02-08T02:39:24+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 08 02:39:24 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 08 02:39:24 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 08 02:39:25 volumio volumio[24915]: info: Loading plugin "ytcr"... Feb 08 02:39:27 volumio volumio[24915]: info: Loading plugin "ytmusic"... Feb 08 02:39:28 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 50. Feb 08 02:39:28 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 08 02:39:28 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 08 02:39:28 volumio go-librespot[25007]: go-librespot daemon starting... Feb 08 02:39:28 volumio go-librespot[25008]: time="2026-02-08T02:39:28+07:00" level=info msg="running go-librespot 0.4.0" Feb 08 02:39:28 volumio go-librespot[25008]: time="2026-02-08T02:39:28+07:00" level=debug msg="app state loaded" Feb 08 02:39:28 volumio go-librespot[25008]: time="2026-02-08T02:39:28+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 08 02:39:28 volumio go-librespot[25008]: time="2026-02-08T02:39:28+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 08 02:39:28 volumio go-librespot[25008]: time="2026-02-08T02:39: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 08 02:39:28 volumio go-librespot[25008]: time="2026-02-08T02:39: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 08 02:39:28 volumio go-librespot[25008]: time="2026-02-08T02:39:28+07:00" level=info msg="zeroconf server listening on port 40837" Feb 08 02:39:28 volumio volumio-remote-updater[643]: [2026-02-08 02:39:28] [connect] Successful connection Feb 08 02:39:29 volumio go-librespot[25008]: time="2026-02-08T02:39:29+07:00" level=debug msg="obtained new client token: AACQABPLXWlxt4VsgDZbLmkdC022fZB2lxZODITjuN1f8dKWEnejagYrbE4kwV+1Wza/esyMTGJ4D2dEdQaQjZ4QtOnt2FvG/qYD3Tf/VqVw5psi1HW3ZadJ4oPtlS/EbV5SO52P3QAaMm/23Q3s1Fxlz8HQXEBl9DJaL6Rz8f/jWkxz7PCpbc6QJaQaedgD9qvCOQTzGzlsMXXYyyNauzrGMC1qWHfmoYgroWIAL+ohvo2MPVzn" Feb 08 02:39:29 volumio volumio[24915]: info: Loading plugin "outputs"... Feb 08 02:39:29 volumio volumio[24915]: info: Loading plugin "albumart"... Feb 08 02:39:29 volumio volumio[24915]: info: Plugin example_plugin is not enabled Feb 08 02:39:29 volumio volumio[24915]: info: Loading plugin "inputs"... Feb 08 02:39:29 volumio volumio[24915]: info: Loading plugin "updater_comm"... Feb 08 02:39:29 volumio go-librespot[25008]: time="2026-02-08T02:39:29+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 08 02:39:29 volumio go-librespot[25008]: time="2026-02-08T02:39:29+07:00" level=debug msg="completed keyexchange" Feb 08 02:39:29 volumio go-librespot[25008]: time="2026-02-08T02:39:29+07:00" level=debug msg="completed challenge" Feb 08 02:39:29 volumio go-librespot[25008]: time="2026-02-08T02:39:29+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 08 02:39:29 volumio volumio[24915]: info: Plugin mpdemulation is not enabled Feb 08 02:39:29 volumio volumio[24915]: info: Loading plugin "rest_api"... Feb 08 02:39:29 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 08 02:39:29 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 08 02:39:29 volumio volumio[24915]: info: Loading plugin "websocket"... Feb 08 02:39:29 volumio volumio[24915]: info: Starting Socket.io Server version 1.7.4 Feb 08 02:39:29 volumio volumio[24915]: info: Loading plugin "RoonBridge"... Feb 08 02:39:29 volumio volumio[24915]: info: Applying required configuration parameters for plugin RoonBridge Feb 08 02:39:29 volumio volumio[24915]: info: Loading i18n strings for locale en Feb 08 02:39:30 volumio volumio[24915]: Updating browse sources language Feb 08 02:39:30 volumio volumio[24915]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 08 02:39:30 volumio volumio[25029]: Forking 3 albumart workers Feb 08 02:39:30 volumio volumio[24915]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 08 02:39:30 volumio volumio[24915]: info: CoreCommandRouter::initPlayerControls Feb 08 02:39:30 volumio volumio[24915]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 02:39:30 volumio volumio[24915]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 02:39:30 volumio volumio[24915]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 02:39:30 volumio volumio[24915]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 02:39:30 volumio volumio[24915]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 02:39:30 volumio volumio[24915]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 02:39:30 volumio volumio[24915]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 02:39:30 volumio volumio[24915]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 02:39:30 volumio volumio[24915]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 08 02:39:30 volumio volumio[24915]: Express server listening on port 3000 Feb 08 02:39:30 volumio volumio[24915]: [Metrics] WebUI: 16s 151.57ms Feb 08 02:39:30 volumio volumio[24915]: info: CoreStateMachine::resetVolumioState Feb 08 02:39:30 volumio volumio[24915]: info: CoreStateMachine::getcurrentVolume Feb 08 02:39:30 volumio volumio[24915]: info: CoreCommandRouter::volumioRetrievevolume Feb 08 02:39:30 volumio volumio[24915]: info: Volumio Network Manager: Network status updated: 1 Feb 08 02:39:30 volumio sudo[25073]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 08 02:39:30 volumio sudo[25073]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 02:39:30 volumio sudo[25075]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 08 02:39:30 volumio sudo[25075]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 02:39:30 volumio sudo[25073]: pam_unix(sudo:session): session closed for user root Feb 08 02:39:30 volumio sudo[25075]: pam_unix(sudo:session): session closed for user root Feb 08 02:39:30 volumio volumio[24915]: info: VolumeController:: Volume=100 Mute =false Feb 08 02:39:30 volumio volumio[24915]: info: CoreStateMachine::pushState Feb 08 02:39:30 volumio volumio[24915]: info: CorePlayQueue::getTrack 0 Feb 08 02:39:30 volumio volumio[24915]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 08 02:39:30 volumio volumio[24915]: info: CoreCommandRouter::volumioPushState Feb 08 02:39:30 volumio volumio[24915]: info: CoreStateMachine::updateTrackBlock Feb 08 02:39:30 volumio volumio[24915]: info: CorePlayQueue::getTrackBlock Feb 08 02:39:30 volumio volumio[24915]: info: CoreCommandRouter::volumioRetrievevolume Feb 08 02:39:30 volumio volumio-remote-updater[643]: [2026-02-08 02:39:30] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1770493168 101 Feb 08 02:39:31 volumio volumio[24915]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 1 Feb 08 02:39:31 volumio volumio[24915]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 08 02:39:31 volumio volumio[24915]: info: Reloading queue from file Feb 08 02:39:31 volumio volumio[24915]: info: CoreStateMachine::setRepeat null single undefined Feb 08 02:39:31 volumio volumio[24915]: info: CoreStateMachine::pushState Feb 08 02:39:31 volumio volumio[24915]: info: CorePlayQueue::getTrack 0 Feb 08 02:39:31 volumio volumio[24915]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 08 02:39:31 volumio volumio[24915]: info: CoreCommandRouter::volumioPushState Feb 08 02:39:31 volumio volumio[24915]: info: CoreStateMachine::setRandom null Feb 08 02:39:31 volumio volumio[24915]: info: CoreStateMachine::pushState Feb 08 02:39:31 volumio volumio[24915]: info: CorePlayQueue::getTrack 0 Feb 08 02:39:31 volumio volumio[24915]: info: CoreCommandRouter::volumioPushState Feb 08 02:39:31 volumio volumio[24915]: info: Setting Device type: Raspberry PI Feb 08 02:39:31 volumio volumio[24915]: info: Completed loading Core Plugins Feb 08 02:39:31 volumio volumio[24915]: info: Preparing to generate the ALSA configuration file Feb 08 02:39:31 volumio volumio[24915]: info: VolumeController:: Volume=100 Mute =false Feb 08 02:39:31 volumio volumio[24915]: info: CoreStateMachine::pushState Feb 08 02:39:31 volumio volumio[24915]: info: CorePlayQueue::getTrack 0 Feb 08 02:39:31 volumio volumio[24915]: info: CoreCommandRouter::volumioPushState Feb 08 02:39:31 volumio volumio[24915]: info: Asound.conf file unchanged, so no further update is needed Feb 08 02:39:31 volumio volumio[24915]: info: Output device has changed, restarting MPD Feb 08 02:39:31 volumio sudo[25089]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 08 02:39:31 volumio sudo[25089]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 02:39:31 volumio volumio[24915]: info: Output device has changed, restarting Shairport Sync Feb 08 02:39:31 volumio volumio[24915]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 02:39:31 volumio volumio[24915]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 08 02:39:31 volumio sudo[25091]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 08 02:39:31 volumio sudo[25091]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 02:39:31 volumio sudo[25089]: pam_unix(sudo:session): session closed for user root Feb 08 02:39:31 volumio sudo[25091]: pam_unix(sudo:session): session closed for user root Feb 08 02:39:31 volumio sudo[25094]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 08 02:39:31 volumio sudo[25094]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 02:39:31 volumio volumio[24915]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 08 02:39:31 volumio volumio[24915]: info: ___________ START PLUGINS ___________ Feb 08 02:39:31 volumio volumio[24915]: info: ControllerMpd::onStart: Initializing MPD Feb 08 02:39:31 volumio volumio[24915]: info: Creating MPD Configuration file Feb 08 02:39:31 volumio volumio[24915]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 08 02:39:31 volumio volumio[24915]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 08 02:39:31 volumio volumio[24915]: info: [1770493171688] CoreMusicLibrary::Adding element Media Servers Feb 08 02:39:31 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 08 02:39:31 volumio volumio[24915]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 08 02:39:31 volumio volumio[24915]: info: UPNP Browser: Client initialized successfully Feb 08 02:39:31 volumio sudo[25104]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 08 02:39:31 volumio sudo[25102]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 08 02:39:31 volumio sudo[25102]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 02:39:31 volumio sudo[25104]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 02:39:31 volumio sudo[25102]: pam_unix(sudo:session): session closed for user root Feb 08 02:39:31 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 08 02:39:31 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 08 02:39:31 volumio systemd[1]: mpd.service: Consumed 7.138s CPU time. Feb 08 02:39:31 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 08 02:39:31 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 08 02:39:31 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 08 02:39:31 volumio volumio[24915]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 02:39:31 volumio volumio[24915]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 08 02:39:31 volumio volumio[24915]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 08 02:39:31 volumio volumio[24915]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 02:39:31 volumio volumio[24915]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 08 02:39:31 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 08 02:39:31 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 08 02:39:32 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 08 02:39:32 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 08 02:39:32 volumio volumio[24915]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 08 02:39:32 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 08 02:39:32 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 08 02:39:32 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 08 02:39:32 volumio volumio[24915]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 08 02:39:32 volumio volumio[24915]: info: [1770493172062] CoreMusicLibrary::Adding element Last_100 Feb 08 02:39:32 volumio volumio[24915]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 08 02:39:32 volumio volumio[24915]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 08 02:39:32 volumio volumio[24915]: info: [1770493172074] CoreMusicLibrary::Adding element Webradio Feb 08 02:39:32 volumio volumio[24915]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 08 02:39:32 volumio volumio[24915]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 08 02:39:32 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 08 02:39:32 volumio volumio[24915]: info: Initializing BBC Radios Feb 08 02:39:32 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 08 02:39:32 volumio volumio[24915]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 08 02:39:32 volumio volumio[24915]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 08 02:39:32 volumio volumio[24915]: info: Creating Spotify config file Feb 08 02:39:32 volumio volumio[24915]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 02:39:32 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 51. Feb 08 02:39:32 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 08 02:39:32 volumio sudo[25119]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 08 02:39:32 volumio sudo[25119]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 08 02:39:32 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 08 02:39:32 volumio go-librespot[25134]: go-librespot daemon starting... Feb 08 02:39:32 volumio sudo[25119]: pam_unix(sudo:session): session closed for user root Feb 08 02:39:32 volumio go-librespot[25136]: time="2026-02-08T02:39:32+07:00" level=info msg="running go-librespot 0.4.0" Feb 08 02:39:33 volumio volumio[25040]: Starting albumart workers Feb 08 02:39:33 volumio go-librespot[25136]: time="2026-02-08T02:39:33+07:00" level=info msg="zeroconf server listening on port 38473" Feb 08 02:39:33 volumio volumio[25039]: Starting albumart workers Feb 08 02:39:33 volumio volumio[24915]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 08 02:39:33 volumio volumio[24915]: info: [1770493173756] CoreMusicLibrary::Adding element YouTube Music Feb 08 02:39:33 volumio volumio[24915]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 08 02:39:33 volumio volumio[24915]: Cannot find translation for source YouTube Music Feb 08 02:39:33 volumio volumio[24915]: info: Volumio Calling Home Feb 08 02:39:33 volumio sudo[25145]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Feb 08 02:39:33 volumio sudo[25145]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 02:39:34 volumio volumio[25041]: Starting albumart workers Feb 08 02:39:34 volumio sudo[25145]: pam_unix(sudo:session): session closed for user root Feb 08 02:39:34 volumio volumio[24915]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Feb 08 02:39:34 volumio volumio[24915]: info: Discovery: Found device Volumio Feb 08 02:39:35 volumio volumio[24915]: info: CoreCommandRouter::volumioGetState Feb 08 02:39:35 volumio volumio[24915]: info: CorePlayQueue::getTrack 0 Feb 08 02:39:35 volumio volumio[24915]: info: MPD Permissions set Feb 08 02:39:35 volumio volumio[24915]: info: MPD Permissions set Feb 08 02:39:35 volumio volumio[24915]: info: Upmpdcli Daemon Started Feb 08 02:39:35 volumio volumio[24915]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Feb 08 02:39:35 volumio volumio[24915]: info: Discovery: Found device Volumio Feb 08 02:39:35 volumio volumio[24915]: info: CoreCommandRouter::volumioGetState Feb 08 02:39:35 volumio volumio[24915]: info: CorePlayQueue::getTrack 0 Feb 08 02:39:35 volumio volumio[24915]: info: Volumio called home Feb 08 02:39:35 volumio volumio[24915]: info: Spotify config file written Feb 08 02:39:35 volumio volumio[24915]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Feb 08 02:39:35 volumio volumio[24915]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 02:39:35 volumio volumio[24915]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 02:39:35 volumio volumio[24915]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 02:39:35 volumio volumio[24915]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 02:39:35 volumio volumio[24915]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 02:39:35 volumio volumio[24915]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 02:39:35 volumio volumio[24915]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 02:39:35 volumio volumio[24915]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 02:39:35 volumio sudo[25153]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 08 02:39:35 volumio sudo[25153]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 02:39:35 volumio volumio[24915]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 08 02:39:35 volumio volumio[24915]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 02:39:35 volumio volumio[24915]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 02:39:35 volumio volumio[24915]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 02:39:35 volumio volumio[24915]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 02:39:35 volumio volumio[24915]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 02:39:35 volumio volumio[24915]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 02:39:35 volumio volumio[24915]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 02:39:35 volumio volumio[24915]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 02:39:35 volumio volumio[24915]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 02:39:35 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Feb 08 02:39:35 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Feb 08 02:39:35 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 08 02:39:35 volumio volumio[24915]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 08 02:39:35 volumio volumio[24915]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 08 02:39:35 volumio volumio[24915]: info: No need to fix Spotify hosts Feb 08 02:39:35 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 08 02:39:35 volumio go-librespot[25176]: go-librespot daemon starting... Feb 08 02:39:35 volumio sudo[25153]: pam_unix(sudo:session): session closed for user root Feb 08 02:39:35 volumio go-librespot[25177]: time="2026-02-08T02:39:35+07:00" level=info msg="running go-librespot 0.4.0" Feb 08 02:39:35 volumio go-librespot[25177]: time="2026-02-08T02:39:35+07:00" level=debug msg="app state loaded" Feb 08 02:39:35 volumio go-librespot[25177]: time="2026-02-08T02:39:35+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 08 02:39:36 volumio go-librespot[25177]: time="2026-02-08T02:39:36+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 08 02:39:36 volumio go-librespot[25177]: time="2026-02-08T02:39:36+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 08 02:39:36 volumio go-librespot[25177]: time="2026-02-08T02:39:36+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 08 02:39:36 volumio go-librespot[25177]: time="2026-02-08T02:39:36+07:00" level=info msg="zeroconf server listening on port 40909" Feb 08 02:39:36 volumio volumio[24915]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 08 02:39:36 volumio volumio[24915]: SPOTIFY: BQCCRMKeJppcfU3o_8uqJ6yJfYNf7Khu_-Nua3K4n-LFE5371Pkl14UegBJP3EO_bXb4CK6LahSzKjAltNNm-YwZuhXUq3hHEEB60aG_l91vjd18MzvFBg0rrJilUbJP85xW5jlaC9Q5vFKQP_z_AN6c18I5y9P3dY_9UrWLUv38nIDrTJBD4xGP3XRsFuL765ArTc9wiijvZf3svUY62hvLfNHWwLPSNC_-6bgG1Ibt0OeLgNvYbIWe6Y1hZeiKuoCyG-ypOm-0pkS-v55ABSfqv2MFCDlOi-9b9560jHTSGhzFWIYutwSL Feb 08 02:39:36 volumio volumio[24915]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 08 02:39:36 volumio volumio[24915]: info: New Spotify access token = BQCCRMKeJppcfU3o_8uqJ6yJfYNf7Khu_-Nua3K4n-LFE5371Pkl14UegBJP3EO_bXb4CK6LahSzKjAltNNm-YwZuhXUq3hHEEB60aG_l91vjd18MzvFBg0rrJilUbJP85xW5jlaC9Q5vFKQP_z_AN6c18I5y9P3dY_9UrWLUv38nIDrTJBD4xGP3XRsFuL765ArTc9wiijvZf3svUY62hvLfNHWwLPSNC_-6bgG1Ibt0OeLgNvYbIWe6Y1hZeiKuoCyG-ypOm-0pkS-v55ABSfqv2MFCDlOi-9b9560jHTSGhzFWIYutwSL Feb 08 02:39:36 volumio volumio[24915]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 08 02:39:36 volumio volumio[24915]: info: Starting Shairport Sync Feb 08 02:39:36 volumio go-librespot[25177]: time="2026-02-08T02:39:36+07:00" level=debug msg="obtained new client token: AAD/eEL64GvQPTP0QbOrH205WhoUaHf2VzI52/wwHBZhioUlCx8eQUQ3uhKMBNTZuUYHQGR5JWkz6XUOTgLdfBG3lrjwcx1b/heZX9CGyGvTarNYUPDPrFm401vCvrMrJkjmGApL7tEZRZ9VhQxMqtKW8wfgNdGS2Hk/jKkQKqhO0eLriGCwsJob/zyMkzqrelyIvV0HTrMVUyEVw+9Gjo6vHIUvNgvucvfWJie1B4ED2isDUw2+vJBu6w==" Feb 08 02:39:36 volumio volumio[24915]: info: Starting Shairport Sync Feb 08 02:39:36 volumio volumio[24915]: info: Starting Shairport Sync Feb 08 02:39:36 volumio sudo[25194]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 08 02:39:36 volumio sudo[25193]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 08 02:39:36 volumio go-librespot[25177]: time="2026-02-08T02:39:36+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 08 02:39:36 volumio sudo[25194]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 02:39:36 volumio sudo[25193]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 02:39:36 volumio sudo[25196]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 08 02:39:36 volumio sudo[25196]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 08 02:39:36 volumio go-librespot[25177]: time="2026-02-08T02:39:36+07:00" level=debug msg="completed keyexchange" Feb 08 02:39:36 volumio go-librespot[25177]: time="2026-02-08T02:39:36+07:00" level=debug msg="completed challenge" Feb 08 02:39:36 volumio go-librespot[25177]: time="2026-02-08T02:39:36+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 08 02:39:36 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 08 02:39:36 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 08 02:39:36 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 08 02:39:36 volumio systemd[1]: shairport-sync.service: Consumed 2.369s CPU time. Feb 08 02:39:36 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 08 02:39:36 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 08 02:39:36 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 08 02:39:37 volumio sudo[25196]: pam_unix(sudo:session): session closed for user root Feb 08 02:39:37 volumio volumio[24915]: info: CoreCommandRouter::volumioGetState Feb 08 02:39:37 volumio volumio[24915]: info: CorePlayQueue::getTrack 0 Feb 08 02:39:37 volumio sudo[25193]: pam_unix(sudo:session): session closed for user root Feb 08 02:39:37 volumio sudo[25194]: pam_unix(sudo:session): session closed for user root Feb 08 02:39:37 volumio volumio[24915]: info: Shairport-Sync Started Feb 08 02:39:37 volumio volumio[24915]: Error adding Membership: Error: addMembership EINVAL Feb 08 02:39:37 volumio volumio[24915]: info: Shairport-Sync Started Feb 08 02:39:37 volumio volumio[24915]: info: Shairport-Sync Started Feb 08 02:39:37 volumio volumio[24915]: SPOTIFY: User informations: {"country":"PK","display_name":"215mmgea6kss3jxeqsqdquvji","email":"linh.ngotran@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/215mmgea6kss3jxeqsqdquvji"},"followers":{"href":null,"total":1},"href":"https://api.spotify.com/v1/users/215mmgea6kss3jxeqsqdquvji","id":"215mmgea6kss3jxeqsqdquvji","images":[],"product":"premium","type":"user","uri":"spotify:user:215mmgea6kss3jxeqsqdquvji"} Feb 08 02:39:37 volumio volumio[24915]: info: Spotify Successfully logged in Feb 08 02:39:37 volumio volumio[24915]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 08 02:39:37 volumio volumio[24915]: info: [1770493177183] CoreMusicLibrary::Adding element Spotify Feb 08 02:39:37 volumio volumio[24915]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 08 02:39:37 volumio volumio[24915]: Cannot find translation for source YouTube Music Feb 08 02:39:37 volumio volumio[24915]: Cannot find translation for source Spotify Feb 08 02:39:37 volumio volumio[24915]: info: [yt-cast-receiver] DIAL server listening on port 8098 Feb 08 02:39:38 volumio volumio[24915]: info: CoreCommandRouter::volumioRetrievevolume Feb 08 02:39:38 volumio volumio[24915]: info: VolumeController:: Volume=100 Mute =false Feb 08 02:39:38 volumio volumio[24915]: info: CoreCommandRouter::volumioGetState Feb 08 02:39:38 volumio volumio[24915]: info: CorePlayQueue::getTrack 0 Feb 08 02:39:38 volumio volumio[24915]: info: CoreStateMachine::pushState Feb 08 02:39:38 volumio volumio[24915]: info: CorePlayQueue::getTrack 0 Feb 08 02:39:38 volumio volumio[24915]: info: CoreCommandRouter::volumioPushState Feb 08 02:39:39 volumio volumio[24915]: info: go-librespot daemon successfully initialized Feb 08 02:39:39 volumio mpd[25142]: 2026-02-08T02:39:39 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 08 02:39:39 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 08 02:39:39 volumio sudo[25104]: pam_unix(sudo:session): session closed for user root Feb 08 02:39:39 volumio sudo[25094]: pam_unix(sudo:session): session closed for user root Feb 08 02:39:39 volumio volumio[24915]: error: MPD error: The expression evaluated to a falsy value: Feb 08 02:39:39 volumio volumio[24915]: assert.ok(self.idling) Feb 08 02:39:39 volumio volumio[24915]: error: The expression evaluated to a falsy value: Feb 08 02:39:39 volumio volumio[24915]: assert.ok(self.idling) Feb 08 02:39:39 volumio volumio[24915]: error: updateQueue error: null Feb 08 02:39:39 volumio volumio[24915]: info: MPD running with PID25142 Feb 08 02:39:39 volumio volumio[24915]: ,establishing connection Feb 08 02:39:40 volumio volumio[24915]: info: Completed starting Core Plugins Feb 08 02:39:40 volumio volumio[24915]: info: ------------------------------------------- Feb 08 02:39:40 volumio volumio[24915]: info: ----- MyVolumio plugins startup ---- Feb 08 02:39:40 volumio volumio[24915]: info: ------------------------------------------- Feb 08 02:39:40 volumio volumio[24915]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 08 02:39:40 volumio volumio[24915]: error: updateQueue error: null Feb 08 02:39:40 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Feb 08 02:39:40 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 08 02:39:40 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 08 02:39:40 volumio go-librespot[25237]: go-librespot daemon starting... Feb 08 02:39:40 volumio go-librespot[25238]: time="2026-02-08T02:39:40+07:00" level=info msg="running go-librespot 0.4.0" Feb 08 02:39:40 volumio go-librespot[25238]: time="2026-02-08T02:39:40+07:00" level=debug msg="app state loaded" Feb 08 02:39:40 volumio go-librespot[25238]: time="2026-02-08T02:39:40+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 08 02:39:40 volumio go-librespot[25238]: time="2026-02-08T02:39:40+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 08 02:39:40 volumio go-librespot[25238]: time="2026-02-08T02:39:40+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 08 02:39:40 volumio go-librespot[25238]: time="2026-02-08T02:39:40+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 08 02:39:40 volumio go-librespot[25238]: time="2026-02-08T02:39:40+07:00" level=info msg="zeroconf server listening on port 40045" Feb 08 02:39:40 volumio go-librespot[25238]: time="2026-02-08T02:39:40+07:00" level=debug msg="obtained new client token: AACnS98QeNXR/3cu56Uov9PyCeqX2BYl2irvBVQ2bwmyhzApBDTvY97PgswaGOgzY+R2MKXHSO6+gfOAGlaTq5ROkUS4CLkVbp7eAE/TjOiv/+WFc9sPOVMZAtN3n+hLcP2wJ/txo4bzcC4I6+q06KeHNLpPXP23DIIb/PtS7GkxJPfzn0QgVfPf+IOd4oTqyxKKqF/FYVqwY45MkIJIW7kDVnVLKU4cUq3pVjolhPtJVECEX7GO54rCAA==" Feb 08 02:39:40 volumio go-librespot[25238]: time="2026-02-08T02:39:40+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 08 02:39:41 volumio go-librespot[25238]: time="2026-02-08T02:39:41+07:00" level=debug msg="completed keyexchange" Feb 08 02:39:41 volumio go-librespot[25238]: time="2026-02-08T02:39:41+07:00" level=debug msg="completed challenge" Feb 08 02:39:41 volumio go-librespot[25238]: time="2026-02-08T02:39:41+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 08 02:39:41 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 08 02:39:41 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 08 02:39:42 volumio volumio[24915]: info: Initializing connection to go-librespot Websocket Feb 08 02:39:42 volumio volumio[24915]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 08 02:39:44 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Feb 08 02:39:44 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 08 02:39:44 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 08 02:39:44 volumio go-librespot[25246]: go-librespot daemon starting... Feb 08 02:39:44 volumio go-librespot[25247]: time="2026-02-08T02:39:44+07:00" level=info msg="running go-librespot 0.4.0" Feb 08 02:39:44 volumio go-librespot[25247]: time="2026-02-08T02:39:44+07:00" level=debug msg="app state loaded" Feb 08 02:39:44 volumio go-librespot[25247]: time="2026-02-08T02:39:44+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 08 02:39:44 volumio volumio[24915]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 08 02:39:44 volumio go-librespot[25247]: time="2026-02-08T02:39:44+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 08 02:39:44 volumio go-librespot[25247]: time="2026-02-08T02:39:44+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 08 02:39:44 volumio go-librespot[25247]: time="2026-02-08T02:39:44+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 08 02:39:44 volumio go-librespot[25247]: time="2026-02-08T02:39:44+07:00" level=info msg="zeroconf server listening on port 39975" Feb 08 02:39:45 volumio go-librespot[25247]: time="2026-02-08T02:39:45+07:00" level=debug msg="obtained new client token: AAAwoVts+Jl1I6IRJK9gpsmH3cxsYEKFt1BvEneYNx5+LygwfkMw+LqFVhVLIMRiW0VNR5etqCN55NEhG92J6jg0CP62FlbMnwvxjw9zjuYLrqU8PnAMRBc83DDFYkM6hS193VZpmz8jO7fjI1V06anz3fhRXGXXnJ3tZgU9K80lcI/xqRkfggw9UY9v3/QCt59wuk8ioqSw0e+WZsJlqj5bisrenQQW+87T50mrHfnbBAYpfow2wAw=" Feb 08 02:39:45 volumio go-librespot[25247]: time="2026-02-08T02:39:45+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 08 02:39:45 volumio go-librespot[25247]: time="2026-02-08T02:39:45+07:00" level=debug msg="completed keyexchange" Feb 08 02:39:45 volumio go-librespot[25247]: time="2026-02-08T02:39:45+07:00" level=debug msg="completed challenge" Feb 08 02:39:45 volumio volumio[24915]: info: Initializing connection to go-librespot Websocket Feb 08 02:39:45 volumio go-librespot[25247]: time="2026-02-08T02:39:45+07:00" level=debug msg="new websocket client" Feb 08 02:39:45 volumio go-librespot[25247]: time="2026-02-08T02:39:45+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 08 02:39:45 volumio volumio[24915]: info: Connection to go-librespot Websocket established Feb 08 02:39:45 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 08 02:39:45 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 08 02:39:45 volumio volumio[24915]: info: Connection to go-librespot Websocket closed Feb 08 02:39:48 volumio volumio[24915]: info: Getting Spotify volume Feb 08 02:39:48 volumio volumio[24915]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 08 02:39:48 volumio volumio[24915]: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 08 02:39:48 volumio volumio[24915]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Feb 08 02:39:48 volumio volumio[24915]: errno: -111, Feb 08 02:39:48 volumio volumio[24915]: code: 'ECONNREFUSED', Feb 08 02:39:48 volumio volumio[24915]: syscall: 'connect', Feb 08 02:39:48 volumio volumio[24915]: address: '127.0.0.1', Feb 08 02:39:48 volumio volumio[24915]: port: 9879, Feb 08 02:39:48 volumio volumio[24915]: response: undefined Feb 08 02:39:48 volumio volumio[24915]: } Feb 08 02:39:48 volumio volumio[24915]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 08 02:39:48 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Feb 08 02:39:48 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 08 02:39:48 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 08 02:39:48 volumio go-librespot[25257]: go-librespot daemon starting... Feb 08 02:39:48 volumio go-librespot[25266]: time="2026-02-08T02:39:48+07:00" level=info msg="running go-librespot 0.4.0" Feb 08 02:39:48 volumio go-librespot[25266]: time="2026-02-08T02:39:48+07:00" level=debug msg="app state loaded" Feb 08 02:39:48 volumio go-librespot[25266]: time="2026-02-08T02:39:48+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 08 02:39:49 volumio go-librespot[25266]: time="2026-02-08T02:39:49+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 08 02:39:49 volumio go-librespot[25266]: time="2026-02-08T02:39:49+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 08 02:39:49 volumio go-librespot[25266]: time="2026-02-08T02:39:49+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 08 02:39:49 volumio go-librespot[25266]: time="2026-02-08T02:39:49+07:00" level=info msg="zeroconf server listening on port 39301" Feb 08 02:39:49 volumio go-librespot[25266]: time="2026-02-08T02:39:49+07:00" level=debug msg="obtained new client token: AAAUUhTU8zIabrw57yUTplc2unMttntGLUfZupjV6vREVuyNDbIm4HzWb6Ze15xLzooypr59G3X8/OqGL1Ifh3rmQGg7+smIxuyCAJUbmz4ArH6eqSJoXDnUmeY4lexlX96/pZbwFjVPTGADu775LrdnUMWz8AidmQoKYtK1fhBvt3ZOQZ7LL5v5Vyz6ewrb2XiFqxE26uKGcWA6CBkK/GWSdmOM9/BxbpS7L0AQQmagUKECsv5EUKErDw==" Feb 08 02:39:49 volumio go-librespot[25266]: time="2026-02-08T02:39:49+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 08 02:39:49 volumio go-librespot[25266]: time="2026-02-08T02:39:49+07:00" level=debug msg="completed keyexchange" Feb 08 02:39:49 volumio go-librespot[25266]: time="2026-02-08T02:39:49+07:00" level=debug msg="completed challenge" Feb 08 02:39:49 volumio go-librespot[25266]: time="2026-02-08T02:39:49+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 08 02:39:49 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 08 02:39:49 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 08 02:39:50 volumio sudo[25290]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-08 02:38' Feb 08 02:39:50 volumio sudo[25290]: 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"