Feb 18 15:20:00 volumio volumio[25832]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 18 15:20:00 volumio volumio[25832]: info: CoreCommandRouter::initPlayerControls Feb 18 15:20:00 volumio volumio[25943]: Forking 3 albumart workers Feb 18 15:20:00 volumio volumio[25832]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:20:00 volumio volumio[25832]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:20:00 volumio volumio[25832]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:20:00 volumio volumio[25832]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:20:00 volumio volumio[25832]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:20:00 volumio volumio[25832]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:20:00 volumio volumio[25832]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:20:00 volumio volumio[25832]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:20:00 volumio volumio[25832]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 18 15:20:00 volumio volumio[25832]: Express server listening on port 3000 Feb 18 15:20:00 volumio volumio[25832]: [Metrics] WebUI: 15s 896.52ms Feb 18 15:20:00 volumio volumio[25832]: info: CoreStateMachine::resetVolumioState Feb 18 15:20:00 volumio volumio[25832]: info: CoreStateMachine::getcurrentVolume Feb 18 15:20:00 volumio volumio[25832]: info: CoreCommandRouter::volumioRetrievevolume Feb 18 15:20:00 volumio sudo[25977]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 18 15:20:00 volumio sudo[25977]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 15:20:00 volumio sudo[25977]: pam_unix(sudo:session): session closed for user root Feb 18 15:20:00 volumio volumio[25832]: info: Volumio Network Manager: Network status updated: 1 Feb 18 15:20:00 volumio sudo[25987]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 18 15:20:00 volumio sudo[25987]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 15:20:00 volumio sudo[25987]: pam_unix(sudo:session): session closed for user root Feb 18 15:20:00 volumio volumio[25832]: info: VolumeController:: Volume=100 Mute =false Feb 18 15:20:00 volumio volumio[25832]: info: CoreStateMachine::pushState Feb 18 15:20:00 volumio volumio[25832]: info: CorePlayQueue::getTrack 0 Feb 18 15:20:00 volumio volumio[25832]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 18 15:20:00 volumio volumio[25832]: info: CoreCommandRouter::volumioPushState Feb 18 15:20:00 volumio volumio[25832]: info: CoreStateMachine::updateTrackBlock Feb 18 15:20:00 volumio volumio[25832]: info: CorePlayQueue::getTrackBlock Feb 18 15:20:00 volumio volumio[25832]: info: CoreCommandRouter::volumioRetrievevolume Feb 18 15:20:00 volumio volumio-remote-updater[25144]: [2026-02-18 15:20:00] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1771402798 101 Feb 18 15:20:00 volumio volumio[25832]: 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 18 15:20:00 volumio volumio[25832]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 15:20:00 volumio volumio[25832]: info: Reloading queue from file Feb 18 15:20:01 volumio volumio[25832]: info: CoreStateMachine::setRepeat null single undefined Feb 18 15:20:01 volumio volumio[25832]: info: CoreStateMachine::pushState Feb 18 15:20:01 volumio volumio[25832]: info: CorePlayQueue::getTrack 0 Feb 18 15:20:01 volumio volumio[25832]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 18 15:20:01 volumio volumio[25832]: info: CoreCommandRouter::volumioPushState Feb 18 15:20:01 volumio volumio[25832]: info: CoreStateMachine::setRandom null Feb 18 15:20:01 volumio volumio[25832]: info: CoreStateMachine::pushState Feb 18 15:20:01 volumio volumio[25832]: info: CorePlayQueue::getTrack 0 Feb 18 15:20:01 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Feb 18 15:20:01 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 15:20:01 volumio volumio[25832]: info: CoreCommandRouter::volumioPushState Feb 18 15:20:01 volumio volumio[25832]: info: Setting Device type: Raspberry PI Feb 18 15:20:01 volumio volumio[25832]: info: Completed loading Core Plugins Feb 18 15:20:01 volumio volumio[25832]: info: Preparing to generate the ALSA configuration file Feb 18 15:20:01 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 15:20:01 volumio go-librespot[26002]: go-librespot daemon starting... Feb 18 15:20:01 volumio go-librespot[26004]: time="2026-02-18T15:20:01+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 15:20:01 volumio go-librespot[26004]: time="2026-02-18T15:20:01+07:00" level=debug msg="app state loaded" Feb 18 15:20:01 volumio go-librespot[26004]: time="2026-02-18T15:20:01+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 15:20:01 volumio volumio[25832]: info: VolumeController:: Volume=100 Mute =false Feb 18 15:20:01 volumio volumio[25832]: info: CoreStateMachine::pushState Feb 18 15:20:01 volumio volumio[25832]: info: CorePlayQueue::getTrack 0 Feb 18 15:20:01 volumio volumio[25832]: info: CoreCommandRouter::volumioPushState Feb 18 15:20:01 volumio volumio[25832]: info: Asound.conf file unchanged, so no further update is needed Feb 18 15:20:01 volumio volumio[25832]: info: Output device has changed, restarting MPD Feb 18 15:20:01 volumio sudo[26012]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 18 15:20:01 volumio sudo[26012]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 15:20:01 volumio volumio[25832]: info: Output device has changed, restarting Shairport Sync Feb 18 15:20:01 volumio volumio[25832]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:20:01 volumio volumio[25832]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 15:20:01 volumio sudo[26014]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 18 15:20:01 volumio sudo[26014]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 15:20:01 volumio sudo[26017]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 18 15:20:01 volumio sudo[26017]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 15:20:01 volumio sudo[26014]: pam_unix(sudo:session): session closed for user root Feb 18 15:20:01 volumio volumio[25832]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 18 15:20:01 volumio volumio[25832]: info: ___________ START PLUGINS ___________ Feb 18 15:20:01 volumio volumio[25832]: info: ControllerMpd::onStart: Initializing MPD Feb 18 15:20:01 volumio volumio[25832]: info: Creating MPD Configuration file Feb 18 15:20:01 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 18 15:20:01 volumio sudo[26012]: pam_unix(sudo:session): session closed for user root Feb 18 15:20:01 volumio volumio[25832]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 18 15:20:01 volumio volumio[25832]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 15:20:01 volumio volumio[25832]: info: [1771402801759] CoreMusicLibrary::Adding element Media Servers Feb 18 15:20:01 volumio volumio[25832]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 15:20:01 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 18 15:20:01 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 18 15:20:01 volumio systemd[1]: mpd.service: Consumed 6.678s CPU time. Feb 18 15:20:01 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 18 15:20:01 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 18 15:20:01 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 18 15:20:01 volumio volumio[25832]: info: UPNP Browser: Client initialized successfully Feb 18 15:20:01 volumio sudo[26026]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 18 15:20:01 volumio sudo[26026]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 15:20:01 volumio sudo[26026]: pam_unix(sudo:session): session closed for user root Feb 18 15:20:01 volumio sudo[26028]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 18 15:20:01 volumio sudo[26028]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 15:20:01 volumio volumio[25832]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:20:01 volumio volumio[25832]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 15:20:01 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 18 15:20:01 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 18 15:20:01 volumio go-librespot[26004]: time="2026-02-18T15:20:01+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 15:20:01 volumio go-librespot[26004]: time="2026-02-18T15:20:01+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 18 15:20:01 volumio go-librespot[26004]: time="2026-02-18T15:20:01+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 18 15:20:02 volumio go-librespot[26004]: time="2026-02-18T15:20:02+07:00" level=info msg="zeroconf server listening on port 33897" Feb 18 15:20:02 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 18 15:20:02 volumio volumio[25832]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 18 15:20:02 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 18 15:20:02 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 18 15:20:02 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 18 15:20:02 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 18 15:20:02 volumio volumio[25832]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:20:02 volumio volumio[25832]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 15:20:02 volumio volumio[25832]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 18 15:20:02 volumio volumio[25832]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 15:20:02 volumio volumio[25832]: info: [1771402802184] CoreMusicLibrary::Adding element Last_100 Feb 18 15:20:02 volumio volumio[25832]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 15:20:02 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 18 15:20:02 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 18 15:20:02 volumio volumio[25832]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 15:20:02 volumio volumio[25832]: info: [1771402802226] CoreMusicLibrary::Adding element Webradio Feb 18 15:20:02 volumio volumio[25832]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 15:20:02 volumio volumio[25832]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 18 15:20:02 volumio volumio[25832]: info: Initializing BBC Radios Feb 18 15:20:02 volumio go-librespot[26004]: time="2026-02-18T15:20:02+07:00" level=debug msg="obtained new client token: AABmgDWE5WjM1tKjplA9tYl2fXmufHbALWo9y7tPojzaFMQ3KCBbCi5MkE4F/YLezeoEg7PVJufa6zxASzBuovYbjU9lREn1wjQOzuKCBVLV4FSasEv40zlU/xMNF8UbehyngQaCrC6ShLqzAGfnndvFJ4WBnRB15jL8hx+CdQExL7kE5zvSTtEX2qhPiskSYIHDqA7SzvnQSPTGLED9TpU2+jIfXTW+AYhBi1ZtsWmmoUrsjciJyxc=" Feb 18 15:20:02 volumio go-librespot[26004]: time="2026-02-18T15:20:02+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 15:20:02 volumio volumio[25832]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 18 15:20:02 volumio volumio[25832]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 15:20:02 volumio volumio[25832]: info: Creating Spotify config file Feb 18 15:20:02 volumio volumio[25832]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:20:02 volumio go-librespot[26004]: time="2026-02-18T15:20:02+07:00" level=debug msg="completed keyexchange" Feb 18 15:20:02 volumio go-librespot[26004]: time="2026-02-18T15:20:02+07:00" level=debug msg="completed challenge" Feb 18 15:20:02 volumio go-librespot[26004]: time="2026-02-18T15:20: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 18 15:20:02 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 15:20:02 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 15:20:02 volumio sudo[26043]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 18 15:20:02 volumio sudo[26043]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 18 15:20:02 volumio sudo[26043]: pam_unix(sudo:session): session closed for user root Feb 18 15:20:03 volumio volumio[25954]: Starting albumart workers Feb 18 15:20:03 volumio volumio[25953]: Starting albumart workers Feb 18 15:20:03 volumio volumio[25832]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 15:20:03 volumio volumio[25832]: info: [1771402803763] CoreMusicLibrary::Adding element YouTube Music Feb 18 15:20:03 volumio volumio[25832]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 15:20:03 volumio volumio[25832]: Cannot find translation for source YouTube Music Feb 18 15:20:03 volumio volumio[25832]: info: Volumio Calling Home Feb 18 15:20:03 volumio sudo[26060]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Feb 18 15:20:03 volumio sudo[26060]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 15:20:04 volumio volumio[25955]: Starting albumart workers Feb 18 15:20:04 volumio sudo[26060]: pam_unix(sudo:session): session closed for user root Feb 18 15:20:04 volumio volumio[25832]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Feb 18 15:20:04 volumio volumio[25832]: info: Discovery: Found device Volumio Feb 18 15:20:04 volumio volumio[25832]: info: CoreCommandRouter::volumioGetState Feb 18 15:20:04 volumio volumio[25832]: info: CorePlayQueue::getTrack 0 Feb 18 15:20:04 volumio volumio[25832]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Feb 18 15:20:04 volumio volumio[25832]: info: Discovery: Found device Volumio Feb 18 15:20:04 volumio volumio[25832]: info: CoreCommandRouter::volumioGetState Feb 18 15:20:04 volumio volumio[25832]: info: CorePlayQueue::getTrack 0 Feb 18 15:20:04 volumio volumio[25832]: info: MPD Permissions set Feb 18 15:20:04 volumio volumio[25832]: info: MPD Permissions set Feb 18 15:20:04 volumio volumio[25832]: info: Upmpdcli Daemon Started Feb 18 15:20:04 volumio volumio[25832]: info: Volumio called home Feb 18 15:20:04 volumio volumio[25832]: info: Spotify config file written Feb 18 15:20:04 volumio sudo[26066]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 18 15:20:04 volumio sudo[26066]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 15:20:04 volumio volumio[25832]: 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 18 15:20:04 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 15:20:04 volumio volumio[25832]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:20:04 volumio volumio[25832]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:20:04 volumio volumio[25832]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:20:04 volumio volumio[25832]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:20:04 volumio volumio[25832]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:20:04 volumio volumio[25832]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:20:04 volumio volumio[25832]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:20:04 volumio volumio[25832]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:20:05 volumio go-librespot[26068]: go-librespot daemon starting... Feb 18 15:20:05 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 15:20:05 volumio sudo[26066]: pam_unix(sudo:session): session closed for user root Feb 18 15:20:05 volumio volumio[25832]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 15:20:05 volumio go-librespot[26071]: time="2026-02-18T15:20:05+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 15:20:05 volumio go-librespot[26071]: time="2026-02-18T15:20:05+07:00" level=debug msg="app state loaded" Feb 18 15:20:05 volumio go-librespot[26071]: time="2026-02-18T15:20:05+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 15:20:05 volumio volumio[25832]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:20:05 volumio volumio[25832]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:20:05 volumio volumio[25832]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:20:05 volumio volumio[25832]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:20:05 volumio volumio[25832]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:20:05 volumio volumio[25832]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:20:05 volumio volumio[25832]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:20:05 volumio volumio[25832]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:20:05 volumio volumio[25832]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:20:05 volumio volumio[25832]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 15:20:05 volumio volumio[25832]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:20:05 volumio volumio[25832]: info: No need to fix Spotify hosts Feb 18 15:20:05 volumio go-librespot[26071]: time="2026-02-18T15:20:05+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 18 15:20:05 volumio go-librespot[26071]: time="2026-02-18T15:20:05+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 18 15:20:05 volumio go-librespot[26071]: time="2026-02-18T15:20:05+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 18 15:20:05 volumio volumio[25832]: info: Starting Shairport Sync Feb 18 15:20:05 volumio go-librespot[26071]: time="2026-02-18T15:20:05+07:00" level=info msg="zeroconf server listening on port 42005" Feb 18 15:20:05 volumio volumio[25832]: info: Starting Shairport Sync Feb 18 15:20:05 volumio volumio[25832]: info: Starting Shairport Sync Feb 18 15:20:05 volumio sudo[26098]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 18 15:20:05 volumio sudo[26098]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 15:20:06 volumio sudo[26104]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 18 15:20:06 volumio sudo[26104]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 15:20:06 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 18 15:20:06 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 18 15:20:06 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 18 15:20:06 volumio systemd[1]: shairport-sync.service: Consumed 2.200s CPU time. Feb 18 15:20:06 volumio sudo[26110]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 18 15:20:06 volumio sudo[26110]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 15:20:06 volumio volumio[25832]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 18 15:20:06 volumio volumio[25832]: SPOTIFY: BQADe2wCM7err2h4jDoREe-LFRtjCGzYi9kLhVanfwJz8J2-E8rY7ME0q__mJW-g_dp4DKIrHqSROouL6mI1bmNi2MVW9auz1oBLwFRwYw-DHYWwe3kHFwHT-RGA7yelvzP4maxi98LR8kP6rT1HACqOuUclgrGK2W29uDOljbHNvCfGPRYUgupvymdySSBiBQEJXuISTtTUVF6OAckDpq7n-KE6Yxd-BR2BFx5T5e4_8zC10cW9NzuZ-OVK4Y4fWZruec6GivA27Y0hm7h_byF3VXf6kXUrLAEN3KvMwAPYl1BPCWATSt6- Feb 18 15:20:06 volumio volumio[25832]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 18 15:20:06 volumio volumio[25832]: info: New Spotify access token = BQADe2wCM7err2h4jDoREe-LFRtjCGzYi9kLhVanfwJz8J2-E8rY7ME0q__mJW-g_dp4DKIrHqSROouL6mI1bmNi2MVW9auz1oBLwFRwYw-DHYWwe3kHFwHT-RGA7yelvzP4maxi98LR8kP6rT1HACqOuUclgrGK2W29uDOljbHNvCfGPRYUgupvymdySSBiBQEJXuISTtTUVF6OAckDpq7n-KE6Yxd-BR2BFx5T5e4_8zC10cW9NzuZ-OVK4Y4fWZruec6GivA27Y0hm7h_byF3VXf6kXUrLAEN3KvMwAPYl1BPCWATSt6- Feb 18 15:20:06 volumio volumio[25832]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 18 15:20:06 volumio go-librespot[26071]: time="2026-02-18T15:20:06+07:00" level=debug msg="obtained new client token: AAB3mEb4FVvxNpW5YaDw6Kp6p6IvQ3Yvz+C9ETc4wkzB6DFaF2wFNMrALgrwLgbGIZZoekIpagYurbbwF6cV4MOoFo5pRKZMBYZo9kwdZKRNQ9LAOBiBN7soCqtsMqPLbzBAyCPDoKti252qiaWt8x+a7ZRxBuhUbJrMg7G+xyqSB0Av3PmFxOR8/K7QVr1VvhXtUKRGk/UZmMCKn6jAKsfbLAmGjdholUJcZfDsRQ5erIpKOD5FW5c=" Feb 18 15:20:06 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 18 15:20:06 volumio sudo[26098]: pam_unix(sudo:session): session closed for user root Feb 18 15:20:06 volumio go-librespot[26071]: time="2026-02-18T15:20:06+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 15:20:06 volumio volumio[25832]: info: Shairport-Sync Started Feb 18 15:20:06 volumio volumio[25832]: Error adding Membership: Error: addMembership EINVAL Feb 18 15:20:06 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 18 15:20:06 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 18 15:20:06 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 18 15:20:06 volumio go-librespot[26071]: time="2026-02-18T15:20:06+07:00" level=debug msg="completed keyexchange" Feb 18 15:20:06 volumio go-librespot[26071]: time="2026-02-18T15:20:06+07:00" level=debug msg="completed challenge" Feb 18 15:20:06 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 18 15:20:06 volumio sudo[26104]: pam_unix(sudo:session): session closed for user root Feb 18 15:20:06 volumio sudo[26110]: pam_unix(sudo:session): session closed for user root Feb 18 15:20:06 volumio volumio[25832]: info: Shairport-Sync Started Feb 18 15:20:06 volumio go-librespot[26071]: time="2026-02-18T15:20:06+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 18 15:20:06 volumio volumio[25832]: info: Shairport-Sync Started Feb 18 15:20:06 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 15:20:06 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 15:20:08 volumio volumio[25832]: info: go-librespot daemon successfully initialized Feb 18 15:20:09 volumio mpd[26058]: 2026-02-18T15:20:09 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 18 15:20:09 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 18 15:20:09 volumio sudo[26017]: pam_unix(sudo:session): session closed for user root Feb 18 15:20:09 volumio sudo[26028]: pam_unix(sudo:session): session closed for user root Feb 18 15:20:09 volumio volumio[25832]: error: MPD error: The expression evaluated to a falsy value: Feb 18 15:20:09 volumio volumio[25832]: assert.ok(self.idling) Feb 18 15:20:09 volumio volumio[25832]: error: The expression evaluated to a falsy value: Feb 18 15:20:09 volumio volumio[25832]: assert.ok(self.idling) Feb 18 15:20:09 volumio volumio[25832]: info: MPD running with PID26058 Feb 18 15:20:09 volumio volumio[25832]: ,establishing connection Feb 18 15:20:09 volumio volumio[25832]: error: updateQueue error: null Feb 18 15:20:09 volumio volumio[25832]: error: updateQueue error: null Feb 18 15:20:09 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Feb 18 15:20:09 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 15:20:09 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 15:20:09 volumio go-librespot[26157]: go-librespot daemon starting... Feb 18 15:20:09 volumio go-librespot[26158]: time="2026-02-18T15:20:09+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 15:20:09 volumio go-librespot[26158]: time="2026-02-18T15:20:09+07:00" level=debug msg="app state loaded" Feb 18 15:20:09 volumio go-librespot[26158]: time="2026-02-18T15:20:09+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 15:20:09 volumio volumio[25832]: info: CoreCommandRouter::volumioGetState Feb 18 15:20:09 volumio volumio[25832]: info: CorePlayQueue::getTrack 0 Feb 18 15:20:09 volumio volumio[25832]: 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 18 15:20:09 volumio volumio[25832]: info: Spotify Successfully logged in Feb 18 15:20:09 volumio volumio[25832]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 15:20:09 volumio volumio[25832]: info: [1771402809998] CoreMusicLibrary::Adding element Spotify Feb 18 15:20:10 volumio volumio[25832]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 15:20:10 volumio volumio[25832]: Cannot find translation for source YouTube Music Feb 18 15:20:10 volumio volumio[25832]: Cannot find translation for source Spotify Feb 18 15:20:10 volumio go-librespot[26158]: time="2026-02-18T15:20: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 18 15:20:10 volumio go-librespot[26158]: time="2026-02-18T15:20: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 18 15:20:10 volumio go-librespot[26158]: time="2026-02-18T15:20: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 18 15:20:10 volumio go-librespot[26158]: time="2026-02-18T15:20:10+07:00" level=info msg="zeroconf server listening on port 36761" Feb 18 15:20:10 volumio go-librespot[26158]: time="2026-02-18T15:20:10+07:00" level=debug msg="obtained new client token: AADrpxzI0KsWr9LBTDCnYZ1pvzy+BPxJQFj+MTdaBZVO/5kiKZ08jAAjh1QxV4IU655kGs2WmAOkKStvpPp+Q4gJcAunwsjtgh7bfiznE8rrloOSH4LpA3/JzHKnjzgtd4aH4z5om0yKGpG7s+SsWPTnlhUokVG2HkA14Pw6yjqGSUyINDVBRrW9TVlRSDWU6/SuasbyK9yK/4oNLGerWE+YiwZqDdlS/X10oZ20zF+cMnUwl7UeMY5Dgw==" Feb 18 15:20:10 volumio go-librespot[26158]: time="2026-02-18T15:20:10+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 15:20:10 volumio go-librespot[26158]: time="2026-02-18T15:20:10+07:00" level=debug msg="completed keyexchange" Feb 18 15:20:10 volumio go-librespot[26158]: time="2026-02-18T15:20:10+07:00" level=debug msg="completed challenge" Feb 18 15:20:10 volumio go-librespot[26158]: time="2026-02-18T15:20:10+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 18 15:20:10 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 15:20:10 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 15:20:10 volumio volumio[25832]: info: [yt-cast-receiver] DIAL server listening on port 8098 Feb 18 15:20:10 volumio volumio[25832]: info: CoreCommandRouter::volumioRetrievevolume Feb 18 15:20:11 volumio volumio[25832]: info: VolumeController:: Volume=100 Mute =false Feb 18 15:20:11 volumio volumio[25832]: info: CoreCommandRouter::volumioGetState Feb 18 15:20:11 volumio volumio[25832]: info: CorePlayQueue::getTrack 0 Feb 18 15:20:11 volumio volumio[25832]: info: CoreStateMachine::pushState Feb 18 15:20:11 volumio volumio[25832]: info: CorePlayQueue::getTrack 0 Feb 18 15:20:11 volumio volumio[25832]: info: CoreCommandRouter::volumioPushState Feb 18 15:20:11 volumio volumio[25832]: info: Completed starting Core Plugins Feb 18 15:20:11 volumio volumio[25832]: info: ------------------------------------------- Feb 18 15:20:11 volumio volumio[25832]: info: ----- MyVolumio plugins startup ---- Feb 18 15:20:11 volumio volumio[25832]: info: ------------------------------------------- Feb 18 15:20:11 volumio volumio[25832]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 18 15:20:11 volumio volumio[25832]: info: Initializing connection to go-librespot Websocket Feb 18 15:20:11 volumio volumio[25832]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 18 15:20:14 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Feb 18 15:20:14 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 15:20:14 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 15:20:14 volumio go-librespot[26168]: go-librespot daemon starting... Feb 18 15:20:14 volumio go-librespot[26169]: time="2026-02-18T15:20:14+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 15:20:14 volumio go-librespot[26169]: time="2026-02-18T15:20:14+07:00" level=debug msg="app state loaded" Feb 18 15:20:14 volumio go-librespot[26169]: time="2026-02-18T15:20:14+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 15:20:14 volumio volumio[25832]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 18 15:20:14 volumio go-librespot[26169]: time="2026-02-18T15:20:14+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 15:20:14 volumio go-librespot[26169]: time="2026-02-18T15:20:14+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 18 15:20:14 volumio go-librespot[26169]: time="2026-02-18T15:20:14+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 18 15:20:14 volumio go-librespot[26169]: time="2026-02-18T15:20:14+07:00" level=info msg="zeroconf server listening on port 38379" Feb 18 15:20:14 volumio go-librespot[26169]: time="2026-02-18T15:20:14+07:00" level=debug msg="obtained new client token: AAAZI3MHRxSxq5dLFmlix4/9gBsXYyHnwYvhtOqF+2ox9zKn3VHxa1HM9A3LtxjY8mYnNdvHb2Aee/AF62JBKZNU8zZmNxGHnb4PL+tZx56UU7z92wXUwBEAIYvlt0D+b/eyPBtrV1bu9o3oPidZSkFnz9dBTjdgrMKxpGPh0BCQ0a9SvIFTQE+0scs/4ZfOsbNUwtxKfVn4oqp+17B4GmUIfJ+Wl/y4RVXMjmv2P+N+fhoo+3XSD60mfQ==" Feb 18 15:20:14 volumio volumio[25832]: info: Initializing connection to go-librespot Websocket Feb 18 15:20:14 volumio go-librespot[26169]: time="2026-02-18T15:20:14+07:00" level=debug msg="new websocket client" Feb 18 15:20:14 volumio volumio[25832]: info: Connection to go-librespot Websocket established Feb 18 15:20:14 volumio go-librespot[26169]: time="2026-02-18T15:20:14+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 15:20:15 volumio go-librespot[26169]: time="2026-02-18T15:20:15+07:00" level=debug msg="completed keyexchange" Feb 18 15:20:15 volumio go-librespot[26169]: time="2026-02-18T15:20:15+07:00" level=debug msg="completed challenge" Feb 18 15:20:15 volumio go-librespot[26169]: time="2026-02-18T15:20: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 18 15:20:15 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 15:20:15 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 15:20:15 volumio volumio[25832]: info: Connection to go-librespot Websocket closed Feb 18 15:20:17 volumio volumio[25832]: info: Getting Spotify volume Feb 18 15:20:17 volumio volumio[25832]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 18 15:20:17 volumio volumio[25832]: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 18 15:20:17 volumio volumio[25832]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Feb 18 15:20:17 volumio volumio[25832]: errno: -111, Feb 18 15:20:17 volumio volumio[25832]: code: 'ECONNREFUSED', Feb 18 15:20:17 volumio volumio[25832]: syscall: 'connect', Feb 18 15:20:17 volumio volumio[25832]: address: '127.0.0.1', Feb 18 15:20:17 volumio volumio[25832]: port: 9879, Feb 18 15:20:17 volumio volumio[25832]: response: undefined Feb 18 15:20:17 volumio volumio[25832]: } Feb 18 15:20:17 volumio volumio[25832]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 18 15:20:18 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 11. Feb 18 15:20:18 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 15:20:18 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 15:20:18 volumio go-librespot[26188]: go-librespot daemon starting... Feb 18 15:20:18 volumio go-librespot[26189]: time="2026-02-18T15:20:18+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 15:20:18 volumio go-librespot[26189]: time="2026-02-18T15:20:18+07:00" level=debug msg="app state loaded" Feb 18 15:20:18 volumio go-librespot[26189]: time="2026-02-18T15:20:18+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 15:20:18 volumio go-librespot[26189]: time="2026-02-18T15:20:18+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 15:20:18 volumio go-librespot[26189]: time="2026-02-18T15:20:18+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 18 15:20:18 volumio go-librespot[26189]: time="2026-02-18T15:20:18+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 18 15:20:18 volumio go-librespot[26189]: time="2026-02-18T15:20:18+07:00" level=info msg="zeroconf server listening on port 44901" Feb 18 15:20:19 volumio go-librespot[26189]: time="2026-02-18T15:20:19+07:00" level=debug msg="obtained new client token: AAD/u6RhHh3vzeeDQFPeH6QENA4YgVq24hGRvFSNi20MxyzZyt3Gi7xB8zUwpS0LICfGvygX+lM8DzNO2i0nGziyzT9p/8NqGqJeez+5INKE4J+S0f9g51kMAhILRykojlCkwIxtztSTJyQlC+HgAUUbrv0djojFsoy3TH+DrPv2prpuBK1AfvCL/beN1p3QDesjtLUs9EFSoYGK4hxDjRhJhhBFSP7XiY59iCdnWq980n53fiRX6zc=" Feb 18 15:20:19 volumio go-librespot[26189]: time="2026-02-18T15:20:19+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 15:20:19 volumio go-librespot[26189]: time="2026-02-18T15:20:19+07:00" level=debug msg="completed keyexchange" Feb 18 15:20:19 volumio go-librespot[26189]: time="2026-02-18T15:20:19+07:00" level=debug msg="completed challenge" Feb 18 15:20:19 volumio sudo[26213]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-18 15:19' Feb 18 15:20:19 volumio sudo[26213]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 15:20:19 volumio go-librespot[26189]: time="2026-02-18T15:20:19+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 18 15:20:19 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 15:20:19 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 15:20:19 volumio sudo[26213]: pam_unix(sudo:session): session closed for user root Feb 18 15:20:19 volumio volumio-remote-updater[25144]: [2026-02-18 15:20:19] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Feb 18 15:20:19 volumio volumio-remote-updater[25144]: [2026-02-18 15:20:19] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Feb 18 15:20:19 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Feb 18 15:20:19 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Feb 18 15:20:19 volumio systemd[1]: volumio.service: Consumed 48.461s CPU time. Feb 18 15:20:19 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 18 15:20:20 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 18 15:20:20 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 22068. Feb 18 15:20:20 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 18 15:20:20 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Feb 18 15:20:20 volumio systemd[1]: volumio.service: Consumed 48.461s CPU time. Feb 18 15:20:20 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Feb 18 15:20:20 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 18 15:20:22 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 12. Feb 18 15:20:22 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 15:20:22 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 15:20:22 volumio go-librespot[26242]: go-librespot daemon starting... Feb 18 15:20:22 volumio go-librespot[26243]: time="2026-02-18T15:20:22+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 15:20:22 volumio go-librespot[26243]: time="2026-02-18T15:20:22+07:00" level=debug msg="app state loaded" Feb 18 15:20:22 volumio go-librespot[26243]: time="2026-02-18T15:20:22+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 15:20:23 volumio go-librespot[26243]: time="2026-02-18T15:20:23+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 15:20:23 volumio go-librespot[26243]: time="2026-02-18T15:20:23+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 18 15:20:23 volumio go-librespot[26243]: time="2026-02-18T15:20:23+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 18 15:20:23 volumio go-librespot[26243]: time="2026-02-18T15:20:23+07:00" level=info msg="zeroconf server listening on port 34741" Feb 18 15:20:23 volumio go-librespot[26243]: time="2026-02-18T15:20:23+07:00" level=debug msg="obtained new client token: AABRu2IfAcTRock/J7MzM9roIJo5imMESpeE4RC3iDsWQwmf8sKFZtz1V1c6RYnfS9AKEk+bnSUHiXnN8r8ckV7haY47hkL51IPWHUZSvzT16dHa+qQqkfyEgsg/UAj/TRhnmb8EHu9rrFQsgFv1QDmjJ4OmWdabN3JVkDP9nK/4dOwoRM5QMstJGqyyS2dh4UgoSogii0RHGBeJygVUXnXngWhueEbPKUBAoRVNkcQKrlXHGALtM2tGtQ==" Feb 18 15:20:23 volumio go-librespot[26243]: time="2026-02-18T15:20:23+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 15:20:23 volumio go-librespot[26243]: time="2026-02-18T15:20:23+07:00" level=debug msg="completed keyexchange" Feb 18 15:20:23 volumio go-librespot[26243]: time="2026-02-18T15:20:23+07:00" level=debug msg="completed challenge" Feb 18 15:20:23 volumio volumio[26227]: info: ------------------------------------------- Feb 18 15:20:23 volumio volumio[26227]: info: ----- Volumio3 ---- Feb 18 15:20:23 volumio volumio[26227]: info: ------------------------------------------- Feb 18 15:20:23 volumio go-librespot[26243]: time="2026-02-18T15:20:23+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 18 15:20:23 volumio volumio[26227]: info: ----- System startup ---- Feb 18 15:20:23 volumio volumio[26227]: info: ------------------------------------------- Feb 18 15:20:23 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 15:20:23 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 15:20:24 volumio volumio-remote-updater[25144]: [2026-02-18 15:20:24] [connect] Successful connection Feb 18 15:20:25 volumio volumio[26227]: info: MYVOLUMIO Environment detected Feb 18 15:20:25 volumio volumio[26227]: info: Plugin folders cleanup Feb 18 15:20:25 volumio volumio[26227]: info: Scanning into folder /volumio/app/plugins/ Feb 18 15:20:25 volumio volumio[26227]: info: Scanning category audio_interface Feb 18 15:20:25 volumio volumio[26227]: info: Scanning category miscellanea Feb 18 15:20:25 volumio volumio[26227]: info: Scanning category music_service Feb 18 15:20:25 volumio volumio[26227]: info: Scanning category plugins.json Feb 18 15:20:25 volumio volumio[26227]: info: Scanning category system_controller Feb 18 15:20:25 volumio volumio[26227]: info: Scanning category user_interface Feb 18 15:20:25 volumio volumio[26227]: info: Scanning into folder /data/plugins/ Feb 18 15:20:25 volumio volumio[26227]: info: Scanning category music_service Feb 18 15:20:25 volumio volumio[26227]: info: Plugin folders cleanup completed Feb 18 15:20:25 volumio volumio[26227]: info: ------------------------------------------- Feb 18 15:20:25 volumio volumio[26227]: info: ----- Core plugins startup ---- Feb 18 15:20:25 volumio volumio[26227]: info: ------------------------------------------- Feb 18 15:20:25 volumio volumio[26227]: info: Loading plugins from folder /volumio/app/plugins/ Feb 18 15:20:25 volumio volumio[26227]: info: Adding plugin upnp to MyMusic Plugins Feb 18 15:20:25 volumio volumio[26227]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 18 15:20:25 volumio volumio[26227]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 18 15:20:25 volumio volumio[26227]: info: Loading plugins from folder /data/plugins/ Feb 18 15:20:25 volumio volumio[26227]: info: Loading plugin "system"... Feb 18 15:20:25 volumio volumio[26227]: info: Loading plugin "appearance"... Feb 18 15:20:26 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 13. Feb 18 15:20:26 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 15:20:26 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 15:20:26 volumio go-librespot[26263]: go-librespot daemon starting... Feb 18 15:20:26 volumio go-librespot[26264]: time="2026-02-18T15:20:26+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 15:20:26 volumio go-librespot[26264]: time="2026-02-18T15:20:26+07:00" level=debug msg="app state loaded" Feb 18 15:20:26 volumio go-librespot[26264]: time="2026-02-18T15:20:26+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 15:20:27 volumio volumio[26227]: info: Loading plugin "network"... Feb 18 15:20:27 volumio volumio[26227]: info: Refreshing Cached IP Addresses Feb 18 15:20:27 volumio sudo[26271]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 18 15:20:27 volumio sudo[26271]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 15:20:27 volumio sudo[26273]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 18 15:20:27 volumio sudo[26273]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 15:20:27 volumio sudo[26271]: pam_unix(sudo:session): session closed for user root Feb 18 15:20:27 volumio volumio[26227]: info: Loading plugin "services"... Feb 18 15:20:27 volumio sudo[26273]: pam_unix(sudo:session): session closed for user root Feb 18 15:20:27 volumio volumio[26227]: info: Loading plugin "alsa_controller"... Feb 18 15:20:27 volumio sudo[26282]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 18 15:20:27 volumio sudo[26282]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 15:20:27 volumio volumio[26227]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 18 15:20:27 volumio volumio[26227]: info: Loading plugin "wizard"... Feb 18 15:20:27 volumio volumio[26227]: info: Loading plugin "networkfs"... Feb 18 15:20:27 volumio go-librespot[26264]: time="2026-02-18T15:20:27+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 15:20:27 volumio go-librespot[26264]: time="2026-02-18T15:20:27+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 18 15:20:27 volumio go-librespot[26264]: time="2026-02-18T15:20:27+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 18 15:20:27 volumio volumio[26227]: info: Starting Udev Watcher for removable devices Feb 18 15:20:27 volumio go-librespot[26264]: time="2026-02-18T15:20:27+07:00" level=info msg="zeroconf server listening on port 45265" Feb 18 15:20:27 volumio volumio[26227]: info: Ignoring mount for partition: boot Feb 18 15:20:27 volumio volumio[26227]: info: Ignoring mount for partition: volumio Feb 18 15:20:27 volumio volumio[26227]: info: Ignoring mount for partition: volumio_data Feb 18 15:20:27 volumio volumio[26227]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 18 15:20:27 volumio volumio[26227]: info: Loading plugin "volumio_command_line_client"... Feb 18 15:20:27 volumio volumio[26227]: info: Loading plugin "upnp"... Feb 18 15:20:27 volumio volumio[26227]: info: [1771402827644] Starting Upmpd Daemon Feb 18 15:20:27 volumio volumio[26227]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 18 15:20:27 volumio volumio[26227]: info: Loading plugin "my_music"... Feb 18 15:20:27 volumio volumio[26227]: info: Loading plugin "mpd"... Feb 18 15:20:27 volumio go-librespot[26264]: time="2026-02-18T15:20:27+07:00" level=debug msg="obtained new client token: AAAAqkS7WQfkLz1X+qKmVMxvPC6wk7qD89kpmUSC/MesaAPp30vna/bFhh+WLm87/yY1KIF2V8f7SiHOp4SLDT3pcvDG+QV0ngEJYj/CyukzYwd6/k2jITPkO9+AnXOXPQJNniphhuioOMfRKkyxbI/MojNCKiQnIYhckpsP97sMVAc7qCPZ3zI9McWnb+qgESt46l7Q90IBchdwvXXno2YX93hlhbj1KJsh86s6ExpNYtZwYassB3DPNg==" Feb 18 15:20:27 volumio go-librespot[26264]: time="2026-02-18T15:20:27+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 18 15:20:27 volumio go-librespot[26264]: time="2026-02-18T15:20:27+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Feb 18 15:20:28 volumio go-librespot[26264]: time="2026-02-18T15:20:28+07:00" level=debug msg="completed keyexchange" Feb 18 15:20:28 volumio go-librespot[26264]: time="2026-02-18T15:20:28+07:00" level=debug msg="completed challenge" Feb 18 15:20:28 volumio go-librespot[26264]: time="2026-02-18T15:20: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 18 15:20:28 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 15:20:28 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 15:20:28 volumio volumio[26227]: info: Loading plugin "upnp_browser"... Feb 18 15:20:30 volumio sudo[26282]: pam_unix(sudo:session): session closed for user root Feb 18 15:20:31 volumio volumio[26227]: info: Starting UPNP Browser Feb 18 15:20:31 volumio volumio[26227]: info: Loading plugin "alarm-clock"... Feb 18 15:20:31 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 14. Feb 18 15:20:31 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 15:20:31 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 15:20:31 volumio go-librespot[26305]: go-librespot daemon starting... Feb 18 15:20:31 volumio go-librespot[26306]: time="2026-02-18T15:20:31+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 15:20:31 volumio go-librespot[26306]: time="2026-02-18T15:20:31+07:00" level=debug msg="app state loaded" Feb 18 15:20:31 volumio go-librespot[26306]: time="2026-02-18T15:20:31+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 15:20:31 volumio volumio[26227]: info: Loading plugin "airplay_emulation"... Feb 18 15:20:31 volumio volumio[26227]: info: Starting Shairport Sync Feb 18 15:20:31 volumio volumio[26227]: info: Loading plugin "last_100"... Feb 18 15:20:31 volumio volumio[26227]: info: Loading plugin "webradio"... Feb 18 15:20:31 volumio volumio[26227]: info: Loading plugin "i2s_dacs"... Feb 18 15:20:31 volumio volumio[26227]: info: Loading plugin "volumiodiscovery"... Feb 18 15:20:31 volumio volumio[26227]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 18 15:20:31 volumio volumio[26227]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 18 15:20:31 volumio volumio[26227]: *** WARNING *** For more information see Feb 18 15:20:31 volumio volumio[26227]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 18 15:20:31 volumio volumio[26227]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 18 15:20:31 volumio volumio[26227]: *** WARNING *** For more information see Feb 18 15:20:31 volumio node[26227]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 18 15:20:31 volumio node[26227]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 18 15:20:31 volumio node[26227]: *** WARNING *** For more information see Feb 18 15:20:31 volumio node[26227]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 18 15:20:31 volumio node[26227]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 18 15:20:31 volumio node[26227]: *** WARNING *** For more information see Feb 18 15:20:31 volumio volumio[26227]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 18 15:20:31 volumio volumio[26227]: info: Discovery: Started advertising with name: Volumio Feb 18 15:20:31 volumio volumio[26227]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 18 15:20:31 volumio volumio[26227]: info: Loading plugin "spop"... Feb 18 15:20:32 volumio go-librespot[26306]: time="2026-02-18T15:20:32+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 15:20:32 volumio go-librespot[26306]: time="2026-02-18T15:20:32+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 18 15:20:32 volumio go-librespot[26306]: time="2026-02-18T15:20:32+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 18 15:20:32 volumio go-librespot[26306]: time="2026-02-18T15:20:32+07:00" level=info msg="zeroconf server listening on port 37591" Feb 18 15:20:32 volumio go-librespot[26306]: time="2026-02-18T15:20:32+07:00" level=debug msg="obtained new client token: AABLbIJRiloGtFsF65v0elBES3X9ooNdoJhWgVfrVCoJSkCybx2I9x1FvTJkdYD5AV3HKbqFGGrfpbq1LwEOaZji8pFyk9o9b7vA2c2cepEAAogTCnVlgcAqCnz1LJPhK/T4K30Axd92EewGWoSeNYo5dVa6v5Lk0l4vD4zU181sELHZcxp5YbekqjtmAJdCL3HlDoBcadz0G7t4K+s6O8QIchZTf1uAnn/DihEK42I3lFaxjnDG/rM=" Feb 18 15:20:32 volumio go-librespot[26306]: time="2026-02-18T15:20:32+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 15:20:32 volumio go-librespot[26306]: time="2026-02-18T15:20:32+07:00" level=debug msg="completed keyexchange" Feb 18 15:20:32 volumio go-librespot[26306]: time="2026-02-18T15:20:32+07:00" level=debug msg="completed challenge" Feb 18 15:20:32 volumio go-librespot[26306]: time="2026-02-18T15:20:32+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 18 15:20:32 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 15:20:32 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 15:20:33 volumio volumio[26227]: info: Loading plugin "ytcr"... Feb 18 15:20:35 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 15. Feb 18 15:20:35 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 15:20:35 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 15:20:35 volumio go-librespot[26315]: go-librespot daemon starting... Feb 18 15:20:35 volumio go-librespot[26316]: time="2026-02-18T15:20:35+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 15:20:35 volumio go-librespot[26316]: time="2026-02-18T15:20:35+07:00" level=debug msg="app state loaded" Feb 18 15:20:35 volumio go-librespot[26316]: time="2026-02-18T15:20:35+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 15:20:36 volumio go-librespot[26316]: time="2026-02-18T15:20: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 18 15:20:36 volumio go-librespot[26316]: time="2026-02-18T15:20: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 18 15:20:36 volumio go-librespot[26316]: time="2026-02-18T15:20: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 18 15:20:36 volumio volumio[26227]: info: Loading plugin "ytmusic"... Feb 18 15:20:36 volumio go-librespot[26316]: time="2026-02-18T15:20:36+07:00" level=info msg="zeroconf server listening on port 38787" Feb 18 15:20:36 volumio go-librespot[26316]: time="2026-02-18T15:20:36+07:00" level=debug msg="obtained new client token: AADykB8oqfI4ofzHrfnhqgTV4nsSZdst2/6c+rrmTpTEOUmbVGTDUn8AcLrsT5/w9R5jQlamCGTxfPfEQjqrbVahJkDxd7mFk8Csca0qNI+PO/AntWCmwb8fyr984+1sYrZ+QVIeZm5Nc2+CpH7uNvLKL+52YqsQfeWZ/YlJRtnvnOmkz/vdYgPc0Ep1KrHcnuebZzgcPGM/oqmGSORJIVDrcspGpsootpnp1FxCSNXsbQxaxXmRj4JkHg==" Feb 18 15:20:36 volumio go-librespot[26316]: time="2026-02-18T15:20:36+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 15:20:36 volumio go-librespot[26316]: time="2026-02-18T15:20:36+07:00" level=debug msg="completed keyexchange" Feb 18 15:20:36 volumio go-librespot[26316]: time="2026-02-18T15:20:36+07:00" level=debug msg="completed challenge" Feb 18 15:20:37 volumio go-librespot[26316]: time="2026-02-18T15:20: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 18 15:20:37 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 15:20:37 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 15:20:37 volumio volumio-remote-updater[25144]: [2026-02-18 15:20:37] [connect] Successful connection Feb 18 15:20:37 volumio volumio[26227]: info: Loading plugin "outputs"... Feb 18 15:20:37 volumio volumio[26227]: info: Loading plugin "albumart"... Feb 18 15:20:37 volumio volumio[26227]: info: Plugin example_plugin is not enabled Feb 18 15:20:37 volumio volumio[26227]: info: Loading plugin "inputs"... Feb 18 15:20:37 volumio volumio[26227]: info: Loading plugin "updater_comm"... Feb 18 15:20:37 volumio volumio[26227]: info: Plugin mpdemulation is not enabled Feb 18 15:20:37 volumio volumio[26227]: info: Loading plugin "rest_api"... Feb 18 15:20:38 volumio volumio[26227]: info: Loading plugin "websocket"... Feb 18 15:20:38 volumio volumio[26227]: info: Starting Socket.io Server version 1.7.4 Feb 18 15:20:38 volumio volumio[26227]: info: Loading plugin "RoonBridge"... Feb 18 15:20:38 volumio volumio[26227]: info: Applying required configuration parameters for plugin RoonBridge Feb 18 15:20:38 volumio volumio[26227]: info: Loading i18n strings for locale en Feb 18 15:20:38 volumio volumio[26227]: Updating browse sources language Feb 18 15:20:38 volumio volumio[26227]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 15:20:38 volumio volumio[26337]: Forking 3 albumart workers Feb 18 15:20:38 volumio volumio[26227]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 18 15:20:38 volumio volumio[26227]: info: CoreCommandRouter::initPlayerControls Feb 18 15:20:38 volumio volumio[26227]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:20:38 volumio volumio[26227]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:20:38 volumio volumio[26227]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:20:38 volumio volumio[26227]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:20:38 volumio volumio[26227]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:20:38 volumio volumio[26227]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:20:38 volumio volumio[26227]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:20:38 volumio volumio[26227]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:20:38 volumio volumio[26227]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 18 15:20:38 volumio volumio[26227]: Express server listening on port 3000 Feb 18 15:20:38 volumio volumio[26227]: [Metrics] WebUI: 16s 106.64ms Feb 18 15:20:38 volumio volumio[26227]: info: CoreStateMachine::resetVolumioState Feb 18 15:20:38 volumio volumio[26227]: info: CoreStateMachine::getcurrentVolume Feb 18 15:20:38 volumio volumio[26227]: info: CoreCommandRouter::volumioRetrievevolume Feb 18 15:20:39 volumio sudo[26382]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 18 15:20:39 volumio sudo[26382]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 15:20:39 volumio volumio[26227]: info: Volumio Network Manager: Network status updated: 1 Feb 18 15:20:39 volumio sudo[26382]: pam_unix(sudo:session): session closed for user root Feb 18 15:20:39 volumio sudo[26384]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 18 15:20:39 volumio sudo[26384]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 15:20:39 volumio sudo[26384]: pam_unix(sudo:session): session closed for user root Feb 18 15:20:39 volumio volumio-remote-updater[25144]: [2026-02-18 15:20:39] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1771402837 101 Feb 18 15:20:39 volumio volumio[26227]: 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 18 15:20:39 volumio volumio[26227]: info: VolumeController:: Volume=100 Mute =false Feb 18 15:20:39 volumio volumio[26227]: info: CoreStateMachine::pushState Feb 18 15:20:39 volumio volumio[26227]: info: CorePlayQueue::getTrack 0 Feb 18 15:20:39 volumio volumio[26227]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 18 15:20:39 volumio volumio[26227]: info: CoreCommandRouter::volumioPushState Feb 18 15:20:39 volumio volumio[26227]: info: CoreStateMachine::updateTrackBlock Feb 18 15:20:39 volumio volumio[26227]: info: CorePlayQueue::getTrackBlock Feb 18 15:20:39 volumio volumio[26227]: info: CoreCommandRouter::volumioRetrievevolume Feb 18 15:20:39 volumio volumio[26227]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 15:20:39 volumio volumio[26227]: info: Reloading queue from file Feb 18 15:20:39 volumio volumio[26227]: info: CoreStateMachine::setRepeat null single undefined Feb 18 15:20:39 volumio volumio[26227]: info: CoreStateMachine::pushState Feb 18 15:20:39 volumio volumio[26227]: info: CorePlayQueue::getTrack 0 Feb 18 15:20:39 volumio volumio[26227]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 18 15:20:39 volumio volumio[26227]: info: CoreCommandRouter::volumioPushState Feb 18 15:20:39 volumio volumio[26227]: info: CoreStateMachine::setRandom null Feb 18 15:20:39 volumio volumio[26227]: info: CoreStateMachine::pushState Feb 18 15:20:39 volumio volumio[26227]: info: CorePlayQueue::getTrack 0 Feb 18 15:20:39 volumio volumio[26227]: info: CoreCommandRouter::volumioPushState Feb 18 15:20:39 volumio volumio[26227]: info: Setting Device type: Raspberry PI Feb 18 15:20:39 volumio volumio[26227]: info: Completed loading Core Plugins Feb 18 15:20:39 volumio volumio[26227]: info: Preparing to generate the ALSA configuration file Feb 18 15:20:39 volumio volumio[26227]: info: VolumeController:: Volume=100 Mute =false Feb 18 15:20:39 volumio volumio[26227]: info: CoreStateMachine::pushState Feb 18 15:20:39 volumio volumio[26227]: info: CorePlayQueue::getTrack 0 Feb 18 15:20:39 volumio volumio[26227]: info: CoreCommandRouter::volumioPushState Feb 18 15:20:39 volumio volumio[26227]: info: Asound.conf file unchanged, so no further update is needed Feb 18 15:20:39 volumio volumio[26227]: info: Output device has changed, restarting MPD Feb 18 15:20:39 volumio sudo[26397]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 18 15:20:39 volumio sudo[26397]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 15:20:39 volumio volumio[26227]: info: Output device has changed, restarting Shairport Sync Feb 18 15:20:39 volumio volumio[26227]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:20:39 volumio volumio[26227]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 15:20:40 volumio sudo[26403]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 18 15:20:40 volumio sudo[26403]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 15:20:40 volumio sudo[26399]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 18 15:20:40 volumio sudo[26399]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 15:20:40 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 16. Feb 18 15:20:40 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 15:20:40 volumio sudo[26399]: pam_unix(sudo:session): session closed for user root Feb 18 15:20:40 volumio sudo[26397]: pam_unix(sudo:session): session closed for user root Feb 18 15:20:40 volumio volumio[26227]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 18 15:20:40 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 15:20:40 volumio go-librespot[26409]: go-librespot daemon starting... Feb 18 15:20:40 volumio volumio[26227]: info: ___________ START PLUGINS ___________ Feb 18 15:20:40 volumio volumio[26227]: info: ControllerMpd::onStart: Initializing MPD Feb 18 15:20:40 volumio volumio[26227]: info: Creating MPD Configuration file Feb 18 15:20:40 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 18 15:20:40 volumio go-librespot[26410]: time="2026-02-18T15:20:40+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 15:20:40 volumio go-librespot[26410]: time="2026-02-18T15:20:40+07:00" level=debug msg="app state loaded" Feb 18 15:20:40 volumio go-librespot[26410]: time="2026-02-18T15:20:40+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 15:20:40 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 18 15:20:40 volumio sudo[26417]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 18 15:20:40 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 18 15:20:40 volumio sudo[26417]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 15:20:40 volumio systemd[1]: mpd.service: Consumed 6.715s CPU time. Feb 18 15:20:40 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 18 15:20:40 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 18 15:20:40 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 18 15:20:40 volumio sudo[26419]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 18 15:20:40 volumio sudo[26419]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 15:20:40 volumio volumio[26227]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 18 15:20:40 volumio volumio[26227]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 15:20:40 volumio volumio[26227]: info: [1771402840443] CoreMusicLibrary::Adding element Media Servers Feb 18 15:20:40 volumio volumio[26227]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 15:20:40 volumio sudo[26417]: pam_unix(sudo:session): session closed for user root Feb 18 15:20:40 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 18 15:20:40 volumio volumio[26227]: info: UPNP Browser: Client initialized successfully Feb 18 15:20:40 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 18 15:20:40 volumio volumio[26227]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:20:40 volumio volumio[26227]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 15:20:40 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 18 15:20:40 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 18 15:20:40 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 18 15:20:40 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 18 15:20:40 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 18 15:20:40 volumio volumio[26227]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 18 15:20:40 volumio volumio[26227]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:20:40 volumio volumio[26227]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 15:20:40 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 18 15:20:40 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 18 15:20:40 volumio volumio[26227]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 18 15:20:40 volumio volumio[26227]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 15:20:40 volumio volumio[26227]: info: [1771402840880] CoreMusicLibrary::Adding element Last_100 Feb 18 15:20:40 volumio volumio[26227]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 15:20:40 volumio volumio[26227]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 15:20:40 volumio volumio[26227]: info: [1771402840907] CoreMusicLibrary::Adding element Webradio Feb 18 15:20:40 volumio volumio[26227]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 15:20:40 volumio volumio[26227]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 18 15:20:40 volumio volumio[26227]: info: Initializing BBC Radios Feb 18 15:20:41 volumio go-librespot[26410]: time="2026-02-18T15:20:41+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 15:20:41 volumio go-librespot[26410]: time="2026-02-18T15:20:41+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 18 15:20:41 volumio go-librespot[26410]: time="2026-02-18T15:20:41+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 18 15:20:41 volumio go-librespot[26410]: time="2026-02-18T15:20:41+07:00" level=info msg="zeroconf server listening on port 39305" Feb 18 15:20:41 volumio volumio[26227]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 18 15:20:41 volumio volumio[26227]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 15:20:41 volumio volumio[26227]: info: Creating Spotify config file Feb 18 15:20:41 volumio volumio[26227]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:20:41 volumio sudo[26432]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 18 15:20:41 volumio sudo[26432]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 18 15:20:41 volumio sudo[26432]: pam_unix(sudo:session): session closed for user root Feb 18 15:20:41 volumio go-librespot[26410]: time="2026-02-18T15:20:41+07:00" level=debug msg="obtained new client token: AAAJPLJDeE2l37b04BEdYAifUbNq8BJfKABxrjkwFs37on29jbbS/UOGP44Bj2vO0zp0KVSO4ekhoMnQpoB2OF14eM7fP/p75BOzhHZ3j504Duh6JgBo7m4N70cVyX2UZPyWwaNGREif+5Djq1gzpywDaLZkJX9dU9nZhPe2JBcQd78Fmhv8Y5itn6ebVEAVnhnBbbSdTnAtPZTv2CreNIHS+uA/zBvomPU5d5ncUEXU7QwImM1mX8iaiw==" Feb 18 15:20:41 volumio go-librespot[26410]: time="2026-02-18T15:20:41+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 15:20:41 volumio go-librespot[26410]: time="2026-02-18T15:20:41+07:00" level=debug msg="completed keyexchange" Feb 18 15:20:41 volumio go-librespot[26410]: time="2026-02-18T15:20:41+07:00" level=debug msg="completed challenge" Feb 18 15:20:41 volumio go-librespot[26410]: time="2026-02-18T15:20: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 18 15:20:41 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 15:20:41 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 15:20:41 volumio volumio[26349]: Starting albumart workers Feb 18 15:20:42 volumio volumio[26348]: Starting albumart workers Feb 18 15:20:42 volumio volumio[26227]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 15:20:42 volumio volumio[26227]: info: [1771402842284] CoreMusicLibrary::Adding element YouTube Music Feb 18 15:20:42 volumio volumio[26227]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 15:20:42 volumio volumio[26227]: Cannot find translation for source YouTube Music Feb 18 15:20:42 volumio volumio[26227]: info: Volumio Calling Home Feb 18 15:20:42 volumio sudo[26451]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Feb 18 15:20:42 volumio volumio[26347]: Starting albumart workers Feb 18 15:20:42 volumio sudo[26451]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 15:20:42 volumio sudo[26451]: pam_unix(sudo:session): session closed for user root Feb 18 15:20:43 volumio volumio[26227]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Feb 18 15:20:43 volumio volumio[26227]: info: Discovery: Found device Volumio Feb 18 15:20:43 volumio volumio[26227]: info: CoreCommandRouter::volumioGetState Feb 18 15:20:43 volumio volumio[26227]: info: CorePlayQueue::getTrack 0 Feb 18 15:20:43 volumio volumio[26227]: info: MPD Permissions set Feb 18 15:20:43 volumio volumio[26227]: info: MPD Permissions set Feb 18 15:20:43 volumio volumio[26227]: info: Upmpdcli Daemon Started Feb 18 15:20:43 volumio volumio[26227]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Feb 18 15:20:43 volumio volumio[26227]: info: Discovery: Found device Volumio Feb 18 15:20:43 volumio volumio[26227]: info: CoreCommandRouter::volumioGetState Feb 18 15:20:43 volumio volumio[26227]: info: CorePlayQueue::getTrack 0 Feb 18 15:20:43 volumio volumio[26227]: info: Spotify config file written Feb 18 15:20:43 volumio volumio[26227]: 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 18 15:20:43 volumio sudo[26459]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 18 15:20:43 volumio volumio[26227]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:20:43 volumio volumio[26227]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:20:43 volumio volumio[26227]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:20:43 volumio volumio[26227]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:20:43 volumio volumio[26227]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:20:43 volumio volumio[26227]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:20:43 volumio volumio[26227]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:20:43 volumio volumio[26227]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:20:43 volumio sudo[26459]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 15:20:43 volumio volumio[26227]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 15:20:43 volumio volumio[26227]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:20:43 volumio volumio[26227]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:20:43 volumio volumio[26227]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:20:43 volumio volumio[26227]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:20:43 volumio volumio[26227]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:20:43 volumio volumio[26227]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:20:43 volumio volumio[26227]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:20:43 volumio volumio[26227]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:20:43 volumio volumio[26227]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:20:43 volumio volumio[26227]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 15:20:43 volumio volumio[26227]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:20:43 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 15:20:43 volumio volumio[26227]: info: No need to fix Spotify hosts Feb 18 15:20:43 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 15:20:43 volumio go-librespot[26471]: go-librespot daemon starting... Feb 18 15:20:43 volumio sudo[26459]: pam_unix(sudo:session): session closed for user root Feb 18 15:20:43 volumio go-librespot[26472]: time="2026-02-18T15:20:43+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 15:20:43 volumio go-librespot[26472]: time="2026-02-18T15:20:43+07:00" level=debug msg="app state loaded" Feb 18 15:20:43 volumio go-librespot[26472]: time="2026-02-18T15:20:43+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 15:20:44 volumio go-librespot[26472]: time="2026-02-18T15:20: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 18 15:20:44 volumio go-librespot[26472]: time="2026-02-18T15:20: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 18 15:20:44 volumio go-librespot[26472]: time="2026-02-18T15:20: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 18 15:20:44 volumio go-librespot[26472]: time="2026-02-18T15:20:44+07:00" level=info msg="zeroconf server listening on port 35935" Feb 18 15:20:44 volumio go-librespot[26472]: time="2026-02-18T15:20:44+07:00" level=debug msg="obtained new client token: AAAJk1N/xpBhi6h0O/5VtwP3gp+O0CNUG68IEtWUxJzfY8JY2rrNHiBgMsp0fYeKXoujDvRzjefr/LxFouco4DIISF48Dl9+Bysa2nJbo3HwXYmPh47bmHr0S5C9ZhxG/kHbN3TLMQ6PwTCiuKazs51JEvgmx/2BAZNAokFbVcoPsdBWRT9Be0Gmoi9BL42OqHpEkDXZNi7YlGaVwmq+ZOOlHetgx4BRE3ykoHcYZB3Va7P5LlToekcibg==" Feb 18 15:20:44 volumio volumio[26227]: info: Volumio called home Feb 18 15:20:44 volumio volumio[26227]: info: Starting Shairport Sync Feb 18 15:20:44 volumio volumio[26227]: info: Starting Shairport Sync Feb 18 15:20:44 volumio volumio[26227]: info: Starting Shairport Sync Feb 18 15:20:45 volumio go-librespot[26472]: time="2026-02-18T15:20:44+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 15:20:45 volumio sudo[26499]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 18 15:20:45 volumio sudo[26499]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 15:20:45 volumio sudo[26501]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 18 15:20:45 volumio sudo[26501]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 15:20:45 volumio sudo[26503]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 18 15:20:45 volumio sudo[26503]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 15:20:45 volumio go-librespot[26472]: time="2026-02-18T15:20:45+07:00" level=debug msg="completed keyexchange" Feb 18 15:20:45 volumio go-librespot[26472]: time="2026-02-18T15:20:45+07:00" level=debug msg="completed challenge" Feb 18 15:20:45 volumio go-librespot[26472]: time="2026-02-18T15:20: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 18 15:20:45 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 15:20:45 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 15:20:45 volumio volumio[26227]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 18 15:20:45 volumio volumio[26227]: SPOTIFY: BQCozXCCM5m6d7SDwGlPof4UXzSFJ1MtG5jULLyq8kUhyCSoB6FURz7iUYNianBzU-vKCx7bd2DH6chvmqc7tJrwewSNL7UE6yac8wvQsR5ii97Z1c7jnNrw8Zt2gMWWcTS--VBXR02q4zDxJtIsTSykUGSHHLTMt54U3femTI0YY2O8y5XwRJ5hFgWs2P80OMgz70zpU1G65VAJsQgTEOD-U5WURgLaFRb3zZCpvWEzM1n8Dl8OOvdtpud07GE1tTaiNYh8xonBZOkJ4D0KA2NmqPYiag7BYipcACXMzdTJY1tBWptOHqLU Feb 18 15:20:45 volumio volumio[26227]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 18 15:20:45 volumio volumio[26227]: info: New Spotify access token = BQCozXCCM5m6d7SDwGlPof4UXzSFJ1MtG5jULLyq8kUhyCSoB6FURz7iUYNianBzU-vKCx7bd2DH6chvmqc7tJrwewSNL7UE6yac8wvQsR5ii97Z1c7jnNrw8Zt2gMWWcTS--VBXR02q4zDxJtIsTSykUGSHHLTMt54U3femTI0YY2O8y5XwRJ5hFgWs2P80OMgz70zpU1G65VAJsQgTEOD-U5WURgLaFRb3zZCpvWEzM1n8Dl8OOvdtpud07GE1tTaiNYh8xonBZOkJ4D0KA2NmqPYiag7BYipcACXMzdTJY1tBWptOHqLU Feb 18 15:20:45 volumio volumio[26227]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 18 15:20:45 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 18 15:20:45 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 18 15:20:45 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 18 15:20:45 volumio systemd[1]: shairport-sync.service: Consumed 2.286s CPU time. Feb 18 15:20:45 volumio volumio[26227]: info: CoreCommandRouter::volumioGetState Feb 18 15:20:45 volumio volumio[26227]: info: CorePlayQueue::getTrack 0 Feb 18 15:20:45 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 18 15:20:45 volumio sudo[26503]: pam_unix(sudo:session): session closed for user root Feb 18 15:20:45 volumio sudo[26499]: pam_unix(sudo:session): session closed for user root Feb 18 15:20:45 volumio sudo[26501]: pam_unix(sudo:session): session closed for user root Feb 18 15:20:45 volumio volumio[26227]: info: Shairport-Sync Started Feb 18 15:20:45 volumio volumio[26227]: Error adding Membership: Error: addMembership EINVAL Feb 18 15:20:45 volumio volumio[26227]: info: Shairport-Sync Started Feb 18 15:20:45 volumio volumio[26227]: info: Shairport-Sync Started Feb 18 15:20:45 volumio volumio[26227]: 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 18 15:20:45 volumio volumio[26227]: info: Spotify Successfully logged in Feb 18 15:20:45 volumio volumio[26227]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 15:20:45 volumio volumio[26227]: info: [1771402845842] CoreMusicLibrary::Adding element Spotify Feb 18 15:20:45 volumio volumio[26227]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 15:20:45 volumio volumio[26227]: Cannot find translation for source YouTube Music Feb 18 15:20:45 volumio volumio[26227]: Cannot find translation for source Spotify Feb 18 15:20:46 volumio volumio[26227]: info: [yt-cast-receiver] DIAL server listening on port 8098 Feb 18 15:20:46 volumio volumio[26227]: info: CoreCommandRouter::volumioRetrievevolume Feb 18 15:20:47 volumio volumio[26227]: info: VolumeController:: Volume=100 Mute =false Feb 18 15:20:47 volumio volumio[26227]: info: CoreCommandRouter::volumioGetState Feb 18 15:20:47 volumio volumio[26227]: info: CorePlayQueue::getTrack 0 Feb 18 15:20:47 volumio volumio[26227]: info: CoreStateMachine::pushState Feb 18 15:20:47 volumio volumio[26227]: info: CorePlayQueue::getTrack 0 Feb 18 15:20:47 volumio volumio[26227]: info: CoreCommandRouter::volumioPushState Feb 18 15:20:47 volumio volumio[26227]: info: go-librespot daemon successfully initialized Feb 18 15:20:48 volumio mpd[26449]: 2026-02-18T15:20:48 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 18 15:20:48 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 18 15:20:48 volumio sudo[26419]: pam_unix(sudo:session): session closed for user root Feb 18 15:20:48 volumio sudo[26403]: pam_unix(sudo:session): session closed for user root Feb 18 15:20:48 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 17. Feb 18 15:20:48 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 15:20:48 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 15:20:48 volumio go-librespot[26544]: go-librespot daemon starting... Feb 18 15:20:48 volumio go-librespot[26545]: time="2026-02-18T15:20:48+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 15:20:48 volumio go-librespot[26545]: time="2026-02-18T15:20:48+07:00" level=debug msg="app state loaded" Feb 18 15:20:48 volumio go-librespot[26545]: time="2026-02-18T15:20:48+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 15:20:48 volumio volumio[26227]: error: MPD error: The expression evaluated to a falsy value: Feb 18 15:20:48 volumio volumio[26227]: assert.ok(self.idling) Feb 18 15:20:48 volumio volumio[26227]: error: The expression evaluated to a falsy value: Feb 18 15:20:48 volumio volumio[26227]: assert.ok(self.idling) Feb 18 15:20:48 volumio volumio[26227]: error: updateQueue error: null Feb 18 15:20:48 volumio volumio[26227]: info: MPD running with PID26449 Feb 18 15:20:48 volumio volumio[26227]: ,establishing connection Feb 18 15:20:48 volumio volumio[26227]: info: Completed starting Core Plugins Feb 18 15:20:48 volumio volumio[26227]: info: ------------------------------------------- Feb 18 15:20:48 volumio volumio[26227]: info: ----- MyVolumio plugins startup ---- Feb 18 15:20:48 volumio volumio[26227]: info: ------------------------------------------- Feb 18 15:20:48 volumio volumio[26227]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 18 15:20:48 volumio volumio[26227]: error: updateQueue error: null Feb 18 15:20:48 volumio go-librespot[26545]: time="2026-02-18T15:20:48+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 15:20:48 volumio go-librespot[26545]: time="2026-02-18T15:20:48+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 18 15:20:48 volumio go-librespot[26545]: time="2026-02-18T15:20:48+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 18 15:20:48 volumio go-librespot[26545]: time="2026-02-18T15:20:48+07:00" level=info msg="zeroconf server listening on port 42331" Feb 18 15:20:49 volumio go-librespot[26545]: time="2026-02-18T15:20:49+07:00" level=debug msg="obtained new client token: AADq9uxGIYZI9X1qsYyI1IrB66VPKf19QdOO20c7qkvzuo56DhsRhHvC3gWHS4Ue9zUcHj9MxR5JRlGsTAtv6M+k0Lp+5qTxvG0DtAD8sdvfgCltypgQbTNajkpnm+XjN4ArYJsA4GSbAkCcDX81HlgB04JdClF6PnpHLJgYiFReLkqQKNYoGWO8Xral6Y1McbVJvJL7drpuUP8g7hiHZMzNBZgCpgV7m4wUORzpjuYffmO3VbovX14=" Feb 18 15:20:49 volumio go-librespot[26545]: time="2026-02-18T15:20:49+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 15:20:49 volumio go-librespot[26545]: time="2026-02-18T15:20:49+07:00" level=debug msg="completed keyexchange" Feb 18 15:20:49 volumio go-librespot[26545]: time="2026-02-18T15:20:49+07:00" level=debug msg="completed challenge" Feb 18 15:20:49 volumio go-librespot[26545]: time="2026-02-18T15:20: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 18 15:20:49 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 15:20:49 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 15:20:50 volumio volumio[26227]: info: Initializing connection to go-librespot Websocket Feb 18 15:20:50 volumio volumio[26227]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 18 15:20:52 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 18. Feb 18 15:20:52 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 15:20:52 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 15:20:52 volumio go-librespot[26552]: go-librespot daemon starting... Feb 18 15:20:52 volumio go-librespot[26553]: time="2026-02-18T15:20:52+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 15:20:52 volumio go-librespot[26553]: time="2026-02-18T15:20:52+07:00" level=debug msg="app state loaded" Feb 18 15:20:52 volumio go-librespot[26553]: time="2026-02-18T15:20:52+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 15:20:53 volumio go-librespot[26553]: time="2026-02-18T15:20:53+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 18 15:20:53 volumio go-librespot[26553]: time="2026-02-18T15:20:53+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 18 15:20:53 volumio go-librespot[26553]: time="2026-02-18T15:20:53+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 18 15:20:53 volumio go-librespot[26553]: time="2026-02-18T15:20:53+07:00" level=info msg="zeroconf server listening on port 44475" Feb 18 15:20:53 volumio volumio[26227]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 18 15:20:53 volumio go-librespot[26553]: time="2026-02-18T15:20:53+07:00" level=debug msg="obtained new client token: AAA19pNjc8RaD2vrTrzqx2kY9OQWpF82Ki9mz4budH+dDJuKIYtqwz3s68QsDIZxohgkZNQpROGrN6OOqCFGciGr4n2GfotIYPZ0x6z3C1514H5U3MXVpeP+36EylhfoE70QudYYPgK3ZKFRG5CkBx+kRMkiMEdeKq/k0pHDZoPUpl6WnPouLUJU+dESuRAsJxMqeZWG7Gi48v8v8STJuZOBKXIZ6kAkMOCfgtmDnjPqgr9J6iXRbXqOig==" Feb 18 15:20:53 volumio go-librespot[26553]: time="2026-02-18T15:20:53+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 15:20:53 volumio go-librespot[26553]: time="2026-02-18T15:20:53+07:00" level=debug msg="completed keyexchange" Feb 18 15:20:53 volumio go-librespot[26553]: time="2026-02-18T15:20:53+07:00" level=debug msg="completed challenge" Feb 18 15:20:53 volumio go-librespot[26553]: time="2026-02-18T15:20:53+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 18 15:20:53 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 15:20:53 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 15:20:53 volumio volumio[26227]: info: Initializing connection to go-librespot Websocket Feb 18 15:20:53 volumio volumio[26227]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 18 15:20:56 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 19. Feb 18 15:20:56 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 15:20:56 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 15:20:56 volumio go-librespot[26561]: go-librespot daemon starting... Feb 18 15:20:56 volumio volumio[26227]: info: Initializing connection to go-librespot Websocket Feb 18 15:20:56 volumio volumio[26227]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 18 15:20:56 volumio go-librespot[26562]: time="2026-02-18T15:20:56+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 15:20:56 volumio go-librespot[26562]: time="2026-02-18T15:20:56+07:00" level=debug msg="app state loaded" Feb 18 15:20:56 volumio go-librespot[26562]: time="2026-02-18T15:20:56+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 15:20:57 volumio volumio[26227]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 18 15:20:57 volumio volumio[26227]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 18 15:20:57 volumio volumio[26227]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 18 15:20:57 volumio volumio[26227]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 18 15:20:57 volumio volumio[26227]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 18 15:20:57 volumio volumio[26227]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 18 15:20:57 volumio volumio[26227]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 18 15:20:57 volumio volumio[26227]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 18 15:20:57 volumio volumio[26227]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 18 15:20:57 volumio volumio[26227]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 18 15:20:57 volumio volumio[26227]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 18 15:20:57 volumio volumio[26227]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 18 15:20:57 volumio volumio[26227]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 18 15:20:57 volumio volumio[26227]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 18 15:20:57 volumio volumio[26227]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 18 15:20:57 volumio volumio[26227]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 18 15:20:57 volumio volumio[26227]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 18 15:20:57 volumio volumio[26227]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 18 15:20:57 volumio volumio[26227]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 18 15:20:57 volumio volumio[26227]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 18 15:20:57 volumio volumio[26227]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 18 15:20:57 volumio volumio[26227]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 18 15:20:57 volumio volumio[26227]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 18 15:20:57 volumio volumio[26227]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 18 15:20:57 volumio volumio[26227]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 18 15:20:57 volumio volumio[26227]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 18 15:20:57 volumio volumio[26227]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 18 15:20:57 volumio volumio[26227]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 18 15:20:57 volumio volumio[26227]: info: Adding plugin bluetooth to MyMusic Plugins Feb 18 15:20:57 volumio volumio[26227]: info: Adding plugin multiroom to MyMusic Plugins Feb 18 15:20:57 volumio volumio[26227]: info: Adding plugin metavolumio to MyMusic Plugins Feb 18 15:20:57 volumio volumio[26227]: info: Adding plugin cd_controller to MyMusic Plugins Feb 18 15:20:57 volumio volumio[26227]: info: Adding plugin qobuzconnect to MyMusic Plugins Feb 18 15:20:57 volumio volumio[26227]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 18 15:20:57 volumio volumio[26227]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 18 15:20:57 volumio volumio[26227]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 18 15:20:57 volumio go-librespot[26562]: time="2026-02-18T15:20:57+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 15:20:57 volumio go-librespot[26562]: time="2026-02-18T15:20:57+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 18 15:20:57 volumio go-librespot[26562]: time="2026-02-18T15:20:57+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 18 15:20:57 volumio go-librespot[26562]: time="2026-02-18T15:20:57+07:00" level=info msg="zeroconf server listening on port 42259" Feb 18 15:20:57 volumio go-librespot[26562]: time="2026-02-18T15:20:57+07:00" level=debug msg="obtained new client token: AAAX/sOR+7+K1To1jIrIolHT/GzGr/5eH5spZTkyeOX290058fKI0jZTu8UODK52f6zt+Be2awcH6nvvdAH3b8k2mLbbgrgcyAjDLRYQgi8lm+DwDHk8oG/6Ge/x258zzmogq6gE9Ghap37Q+Y1Bzq6CLvwAovruaEUk4NOjVsk3Vje9W6fhmK69DeD4IKxqb9ur8Luq5RzFOXhd3Jiuh+f9BoUQRiLGyVYy9Ah974F0tGtfEfvmwkNfqg==" Feb 18 15:20:57 volumio go-librespot[26562]: time="2026-02-18T15:20:57+07:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:4070, retrying with a different AP" error="dial tcp 104.199.241.202:4070: connect: connection refused" Feb 18 15:20:57 volumio go-librespot[26562]: time="2026-02-18T15:20:57+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Feb 18 15:20:58 volumio go-librespot[26562]: time="2026-02-18T15:20:58+07:00" level=debug msg="completed keyexchange" Feb 18 15:20:58 volumio go-librespot[26562]: time="2026-02-18T15:20:58+07:00" level=debug msg="completed challenge" Feb 18 15:20:58 volumio go-librespot[26562]: time="2026-02-18T15:20:58+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 18 15:20:59 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 15:20:59 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 15:20:59 volumio volumio[26227]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 18 15:20:59 volumio volumio[26227]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 18 15:20:59 volumio volumio[26227]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 15:20:59 volumio volumio[26227]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 15:20:59 volumio volumio[26227]: info: Starting MyVolumio Remote Streaming Endpoints Feb 18 15:20:59 volumio volumio[26227]: info: MyVolumio login type: Token Feb 18 15:20:59 volumio volumio[26227]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 18 15:20:59 volumio volumio[26227]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 18 15:21:01 volumio volumio[26227]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 18 15:21:01 volumio volumio[26227]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 18 15:21:01 volumio volumio[26227]: info: Streaming services startup Feb 18 15:21:01 volumio volumio[26227]: info: Starting Streaming Daemon Feb 18 15:21:01 volumio sudo[26585]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 18 15:21:01 volumio sudo[26585]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 15:21:01 volumio volumio[26227]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 18 15:21:01 volumio sudo[26585]: pam_unix(sudo:session): session closed for user root Feb 18 15:21:01 volumio volumio[26227]: info: Initializing connection to go-librespot Websocket Feb 18 15:21:01 volumio volumio[26227]: error: Cannot start Volumio Streaming Daemon Feb 18 15:21:01 volumio volumio[26227]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 18 15:21:01 volumio volumio[26227]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 18 15:21:01 volumio volumio[26227]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 18 15:21:02 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 20. Feb 18 15:21:02 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 15:21:02 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 15:21:02 volumio go-librespot[26591]: go-librespot daemon starting... Feb 18 15:21:02 volumio go-librespot[26592]: time="2026-02-18T15:21:02+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 15:21:02 volumio go-librespot[26592]: time="2026-02-18T15:21:02+07:00" level=debug msg="app state loaded" Feb 18 15:21:02 volumio go-librespot[26592]: time="2026-02-18T15:21:02+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 15:21:02 volumio volumio[26227]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Feb 18 15:21:02 volumio go-librespot[26592]: time="2026-02-18T15:21:02+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 15:21:02 volumio go-librespot[26592]: time="2026-02-18T15:21:02+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 18 15:21:02 volumio go-librespot[26592]: time="2026-02-18T15:21:02+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 18 15:21:02 volumio go-librespot[26592]: time="2026-02-18T15:21:02+07:00" level=info msg="zeroconf server listening on port 34313" Feb 18 15:21:02 volumio go-librespot[26592]: time="2026-02-18T15:21:02+07:00" level=debug msg="obtained new client token: AADWMtX7v7qU6F0+M8zzHJpz1+u1ueADtCFQsZ5E+KaRWYk9Y3TNudZcElxvnC1asvs16ApQf3yFLfkhU8mx0eZdnrXYmPMIdkwCKvkB7cLFhDp6noLVlNMgnYDC+0cPXfhKna8/Wwcxu6HgAwbWPqnd4MPBI9KCg2j9sJb9xcHBrrCAdb+MIry2OAfbv1qFMoMfnYeUgvMa74N3+JG03E/cgEcWc2XzhxCDSVSxWLjWbjK0yyP7xL3Ggw==" Feb 18 15:21:03 volumio go-librespot[26592]: time="2026-02-18T15:21:03+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 15:21:03 volumio go-librespot[26592]: time="2026-02-18T15:21:03+07:00" level=debug msg="completed keyexchange" Feb 18 15:21:03 volumio go-librespot[26592]: time="2026-02-18T15:21:03+07:00" level=debug msg="completed challenge" Feb 18 15:21:03 volumio go-librespot[26592]: time="2026-02-18T15:21: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 18 15:21:03 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 15:21:03 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 15:21:03 volumio volumio[26227]: info: MyVolumio token set successfully Feb 18 15:21:03 volumio volumio[26227]: info: MYVOLUMIO: Adding device Feb 18 15:21:03 volumio volumio[26227]: info: MYVOLUMIO: Evaluating Server Feb 18 15:21:03 volumio volumio[26227]: info: MyVolumio status changed Feb 18 15:21:03 volumio volumio[26227]: info: Streaming services startup Feb 18 15:21:03 volumio volumio[26227]: info: Starting Streaming Daemon Feb 18 15:21:03 volumio volumio[26227]: info: Removing browser output: myVolumio user plan is not superstar Feb 18 15:21:03 volumio volumio[26227]: info: Removing audio output: Feb 18 15:21:03 volumio volumio[26227]: info: Stoppping Tunnel 1 Feb 18 15:21:03 volumio sudo[26620]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 18 15:21:03 volumio sudo[26620]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 15:21:03 volumio sudo[26620]: pam_unix(sudo:session): session closed for user root Feb 18 15:21:03 volumio sudo[26623]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Feb 18 15:21:03 volumio volumio[26227]: error: Cannot start Volumio Streaming Daemon Feb 18 15:21:03 volumio volumio[26227]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 18 15:21:03 volumio volumio[26227]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 18 15:21:03 volumio sudo[26623]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 15:21:04 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 18 15:21:04 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 18 15:21:04 volumio volumio[26227]: info: Setting Geolocation for MyVolumio to as1 Feb 18 15:21:04 volumio volumio[26227]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 15:21:04 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 18 15:21:04 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 18 15:21:04 volumio volumio[26227]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 15:21:04 volumio volumio[26227]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 15:21:04 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 18 15:21:04 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 18 15:21:04 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 18 15:21:04 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 18 15:21:04 volumio sudo[26623]: pam_unix(sudo:session): session closed for user root Feb 18 15:21:04 volumio volumio[26227]: info: Remote SSH Stopped Feb 18 15:21:04 volumio volumio[26227]: info: Initializing connection to go-librespot Websocket Feb 18 15:21:04 volumio volumio[26227]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 18 15:21:04 volumio volumio[26227]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Feb 18 15:21:05 volumio volumio[26227]: info: Updating MyVolumio device info Feb 18 15:21:05 volumio volumio[26227]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 15:21:05 volumio volumio[26227]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 15:21:05 volumio volumio[26227]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 15:21:05 volumio volumio[26227]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Feb 18 15:21:06 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 21. Feb 18 15:21:06 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 15:21:06 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 15:21:06 volumio go-librespot[26626]: go-librespot daemon starting... Feb 18 15:21:06 volumio go-librespot[26627]: time="2026-02-18T15:21:06+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 15:21:06 volumio go-librespot[26627]: time="2026-02-18T15:21:06+07:00" level=debug msg="app state loaded" Feb 18 15:21:06 volumio go-librespot[26627]: time="2026-02-18T15:21:06+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 15:21:06 volumio go-librespot[26627]: time="2026-02-18T15:21:06+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 15:21:06 volumio go-librespot[26627]: time="2026-02-18T15:21:06+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 18 15:21:06 volumio go-librespot[26627]: time="2026-02-18T15:21:06+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 18 15:21:06 volumio go-librespot[26627]: time="2026-02-18T15:21:06+07:00" level=info msg="zeroconf server listening on port 41291" Feb 18 15:21:07 volumio go-librespot[26627]: time="2026-02-18T15:21:07+07:00" level=debug msg="obtained new client token: AAAzn5fru+mfYYLCRrsTyV9ew57pQMdQxazwNVZz0JBcjP02T084QoIMLHijP3A3iJBcCyCxf1+9PGyNHjNUl2NHaBZGQS+WNHwVQEzga34MrdVP4ffkvbzAHCSv07OA9WP9WVntQ8Pbc4u2Sn+bq2uFP3ySyTwYbGECFZgnKxi0QvTWKW+kT6FjseKsiBMOIjiajfUSBjfdBgTCKiHDuAWrr1Scxizz8kYxJDVvoByR1yYIkVrs+cE=" Feb 18 15:21:07 volumio volumio[26227]: info: Initializing connection to go-librespot Websocket Feb 18 15:21:07 volumio go-librespot[26627]: time="2026-02-18T15:21:07+07:00" level=debug msg="new websocket client" Feb 18 15:21:07 volumio volumio[26227]: info: Connection to go-librespot Websocket established Feb 18 15:21:07 volumio go-librespot[26627]: time="2026-02-18T15:21:07+07:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:4070, retrying with a different AP" error="dial tcp 104.199.241.202:4070: connect: connection refused" Feb 18 15:21:07 volumio go-librespot[26627]: time="2026-02-18T15:21:07+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Feb 18 15:21:07 volumio go-librespot[26627]: time="2026-02-18T15:21:07+07:00" level=debug msg="completed keyexchange" Feb 18 15:21:07 volumio go-librespot[26627]: time="2026-02-18T15:21:07+07:00" level=debug msg="completed challenge" Feb 18 15:21:07 volumio go-librespot[26627]: time="2026-02-18T15:21: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 18 15:21:07 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 15:21:07 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 15:21:07 volumio volumio[26227]: info: Connection to go-librespot Websocket closed Feb 18 15:21:08 volumio volumio[26227]: info: MYVOLUMIO: Adding device Feb 18 15:21:08 volumio volumio[26227]: info: MYVOLUMIO: Evaluating Server Feb 18 15:21:09 volumio volumio[26227]: info: Setting Geolocation for MyVolumio to as1 Feb 18 15:21:09 volumio volumio[26227]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 15:21:09 volumio volumio[26227]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 15:21:09 volumio volumio[26227]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 15:21:09 volumio volumio[26227]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Feb 18 15:21:10 volumio volumio[26227]: info: Updating MyVolumio device info Feb 18 15:21:10 volumio volumio[26227]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 15:21:10 volumio volumio[26227]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 15:21:10 volumio volumio[26227]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 15:21:10 volumio volumio[26227]: info: Getting Spotify volume Feb 18 15:21:10 volumio volumio[26227]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 18 15:21:10 volumio volumio[26227]: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 18 15:21:10 volumio volumio[26227]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Feb 18 15:21:10 volumio volumio[26227]: errno: -111, Feb 18 15:21:10 volumio volumio[26227]: code: 'ECONNREFUSED', Feb 18 15:21:10 volumio volumio[26227]: syscall: 'connect', Feb 18 15:21:10 volumio volumio[26227]: address: '127.0.0.1', Feb 18 15:21:10 volumio volumio[26227]: port: 9879, Feb 18 15:21:10 volumio volumio[26227]: response: undefined Feb 18 15:21:10 volumio volumio[26227]: } Feb 18 15:21:10 volumio volumio[26227]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 18 15:21:10 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 22. Feb 18 15:21:10 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 15:21:10 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 15:21:10 volumio go-librespot[26678]: go-librespot daemon starting... Feb 18 15:21:10 volumio go-librespot[26679]: time="2026-02-18T15:21:10+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 15:21:10 volumio go-librespot[26679]: time="2026-02-18T15:21:10+07:00" level=debug msg="app state loaded" Feb 18 15:21:10 volumio go-librespot[26679]: time="2026-02-18T15:21:10+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 15:21:11 volumio go-librespot[26679]: time="2026-02-18T15:21: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 15:21:11 volumio go-librespot[26679]: time="2026-02-18T15:21:11+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 18 15:21:11 volumio go-librespot[26679]: time="2026-02-18T15:21:11+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 18 15:21:11 volumio go-librespot[26679]: time="2026-02-18T15:21:11+07:00" level=info msg="zeroconf server listening on port 40111" Feb 18 15:21:11 volumio go-librespot[26679]: time="2026-02-18T15:21:11+07:00" level=debug msg="obtained new client token: AADsSHNYF9rwdq4XV/GoUVQSwh7xRBFF8OnQKMRQUP5wZ/vUiqF7KgxQh/0xB8UOz454DF0EDGY4t0GraSLFjf3/Nf0NrYm38Tb/7WyCmJ0FxMpE3cHvPeopa7NWac2wXMbcG1XuKw58Q8WM8uDrnftOa3A7GJdjcxJn0zvzL21A1BmiG4fUZ7J3q8cW0mwljU4WxVNvJ6EshNh44dpyVksWYj2n2kH3vftsfnJGPV2hlm0876XUpeMQxA==" Feb 18 15:21:11 volumio go-librespot[26679]: time="2026-02-18T15:21:11+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 15:21:11 volumio sudo[26688]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-18 15:20' Feb 18 15:21:11 volumio sudo[26688]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 15:21:11 volumio go-librespot[26679]: time="2026-02-18T15:21:11+07:00" level=debug msg="completed keyexchange" Feb 18 15:21:11 volumio go-librespot[26679]: time="2026-02-18T15:21:11+07:00" level=debug msg="completed challenge" Feb 18 15:21:11 volumio go-librespot[26679]: time="2026-02-18T15:21: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 18 15:21:11 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 15:21:11 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 15:21:12 volumio sudo[26688]: pam_unix(sudo:session): session closed for user root Feb 18 15:21:12 volumio volumio-remote-updater[25144]: [2026-02-18 15:21:12] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Feb 18 15:21:12 volumio volumio-remote-updater[25144]: [2026-02-18 15:21:12] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Feb 18 15:21:12 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Feb 18 15:21:12 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Feb 18 15:21:12 volumio systemd[1]: volumio.service: Consumed 58.484s CPU time. Feb 18 15:21:12 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 18 15:21:12 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 18 15:21:12 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 22069. Feb 18 15:21:12 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 18 15:21:12 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Feb 18 15:21:12 volumio systemd[1]: volumio.service: Consumed 58.484s CPU time. Feb 18 15:21:12 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Feb 18 15:21:12 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 18 15:21:15 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 23. Feb 18 15:21:15 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 15:21:15 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 15:21:15 volumio go-librespot[26721]: go-librespot daemon starting... Feb 18 15:21:15 volumio go-librespot[26722]: time="2026-02-18T15:21:15+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 15:21:15 volumio go-librespot[26722]: time="2026-02-18T15:21:15+07:00" level=debug msg="app state loaded" Feb 18 15:21:15 volumio go-librespot[26722]: time="2026-02-18T15:21:15+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 15:21:15 volumio go-librespot[26722]: time="2026-02-18T15:21: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-gew1.spotify.com:80]" Feb 18 15:21:15 volumio go-librespot[26722]: time="2026-02-18T15:21:15+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 18 15:21:15 volumio go-librespot[26722]: time="2026-02-18T15:21:15+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 18 15:21:15 volumio go-librespot[26722]: time="2026-02-18T15:21:15+07:00" level=info msg="zeroconf server listening on port 36111" Feb 18 15:21:15 volumio go-librespot[26722]: time="2026-02-18T15:21:15+07:00" level=debug msg="obtained new client token: AAD4ZdshW0IwNe52oy+Cn8x5m1tk+i9fyq9VBziUk3lL7Ws3HlVA6h7fP81F8SeI25WYP+xH/dO0zJJGsETEObVAmSfh0b4nBMY1FXSq78GNGQMsqB+6q1TaDH5dZmRarry+SgpAKHuFJ9PcXXHE7SCaYPeKVIJrvZ74WoMvBj98qHX5Y1Vx/6i/Kv+NxNkfOmdWHLYzkOaR6W1o2QKDUpM253Y81V5t6HS88ZvDrBHS9HZByvseJi6ZnQ==" Feb 18 15:21:16 volumio volumio[26703]: info: ------------------------------------------- Feb 18 15:21:16 volumio volumio[26703]: info: ----- Volumio3 ---- Feb 18 15:21:16 volumio volumio[26703]: info: ------------------------------------------- Feb 18 15:21:16 volumio volumio[26703]: info: ----- System startup ---- Feb 18 15:21:16 volumio volumio[26703]: info: ------------------------------------------- Feb 18 15:21:16 volumio go-librespot[26722]: time="2026-02-18T15:21:16+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 15:21:16 volumio go-librespot[26722]: time="2026-02-18T15:21:16+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 18 15:21:16 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 15:21:16 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 15:21:17 volumio volumio-remote-updater[25144]: [2026-02-18 15:21:17] [connect] Successful connection Feb 18 15:21:17 volumio volumio[26703]: info: MYVOLUMIO Environment detected Feb 18 15:21:17 volumio volumio[26703]: info: Plugin folders cleanup Feb 18 15:21:17 volumio volumio[26703]: info: Scanning into folder /volumio/app/plugins/ Feb 18 15:21:17 volumio volumio[26703]: info: Scanning category audio_interface Feb 18 15:21:17 volumio volumio[26703]: info: Scanning category miscellanea Feb 18 15:21:17 volumio volumio[26703]: info: Scanning category music_service Feb 18 15:21:17 volumio volumio[26703]: info: Scanning category plugins.json Feb 18 15:21:17 volumio volumio[26703]: info: Scanning category system_controller Feb 18 15:21:17 volumio volumio[26703]: info: Scanning category user_interface Feb 18 15:21:17 volumio volumio[26703]: info: Scanning into folder /data/plugins/ Feb 18 15:21:17 volumio volumio[26703]: info: Scanning category music_service Feb 18 15:21:17 volumio volumio[26703]: info: Plugin folders cleanup completed Feb 18 15:21:17 volumio volumio[26703]: info: ------------------------------------------- Feb 18 15:21:17 volumio volumio[26703]: info: ----- Core plugins startup ---- Feb 18 15:21:17 volumio volumio[26703]: info: ------------------------------------------- Feb 18 15:21:17 volumio volumio[26703]: info: Loading plugins from folder /volumio/app/plugins/ Feb 18 15:21:17 volumio volumio[26703]: info: Adding plugin upnp to MyMusic Plugins Feb 18 15:21:17 volumio volumio[26703]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 18 15:21:17 volumio volumio[26703]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 18 15:21:17 volumio volumio[26703]: info: Loading plugins from folder /data/plugins/ Feb 18 15:21:17 volumio volumio[26703]: info: Loading plugin "system"... Feb 18 15:21:17 volumio volumio[26703]: info: Loading plugin "appearance"... Feb 18 15:21:19 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 24. Feb 18 15:21:19 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 15:21:19 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 15:21:19 volumio go-librespot[26742]: go-librespot daemon starting... Feb 18 15:21:19 volumio go-librespot[26743]: time="2026-02-18T15:21:19+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 15:21:19 volumio go-librespot[26743]: time="2026-02-18T15:21:19+07:00" level=debug msg="app state loaded" Feb 18 15:21:19 volumio go-librespot[26743]: time="2026-02-18T15:21:19+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 15:21:19 volumio volumio[26703]: info: Loading plugin "network"... Feb 18 15:21:19 volumio volumio[26703]: info: Refreshing Cached IP Addresses Feb 18 15:21:19 volumio sudo[26750]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 18 15:21:19 volumio sudo[26750]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 15:21:19 volumio sudo[26750]: pam_unix(sudo:session): session closed for user root Feb 18 15:21:19 volumio sudo[26752]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 18 15:21:19 volumio sudo[26752]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 15:21:19 volumio volumio[26703]: info: Loading plugin "services"... Feb 18 15:21:19 volumio volumio[26703]: info: Loading plugin "alsa_controller"... Feb 18 15:21:19 volumio sudo[26752]: pam_unix(sudo:session): session closed for user root Feb 18 15:21:19 volumio sudo[26760]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 18 15:21:19 volumio sudo[26760]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 15:21:19 volumio volumio[26703]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 18 15:21:19 volumio volumio[26703]: info: Loading plugin "wizard"... Feb 18 15:21:19 volumio volumio[26703]: info: Loading plugin "networkfs"... Feb 18 15:21:19 volumio volumio[26703]: info: Starting Udev Watcher for removable devices Feb 18 15:21:19 volumio volumio[26703]: info: Ignoring mount for partition: boot Feb 18 15:21:19 volumio volumio[26703]: info: Ignoring mount for partition: volumio Feb 18 15:21:19 volumio volumio[26703]: info: Ignoring mount for partition: volumio_data Feb 18 15:21:19 volumio volumio[26703]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 18 15:21:19 volumio volumio[26703]: info: Loading plugin "volumio_command_line_client"... Feb 18 15:21:19 volumio volumio[26703]: info: Loading plugin "upnp"... Feb 18 15:21:19 volumio volumio[26703]: info: [1771402879967] Starting Upmpd Daemon Feb 18 15:21:19 volumio volumio[26703]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 18 15:21:19 volumio volumio[26703]: info: Loading plugin "my_music"... Feb 18 15:21:19 volumio go-librespot[26743]: time="2026-02-18T15:21: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 18 15:21:19 volumio go-librespot[26743]: time="2026-02-18T15:21: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 18 15:21:19 volumio go-librespot[26743]: time="2026-02-18T15:21: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 18 15:21:19 volumio volumio[26703]: info: Loading plugin "mpd"... Feb 18 15:21:20 volumio go-librespot[26743]: time="2026-02-18T15:21:20+07:00" level=info msg="zeroconf server listening on port 39657" Feb 18 15:21:20 volumio go-librespot[26743]: time="2026-02-18T15:21:20+07:00" level=debug msg="obtained new client token: AADJQemgnjsGVlM3JWFJfCCnJGFZnIrDseVK5Ld+GpqCD6n3zP/sY2237S5XdI1NIwAdHB9TY19PDMWxO3v5y92fKeJgy3TxhX2AHrEuVfMYGC8VR7fr4pQ2sgX3dkqEGALCFemaAUEwI5rbxp2JCd/oDtLogxEn6W4sdZinNDPVEdcfz77DjIaVFokFmbfamT90jM74V5l7dtIjKAFfox68rqDm1+ww3VUNNY6rPA558stdS78FZ3w=" Feb 18 15:21:20 volumio go-librespot[26743]: time="2026-02-18T15:21:20+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 15:21:20 volumio go-librespot[26743]: time="2026-02-18T15:21:20+07:00" level=debug msg="completed keyexchange" Feb 18 15:21:20 volumio go-librespot[26743]: time="2026-02-18T15:21:20+07:00" level=debug msg="completed challenge" Feb 18 15:21:20 volumio go-librespot[26743]: time="2026-02-18T15:21: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 18 15:21:20 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 15:21:20 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 15:21:20 volumio volumio[26703]: info: Loading plugin "upnp_browser"... Feb 18 15:21:22 volumio sudo[26760]: pam_unix(sudo:session): session closed for user root Feb 18 15:21:23 volumio volumio[26703]: info: Starting UPNP Browser Feb 18 15:21:23 volumio volumio[26703]: info: Loading plugin "alarm-clock"... Feb 18 15:21:23 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 25. Feb 18 15:21:23 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 15:21:23 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 15:21:23 volumio go-librespot[26784]: go-librespot daemon starting... Feb 18 15:21:23 volumio go-librespot[26785]: time="2026-02-18T15:21:23+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 15:21:23 volumio go-librespot[26785]: time="2026-02-18T15:21:23+07:00" level=debug msg="app state loaded" Feb 18 15:21:23 volumio go-librespot[26785]: time="2026-02-18T15:21:23+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 15:21:23 volumio volumio[26703]: info: Loading plugin "airplay_emulation"... Feb 18 15:21:23 volumio volumio[26703]: info: Starting Shairport Sync Feb 18 15:21:23 volumio volumio[26703]: info: Loading plugin "last_100"... Feb 18 15:21:23 volumio volumio[26703]: info: Loading plugin "webradio"... Feb 18 15:21:24 volumio volumio[26703]: info: Loading plugin "i2s_dacs"... Feb 18 15:21:24 volumio volumio[26703]: info: Loading plugin "volumiodiscovery"... Feb 18 15:21:24 volumio volumio[26703]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 18 15:21:24 volumio volumio[26703]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 18 15:21:24 volumio volumio[26703]: *** WARNING *** For more information see Feb 18 15:21:24 volumio volumio[26703]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 18 15:21:24 volumio volumio[26703]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 18 15:21:24 volumio volumio[26703]: *** WARNING *** For more information see Feb 18 15:21:24 volumio node[26703]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 18 15:21:24 volumio node[26703]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 18 15:21:24 volumio node[26703]: *** WARNING *** For more information see Feb 18 15:21:24 volumio node[26703]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 18 15:21:24 volumio node[26703]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 18 15:21:24 volumio node[26703]: *** WARNING *** For more information see Feb 18 15:21:24 volumio volumio[26703]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 18 15:21:24 volumio volumio[26703]: info: Discovery: Started advertising with name: Volumio Feb 18 15:21:24 volumio go-librespot[26785]: time="2026-02-18T15:21: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-gew1.spotify.com:80]" Feb 18 15:21:24 volumio go-librespot[26785]: time="2026-02-18T15:21:24+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 18 15:21:24 volumio go-librespot[26785]: time="2026-02-18T15:21:24+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 18 15:21:24 volumio go-librespot[26785]: time="2026-02-18T15:21:24+07:00" level=info msg="zeroconf server listening on port 41223" Feb 18 15:21:24 volumio volumio[26703]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 18 15:21:24 volumio volumio[26703]: info: Loading plugin "spop"... Feb 18 15:21:24 volumio go-librespot[26785]: time="2026-02-18T15:21:24+07:00" level=debug msg="obtained new client token: AABpLkpMeeYIyjbSNwZ2aq341cedrsE9t0qxx5pNaGBIcpIzSRXbIDeTDjEBv0+qvHJlQObaMWFgEShkV8S1ullyci0i6+ePBfiqdBJUH+Dwkfx3tD4wQCrq4z6sMIa4gZaJX6oObaKLTOeShtekec5b0vR4QlZUZOtjseyaU+pn1Pw89QRq4ekLWoZ2mTB0+BDB5C35D3DpriWMmflSKLDXWylXxtiN4ggRRO7yjY2rgGIsuF43PFX9Vg==" Feb 18 15:21:24 volumio go-librespot[26785]: time="2026-02-18T15:21:24+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 15:21:24 volumio go-librespot[26785]: time="2026-02-18T15:21:24+07:00" level=debug msg="completed keyexchange" Feb 18 15:21:24 volumio go-librespot[26785]: time="2026-02-18T15:21:24+07:00" level=debug msg="completed challenge" Feb 18 15:21:24 volumio go-librespot[26785]: time="2026-02-18T15:21: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 18 15:21:24 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 15:21:24 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 15:21:26 volumio volumio[26703]: info: Loading plugin "ytcr"... Feb 18 15:21:28 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 26. Feb 18 15:21:28 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 15:21:28 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 15:21:28 volumio go-librespot[26795]: go-librespot daemon starting... Feb 18 15:21:28 volumio go-librespot[26796]: time="2026-02-18T15:21:28+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 15:21:28 volumio go-librespot[26796]: time="2026-02-18T15:21:28+07:00" level=debug msg="app state loaded" Feb 18 15:21:28 volumio go-librespot[26796]: time="2026-02-18T15:21:28+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 15:21:28 volumio go-librespot[26796]: time="2026-02-18T15:21:28+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 18 15:21:28 volumio go-librespot[26796]: time="2026-02-18T15:21:28+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 18 15:21:28 volumio go-librespot[26796]: time="2026-02-18T15:21:28+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 18 15:21:28 volumio go-librespot[26796]: time="2026-02-18T15:21:28+07:00" level=info msg="zeroconf server listening on port 42407" Feb 18 15:21:28 volumio volumio[26703]: info: Loading plugin "ytmusic"... Feb 18 15:21:28 volumio go-librespot[26796]: time="2026-02-18T15:21:28+07:00" level=debug msg="obtained new client token: AADPE2/+KHKRno4SDcTwbSZmuVgkqVQx/VVdfkM6LQ7y4h/a4W1kzreqID/em+SEcOJGLm2tX47NHC1x698OjpJO2yylo1h2BV26UJb+cpOiXYPdr/IH7RxiVsC87U5UMUBS28YAuXH+Bgv4x3TDKpeeed7iP4sl934b9wKrYDNgi/myoeICK/jyJ0oum/XDksJWJ5QYZ/154vDyLVAPlLGc1AUcU1pWQvE7wdVUzWpi/xBzupfTgQhXHg==" Feb 18 15:21:29 volumio go-librespot[26796]: time="2026-02-18T15:21:29+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 15:21:29 volumio go-librespot[26796]: time="2026-02-18T15:21:29+07:00" level=debug msg="completed keyexchange" Feb 18 15:21:29 volumio go-librespot[26796]: time="2026-02-18T15:21:29+07:00" level=debug msg="completed challenge" Feb 18 15:21:29 volumio go-librespot[26796]: time="2026-02-18T15:21: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 18 15:21:29 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 15:21:29 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 15:21:29 volumio volumio-remote-updater[25144]: [2026-02-18 15:21:29] [connect] Successful connection Feb 18 15:21:29 volumio volumio[26703]: info: Loading plugin "outputs"... Feb 18 15:21:29 volumio volumio[26703]: info: Loading plugin "albumart"... Feb 18 15:21:30 volumio volumio[26703]: info: Plugin example_plugin is not enabled Feb 18 15:21:30 volumio volumio[26703]: info: Loading plugin "inputs"... Feb 18 15:21:30 volumio volumio[26703]: info: Loading plugin "updater_comm"... Feb 18 15:21:30 volumio volumio[26703]: info: Plugin mpdemulation is not enabled Feb 18 15:21:30 volumio volumio[26703]: info: Loading plugin "rest_api"... Feb 18 15:21:30 volumio volumio[26703]: info: Loading plugin "websocket"... Feb 18 15:21:30 volumio volumio[26703]: info: Starting Socket.io Server version 1.7.4 Feb 18 15:21:30 volumio volumio[26703]: info: Loading plugin "RoonBridge"... Feb 18 15:21:30 volumio volumio[26703]: info: Applying required configuration parameters for plugin RoonBridge Feb 18 15:21:30 volumio volumio[26703]: info: Loading i18n strings for locale en Feb 18 15:21:30 volumio volumio[26703]: Updating browse sources language Feb 18 15:21:30 volumio volumio[26703]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 15:21:31 volumio volumio[26817]: Forking 3 albumart workers Feb 18 15:21:31 volumio volumio[26703]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 18 15:21:31 volumio volumio[26703]: info: CoreCommandRouter::initPlayerControls Feb 18 15:21:31 volumio volumio[26703]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:21:31 volumio volumio[26703]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:21:31 volumio volumio[26703]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:21:31 volumio volumio[26703]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:21:31 volumio volumio[26703]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:21:31 volumio volumio[26703]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:21:31 volumio volumio[26703]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:21:31 volumio volumio[26703]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:21:31 volumio volumio[26703]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 18 15:21:31 volumio volumio[26703]: Express server listening on port 3000 Feb 18 15:21:31 volumio volumio[26703]: [Metrics] WebUI: 16s 75.69ms Feb 18 15:21:31 volumio volumio[26703]: info: CoreStateMachine::resetVolumioState Feb 18 15:21:31 volumio volumio[26703]: info: CoreStateMachine::getcurrentVolume Feb 18 15:21:31 volumio volumio[26703]: info: CoreCommandRouter::volumioRetrievevolume Feb 18 15:21:31 volumio sudo[26859]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 18 15:21:31 volumio sudo[26859]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 15:21:31 volumio sudo[26862]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 18 15:21:31 volumio sudo[26862]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 15:21:31 volumio sudo[26859]: pam_unix(sudo:session): session closed for user root Feb 18 15:21:31 volumio sudo[26862]: pam_unix(sudo:session): session closed for user root Feb 18 15:21:31 volumio volumio[26703]: info: Volumio Network Manager: Network status updated: 1 Feb 18 15:21:31 volumio volumio[26703]: info: VolumeController:: Volume=100 Mute =false Feb 18 15:21:31 volumio volumio[26703]: info: CoreStateMachine::pushState Feb 18 15:21:31 volumio volumio[26703]: info: CorePlayQueue::getTrack 0 Feb 18 15:21:31 volumio volumio[26703]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 18 15:21:31 volumio volumio[26703]: info: CoreCommandRouter::volumioPushState Feb 18 15:21:31 volumio volumio[26703]: info: CoreStateMachine::updateTrackBlock Feb 18 15:21:31 volumio volumio[26703]: info: CorePlayQueue::getTrackBlock Feb 18 15:21:31 volumio volumio[26703]: info: CoreCommandRouter::volumioRetrievevolume Feb 18 15:21:31 volumio volumio-remote-updater[25144]: [2026-02-18 15:21:31] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1771402889 101 Feb 18 15:21:31 volumio volumio[26703]: 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 18 15:21:31 volumio volumio[26703]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 15:21:31 volumio volumio[26703]: info: Reloading queue from file Feb 18 15:21:31 volumio volumio[26703]: info: CoreStateMachine::setRepeat null single undefined Feb 18 15:21:31 volumio volumio[26703]: info: CoreStateMachine::pushState Feb 18 15:21:31 volumio volumio[26703]: info: CorePlayQueue::getTrack 0 Feb 18 15:21:31 volumio volumio[26703]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 18 15:21:31 volumio volumio[26703]: info: CoreCommandRouter::volumioPushState Feb 18 15:21:31 volumio volumio[26703]: info: CoreStateMachine::setRandom null Feb 18 15:21:31 volumio volumio[26703]: info: CoreStateMachine::pushState Feb 18 15:21:31 volumio volumio[26703]: info: CorePlayQueue::getTrack 0 Feb 18 15:21:31 volumio volumio[26703]: info: CoreCommandRouter::volumioPushState Feb 18 15:21:31 volumio volumio[26703]: info: Setting Device type: Raspberry PI Feb 18 15:21:32 volumio volumio[26703]: info: Completed loading Core Plugins Feb 18 15:21:32 volumio volumio[26703]: info: Preparing to generate the ALSA configuration file Feb 18 15:21:32 volumio volumio[26703]: info: VolumeController:: Volume=100 Mute =false Feb 18 15:21:32 volumio volumio[26703]: info: CoreStateMachine::pushState Feb 18 15:21:32 volumio volumio[26703]: info: CorePlayQueue::getTrack 0 Feb 18 15:21:32 volumio volumio[26703]: info: CoreCommandRouter::volumioPushState Feb 18 15:21:32 volumio volumio[26703]: info: Asound.conf file unchanged, so no further update is needed Feb 18 15:21:32 volumio volumio[26703]: info: Output device has changed, restarting MPD Feb 18 15:21:32 volumio sudo[26877]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 18 15:21:32 volumio sudo[26877]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 15:21:32 volumio volumio[26703]: info: Output device has changed, restarting Shairport Sync Feb 18 15:21:32 volumio volumio[26703]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:21:32 volumio volumio[26703]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 15:21:32 volumio sudo[26879]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 18 15:21:32 volumio sudo[26879]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 15:21:32 volumio sudo[26882]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 18 15:21:32 volumio sudo[26879]: pam_unix(sudo:session): session closed for user root Feb 18 15:21:32 volumio volumio[26703]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 18 15:21:32 volumio volumio[26703]: info: ___________ START PLUGINS ___________ Feb 18 15:21:32 volumio sudo[26882]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 15:21:32 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 27. Feb 18 15:21:32 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 15:21:32 volumio volumio[26703]: info: ControllerMpd::onStart: Initializing MPD Feb 18 15:21:32 volumio volumio[26703]: info: Creating MPD Configuration file Feb 18 15:21:32 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 15:21:32 volumio go-librespot[26888]: go-librespot daemon starting... Feb 18 15:21:32 volumio go-librespot[26892]: time="2026-02-18T15:21:32+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 15:21:32 volumio go-librespot[26892]: time="2026-02-18T15:21:32+07:00" level=debug msg="app state loaded" Feb 18 15:21:32 volumio go-librespot[26892]: time="2026-02-18T15:21:32+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 15:21:32 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 18 15:21:32 volumio volumio[26703]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 18 15:21:32 volumio volumio[26703]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 15:21:32 volumio volumio[26703]: info: [1771402892586] CoreMusicLibrary::Adding element Media Servers Feb 18 15:21:32 volumio sudo[26891]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 18 15:21:32 volumio sudo[26877]: pam_unix(sudo:session): session closed for user root Feb 18 15:21:32 volumio volumio[26703]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 15:21:32 volumio sudo[26891]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 15:21:32 volumio sudo[26891]: pam_unix(sudo:session): session closed for user root Feb 18 15:21:32 volumio sudo[26899]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 18 15:21:32 volumio sudo[26899]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 15:21:32 volumio volumio[26703]: info: UPNP Browser: Client initialized successfully Feb 18 15:21:32 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 18 15:21:32 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 18 15:21:32 volumio systemd[1]: mpd.service: Consumed 7.084s CPU time. Feb 18 15:21:32 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 18 15:21:32 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 18 15:21:32 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 18 15:21:32 volumio volumio[26703]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:21:32 volumio volumio[26703]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 15:21:32 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 18 15:21:32 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 18 15:21:32 volumio volumio[26703]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 18 15:21:32 volumio volumio[26703]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:21:32 volumio volumio[26703]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 15:21:32 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 18 15:21:32 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 18 15:21:32 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 18 15:21:32 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 18 15:21:32 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 18 15:21:33 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 18 15:21:33 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 18 15:21:33 volumio volumio[26703]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 18 15:21:33 volumio volumio[26703]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 15:21:33 volumio volumio[26703]: info: [1771402893093] CoreMusicLibrary::Adding element Last_100 Feb 18 15:21:33 volumio volumio[26703]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 15:21:33 volumio volumio[26703]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 15:21:33 volumio volumio[26703]: info: [1771402893117] CoreMusicLibrary::Adding element Webradio Feb 18 15:21:33 volumio volumio[26703]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 15:21:33 volumio volumio[26703]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 18 15:21:33 volumio volumio[26703]: info: Initializing BBC Radios Feb 18 15:21:33 volumio go-librespot[26892]: time="2026-02-18T15:21:33+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 18 15:21:33 volumio go-librespot[26892]: time="2026-02-18T15:21:33+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 18 15:21:33 volumio go-librespot[26892]: time="2026-02-18T15:21:33+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 18 15:21:33 volumio go-librespot[26892]: time="2026-02-18T15:21:33+07:00" level=info msg="zeroconf server listening on port 41187" Feb 18 15:21:33 volumio volumio[26703]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 18 15:21:33 volumio volumio[26703]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 15:21:33 volumio volumio[26703]: info: Creating Spotify config file Feb 18 15:21:33 volumio volumio[26703]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:21:33 volumio go-librespot[26892]: time="2026-02-18T15:21:33+07:00" level=debug msg="obtained new client token: AACQBz80z8LkjZ1A9r8FwY2ZUYMtI4gHzO1YWiFKXQRKuy7bmiE2pN4WfoaTerObfJ6h3giwHhSnRx3oRgv28Y9QllQ+viDX2RWimYZSTNIhJ8D9ILzz5PCT57S+UJ5amZENSSMULzRaB6pSKR3YN9mVwVy6FphecIqc0874/jiIbHGA7byn9nfWBAlk6IPQZsHNgzjih/Xot/FrUJInpp5stc/M2D5rJfYhD8z7n+2T6HfG6J6tqpYBRQ==" Feb 18 15:21:33 volumio sudo[26915]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 18 15:21:33 volumio sudo[26915]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 18 15:21:33 volumio sudo[26915]: pam_unix(sudo:session): session closed for user root Feb 18 15:21:33 volumio go-librespot[26892]: time="2026-02-18T15:21:33+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 15:21:33 volumio go-librespot[26892]: time="2026-02-18T15:21:33+07:00" level=debug msg="completed keyexchange" Feb 18 15:21:33 volumio go-librespot[26892]: time="2026-02-18T15:21:33+07:00" level=debug msg="completed challenge" Feb 18 15:21:33 volumio go-librespot[26892]: time="2026-02-18T15:21: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 18 15:21:33 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 15:21:33 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 15:21:34 volumio volumio[26829]: Starting albumart workers Feb 18 15:21:34 volumio volumio[26828]: Starting albumart workers Feb 18 15:21:34 volumio volumio[26703]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 15:21:34 volumio volumio[26703]: info: [1771402894563] CoreMusicLibrary::Adding element YouTube Music Feb 18 15:21:34 volumio volumio[26703]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 15:21:34 volumio volumio[26703]: Cannot find translation for source YouTube Music Feb 18 15:21:34 volumio volumio[26703]: info: Volumio Calling Home Feb 18 15:21:34 volumio sudo[26933]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Feb 18 15:21:34 volumio sudo[26933]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 15:21:34 volumio sudo[26933]: pam_unix(sudo:session): session closed for user root Feb 18 15:21:34 volumio volumio[26827]: Starting albumart workers Feb 18 15:21:35 volumio volumio[26703]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Feb 18 15:21:35 volumio volumio[26703]: info: Discovery: Found device Volumio Feb 18 15:21:35 volumio volumio[26703]: info: CoreCommandRouter::volumioGetState Feb 18 15:21:35 volumio volumio[26703]: info: CorePlayQueue::getTrack 0 Feb 18 15:21:35 volumio volumio[26703]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Feb 18 15:21:35 volumio volumio[26703]: info: Discovery: Found device Volumio Feb 18 15:21:35 volumio volumio[26703]: info: CoreCommandRouter::volumioGetState Feb 18 15:21:35 volumio volumio[26703]: info: CorePlayQueue::getTrack 0 Feb 18 15:21:35 volumio volumio[26703]: info: MPD Permissions set Feb 18 15:21:35 volumio volumio[26703]: info: MPD Permissions set Feb 18 15:21:35 volumio volumio[26703]: info: Upmpdcli Daemon Started Feb 18 15:21:35 volumio volumio[26703]: info: Volumio called home Feb 18 15:21:35 volumio volumio[26703]: info: Spotify config file written Feb 18 15:21:35 volumio sudo[26940]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 18 15:21:35 volumio sudo[26940]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 15:21:35 volumio volumio[26703]: 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 18 15:21:36 volumio volumio[26703]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:21:36 volumio volumio[26703]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:21:36 volumio volumio[26703]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:21:36 volumio volumio[26703]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:21:36 volumio volumio[26703]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:21:36 volumio volumio[26703]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:21:36 volumio volumio[26703]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:21:36 volumio volumio[26703]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:21:36 volumio volumio[26703]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 15:21:36 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 15:21:36 volumio volumio[26703]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:21:36 volumio volumio[26703]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:21:36 volumio volumio[26703]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:21:36 volumio volumio[26703]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:21:36 volumio volumio[26703]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:21:36 volumio volumio[26703]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:21:36 volumio volumio[26703]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:21:36 volumio volumio[26703]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:21:36 volumio volumio[26703]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:21:36 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 15:21:36 volumio go-librespot[26953]: go-librespot daemon starting... Feb 18 15:21:36 volumio volumio[26703]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 15:21:36 volumio volumio[26703]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 15:21:36 volumio sudo[26940]: pam_unix(sudo:session): session closed for user root Feb 18 15:21:36 volumio volumio[26703]: info: No need to fix Spotify hosts Feb 18 15:21:36 volumio go-librespot[26959]: time="2026-02-18T15:21:36+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 15:21:36 volumio go-librespot[26959]: time="2026-02-18T15:21:36+07:00" level=debug msg="app state loaded" Feb 18 15:21:36 volumio go-librespot[26959]: time="2026-02-18T15:21:36+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 15:21:36 volumio go-librespot[26959]: time="2026-02-18T15:21:36+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 15:21:36 volumio go-librespot[26959]: time="2026-02-18T15:21:36+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 18 15:21:36 volumio go-librespot[26959]: time="2026-02-18T15:21:36+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 18 15:21:36 volumio go-librespot[26959]: time="2026-02-18T15:21:36+07:00" level=info msg="zeroconf server listening on port 34479" Feb 18 15:21:37 volumio go-librespot[26959]: time="2026-02-18T15:21:37+07:00" level=debug msg="obtained new client token: AABXpu+TX8hJbxtO2kk4Nl9ZdHG5zcH8O6bx0FwK0097R5r9Eezfqa4JRnh2pwuSj+RrMtApBHA3ooVUjBZ37eAU8oZuX7OgQ2sp5zFkQyRtvKZMxeRrnk3ORJ2Ee7+8aqh4JaqoLWokIZD5wAe9UfEJdYVuNi7qAQV02/R2ZxKTRZGzKQKi1CUz2DKrk+qvlUh1qduK1Msg8mAb43vnBfIfVjWJ6+e3C5JcVnM121Xyk+j3hfS0o+o=" Feb 18 15:21:37 volumio volumio[26703]: info: Starting Shairport Sync Feb 18 15:21:37 volumio volumio[26703]: info: Starting Shairport Sync Feb 18 15:21:37 volumio volumio[26703]: info: Starting Shairport Sync Feb 18 15:21:37 volumio go-librespot[26959]: time="2026-02-18T15:21:37+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 15:21:37 volumio sudo[26979]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 18 15:21:37 volumio sudo[26979]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 15:21:37 volumio sudo[26981]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 18 15:21:37 volumio sudo[26981]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 15:21:37 volumio sudo[26983]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 18 15:21:37 volumio sudo[26983]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 15:21:37 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 18 15:21:37 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 18 15:21:37 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 18 15:21:37 volumio systemd[1]: shairport-sync.service: Consumed 2.373s CPU time. Feb 18 15:21:37 volumio go-librespot[26959]: time="2026-02-18T15:21:37+07:00" level=debug msg="completed keyexchange" Feb 18 15:21:37 volumio go-librespot[26959]: time="2026-02-18T15:21:37+07:00" level=debug msg="completed challenge" Feb 18 15:21:37 volumio go-librespot[26959]: time="2026-02-18T15:21: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 18 15:21:37 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 18 15:21:37 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 15:21:37 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 15:21:37 volumio sudo[26979]: pam_unix(sudo:session): session closed for user root Feb 18 15:21:37 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 18 15:21:37 volumio volumio[26703]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 18 15:21:37 volumio volumio[26703]: SPOTIFY: BQBt3aWq0OwzVoZmyQDZzZajr2FAOyvseCaMVKK5x-fzQDCdTzRDRWrbdFu7oTxOe31b85ZBbwB6E27RpeWagQL-XjZTaNCaPEP_1Oiea6K75JR3LMAkXTJnMzS5cwH4EpC3GohZR4hmSdJGiDTRKGoCWaOr9cP3d5TIjZovgmnz7Ok-4MXh6MVURQRxSBMut0oQLy0TYazf1VKm02uqHtU0-dxI6ywgyiClyXCmCXz0cnJfumMkw_5pLl6nEcEnKF5SeHVZgZKHlBAO8xXt4Buu9DkwZAC1G1sum-T3zgc9x5XTbVAa3QIF Feb 18 15:21:37 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 18 15:21:37 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 18 15:21:37 volumio volumio[26703]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 18 15:21:37 volumio volumio[26703]: info: New Spotify access token = BQBt3aWq0OwzVoZmyQDZzZajr2FAOyvseCaMVKK5x-fzQDCdTzRDRWrbdFu7oTxOe31b85ZBbwB6E27RpeWagQL-XjZTaNCaPEP_1Oiea6K75JR3LMAkXTJnMzS5cwH4EpC3GohZR4hmSdJGiDTRKGoCWaOr9cP3d5TIjZovgmnz7Ok-4MXh6MVURQRxSBMut0oQLy0TYazf1VKm02uqHtU0-dxI6ywgyiClyXCmCXz0cnJfumMkw_5pLl6nEcEnKF5SeHVZgZKHlBAO8xXt4Buu9DkwZAC1G1sum-T3zgc9x5XTbVAa3QIF Feb 18 15:21:37 volumio volumio[26703]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 18 15:21:37 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 18 15:21:37 volumio sudo[26981]: pam_unix(sudo:session): session closed for user root Feb 18 15:21:37 volumio sudo[26983]: pam_unix(sudo:session): session closed for user root Feb 18 15:21:37 volumio volumio[26703]: info: Shairport-Sync Started Feb 18 15:21:37 volumio volumio[26703]: Error adding Membership: Error: addMembership EINVAL Feb 18 15:21:37 volumio volumio[26703]: info: Shairport-Sync Started Feb 18 15:21:37 volumio volumio[26703]: info: Shairport-Sync Started Feb 18 15:21:37 volumio volumio[26703]: info: CoreCommandRouter::volumioGetState Feb 18 15:21:37 volumio volumio[26703]: info: CorePlayQueue::getTrack 0 Feb 18 15:21:38 volumio volumio[26703]: 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 18 15:21:38 volumio volumio[26703]: info: Spotify Successfully logged in Feb 18 15:21:38 volumio volumio[26703]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 15:21:38 volumio volumio[26703]: info: [1771402898367] CoreMusicLibrary::Adding element Spotify Feb 18 15:21:38 volumio volumio[26703]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 15:21:38 volumio volumio[26703]: Cannot find translation for source YouTube Music Feb 18 15:21:38 volumio volumio[26703]: Cannot find translation for source Spotify Feb 18 15:21:38 volumio volumio[26703]: info: [yt-cast-receiver] DIAL server listening on port 8098 Feb 18 15:21:38 volumio volumio[26703]: info: CoreCommandRouter::volumioRetrievevolume Feb 18 15:21:39 volumio volumio[26703]: info: VolumeController:: Volume=100 Mute =false Feb 18 15:21:39 volumio volumio[26703]: info: CoreCommandRouter::volumioGetState Feb 18 15:21:39 volumio volumio[26703]: info: CorePlayQueue::getTrack 0 Feb 18 15:21:39 volumio volumio[26703]: info: CoreStateMachine::pushState Feb 18 15:21:39 volumio volumio[26703]: info: CorePlayQueue::getTrack 0 Feb 18 15:21:39 volumio volumio[26703]: info: CoreCommandRouter::volumioPushState Feb 18 15:21:40 volumio volumio[26703]: info: go-librespot daemon successfully initialized Feb 18 15:21:40 volumio mpd[26931]: 2026-02-18T15:21:40 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 18 15:21:40 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 28. Feb 18 15:21:40 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 18 15:21:40 volumio sudo[26899]: pam_unix(sudo:session): session closed for user root Feb 18 15:21:40 volumio sudo[26882]: pam_unix(sudo:session): session closed for user root Feb 18 15:21:40 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 15:21:40 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 15:21:40 volumio go-librespot[27036]: go-librespot daemon starting... Feb 18 15:21:40 volumio go-librespot[27039]: time="2026-02-18T15:21:40+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 15:21:40 volumio go-librespot[27039]: time="2026-02-18T15:21:40+07:00" level=debug msg="app state loaded" Feb 18 15:21:40 volumio go-librespot[27039]: time="2026-02-18T15:21:40+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 15:21:40 volumio volumio[26703]: error: MPD error: The expression evaluated to a falsy value: Feb 18 15:21:40 volumio volumio[26703]: assert.ok(self.idling) Feb 18 15:21:40 volumio volumio[26703]: error: The expression evaluated to a falsy value: Feb 18 15:21:40 volumio volumio[26703]: assert.ok(self.idling) Feb 18 15:21:40 volumio volumio[26703]: error: updateQueue error: null Feb 18 15:21:40 volumio volumio[26703]: info: MPD running with PID26931 Feb 18 15:21:40 volumio volumio[26703]: ,establishing connection Feb 18 15:21:40 volumio volumio[26703]: info: Completed starting Core Plugins Feb 18 15:21:40 volumio volumio[26703]: info: ------------------------------------------- Feb 18 15:21:40 volumio volumio[26703]: info: ----- MyVolumio plugins startup ---- Feb 18 15:21:40 volumio volumio[26703]: info: ------------------------------------------- Feb 18 15:21:40 volumio volumio[26703]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 18 15:21:40 volumio volumio[26703]: error: updateQueue error: null Feb 18 15:21:41 volumio go-librespot[27039]: time="2026-02-18T15:21:41+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 15:21:41 volumio go-librespot[27039]: time="2026-02-18T15:21:41+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 18 15:21:41 volumio go-librespot[27039]: time="2026-02-18T15:21:41+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 18 15:21:41 volumio go-librespot[27039]: time="2026-02-18T15:21:41+07:00" level=info msg="zeroconf server listening on port 43857" Feb 18 15:21:41 volumio go-librespot[27039]: time="2026-02-18T15:21:41+07:00" level=debug msg="obtained new client token: AAAijAxRW2gnMapVVR3VlDPY8PxIECQlvidn9LXT35H5aoVFpo+iJMosElB+C+xr+j5lCx8qOkH06QXQhIj9r11ziz1SuTpW3+e3Pn4KgNueRbdXLhs+LgN01sFjxG7P6s4v3ldH7qOOkECXBq0eanRSE5DL1RyO6cchD+W8US4F5hQfPq3+MZiZijjZFb36wF6aCUqUyheb8zBelVOScyLK8JO1JMq8/3Ip27roK4yUxL4gFQrkVnt9XQ==" Feb 18 15:21:41 volumio go-librespot[27039]: time="2026-02-18T15:21:41+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 15:21:41 volumio go-librespot[27039]: time="2026-02-18T15:21:41+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 18 15:21:41 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 15:21:41 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 15:21:43 volumio volumio[26703]: info: Initializing connection to go-librespot Websocket Feb 18 15:21:43 volumio volumio[26703]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 18 15:21:44 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 29. Feb 18 15:21:44 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 15:21:44 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 15:21:44 volumio go-librespot[27046]: go-librespot daemon starting... Feb 18 15:21:44 volumio go-librespot[27047]: time="2026-02-18T15:21:44+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 15:21:44 volumio go-librespot[27047]: time="2026-02-18T15:21:44+07:00" level=debug msg="app state loaded" Feb 18 15:21:44 volumio go-librespot[27047]: time="2026-02-18T15:21:44+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 15:21:45 volumio go-librespot[27047]: time="2026-02-18T15:21:45+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 18 15:21:45 volumio go-librespot[27047]: time="2026-02-18T15:21:45+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 18 15:21:45 volumio go-librespot[27047]: time="2026-02-18T15:21:45+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 18 15:21:45 volumio go-librespot[27047]: time="2026-02-18T15:21:45+07:00" level=info msg="zeroconf server listening on port 44765" Feb 18 15:21:45 volumio go-librespot[27047]: time="2026-02-18T15:21:45+07:00" level=debug msg="obtained new client token: AADFmSJ7XZx/cWlVl+cdSO4lrFUCPHEiG0zmsB1mV1y11f8nA5NxuljdXZTue8aGrLq3OGVkpM2PpV/B681EbbkikcvkHB9K1xTSIvmVKFtk3Y511rBVq0jbOWgH/wS8XAWTyTRp2E16+2PraHNWSQuDXNEAmU5kQkr2829ClL+D8Q81Os+nFap8DCmhQb+cMSL13JbxcKYvyaM634WZZ9pPSiKLllFb/I54cvC0p/CH212AirUUXnrp/A==" Feb 18 15:21:45 volumio volumio[26703]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 18 15:21:45 volumio go-librespot[27047]: time="2026-02-18T15:21:45+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 15:21:45 volumio go-librespot[27047]: time="2026-02-18T15:21:45+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 18 15:21:45 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 15:21:45 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 15:21:46 volumio volumio[26703]: info: Initializing connection to go-librespot Websocket Feb 18 15:21:46 volumio volumio[26703]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 18 15:21:49 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 30. Feb 18 15:21:49 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 15:21:49 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 15:21:49 volumio go-librespot[27054]: go-librespot daemon starting... Feb 18 15:21:49 volumio go-librespot[27055]: time="2026-02-18T15:21:49+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 15:21:49 volumio go-librespot[27055]: time="2026-02-18T15:21:49+07:00" level=debug msg="app state loaded" Feb 18 15:21:49 volumio go-librespot[27055]: time="2026-02-18T15:21:49+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 15:21:49 volumio volumio[26703]: info: Initializing connection to go-librespot Websocket Feb 18 15:21:49 volumio go-librespot[27055]: time="2026-02-18T15:21:49+07:00" level=debug msg="new websocket client" Feb 18 15:21:49 volumio volumio[26703]: info: Connection to go-librespot Websocket established Feb 18 15:21:49 volumio go-librespot[27055]: time="2026-02-18T15:21: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 15:21:49 volumio go-librespot[27055]: time="2026-02-18T15:21:49+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 18 15:21:49 volumio go-librespot[27055]: time="2026-02-18T15:21:49+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 18 15:21:49 volumio go-librespot[27055]: time="2026-02-18T15:21:49+07:00" level=info msg="zeroconf server listening on port 37239" Feb 18 15:21:49 volumio volumio[26703]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 18 15:21:49 volumio volumio[26703]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 18 15:21:49 volumio volumio[26703]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 18 15:21:49 volumio volumio[26703]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 18 15:21:49 volumio volumio[26703]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 18 15:21:49 volumio volumio[26703]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 18 15:21:49 volumio volumio[26703]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 18 15:21:49 volumio volumio[26703]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 18 15:21:49 volumio volumio[26703]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 18 15:21:49 volumio volumio[26703]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 18 15:21:49 volumio volumio[26703]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 18 15:21:49 volumio volumio[26703]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 18 15:21:49 volumio volumio[26703]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 18 15:21:49 volumio volumio[26703]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 18 15:21:49 volumio volumio[26703]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 18 15:21:49 volumio volumio[26703]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 18 15:21:49 volumio volumio[26703]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 18 15:21:49 volumio volumio[26703]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 18 15:21:49 volumio volumio[26703]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 18 15:21:49 volumio volumio[26703]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 18 15:21:49 volumio volumio[26703]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 18 15:21:49 volumio volumio[26703]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 18 15:21:49 volumio volumio[26703]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 18 15:21:49 volumio volumio[26703]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 18 15:21:49 volumio volumio[26703]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 18 15:21:49 volumio volumio[26703]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 18 15:21:49 volumio volumio[26703]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 18 15:21:49 volumio volumio[26703]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 18 15:21:49 volumio volumio[26703]: info: Adding plugin bluetooth to MyMusic Plugins Feb 18 15:21:49 volumio volumio[26703]: info: Adding plugin multiroom to MyMusic Plugins Feb 18 15:21:49 volumio volumio[26703]: info: Adding plugin metavolumio to MyMusic Plugins Feb 18 15:21:49 volumio volumio[26703]: info: Adding plugin cd_controller to MyMusic Plugins Feb 18 15:21:49 volumio volumio[26703]: info: Adding plugin qobuzconnect to MyMusic Plugins Feb 18 15:21:49 volumio volumio[26703]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 18 15:21:49 volumio volumio[26703]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 18 15:21:49 volumio volumio[26703]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 18 15:21:50 volumio go-librespot[27055]: time="2026-02-18T15:21:50+07:00" level=debug msg="obtained new client token: AAAv7K3GMeERYzm07tTYB91mqXCGcXcTcq76G04Fjd2VL3lt2wpanQeCrMXQopYayquQ2tgquIegVeDPH81oesaIYa8aNGiUF4Npbz2U9q5YfBgt/MqlPwsQKjSLYbc2u30wKnfwRkHL3F4+T3XaZjqnK60KssCox2+4B0n/r9Ihy1ghcK90OZCfTOHDXNeWnSsQCIcKXDko8l2FfcwgvgWKz/nnSv4wT+2MZ5ByWt+L4sCbYTWcJvKOCw==" Feb 18 15:21:50 volumio go-librespot[27055]: time="2026-02-18T15:21:50+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 15:21:50 volumio go-librespot[27055]: time="2026-02-18T15:21:50+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 18 15:21:50 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 15:21:50 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 15:21:51 volumio volumio[26703]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 18 15:21:51 volumio volumio[26703]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 18 15:21:51 volumio volumio[26703]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 15:21:51 volumio volumio[26703]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 15:21:51 volumio volumio[26703]: info: Starting MyVolumio Remote Streaming Endpoints Feb 18 15:21:51 volumio volumio[26703]: info: MyVolumio login type: Token Feb 18 15:21:51 volumio volumio[26703]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 18 15:21:51 volumio volumio[26703]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 18 15:21:53 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 31. Feb 18 15:21:53 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 15:21:53 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 15:21:53 volumio go-librespot[27076]: go-librespot daemon starting... Feb 18 15:21:53 volumio go-librespot[27077]: time="2026-02-18T15:21:53+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 15:21:53 volumio go-librespot[27077]: time="2026-02-18T15:21:53+07:00" level=debug msg="app state loaded" Feb 18 15:21:53 volumio go-librespot[27077]: time="2026-02-18T15:21:53+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 15:21:53 volumio volumio[26703]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 18 15:21:53 volumio volumio[26703]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 18 15:21:53 volumio volumio[26703]: info: Streaming services startup Feb 18 15:21:53 volumio volumio[26703]: info: Starting Streaming Daemon Feb 18 15:21:53 volumio sudo[27084]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 18 15:21:53 volumio sudo[27084]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 15:21:53 volumio volumio[26703]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 18 15:21:53 volumio sudo[27084]: pam_unix(sudo:session): session closed for user root Feb 18 15:21:53 volumio volumio[26703]: info: Getting Spotify volume Feb 18 15:21:53 volumio volumio[26703]: info: Connection to go-librespot Websocket closed Feb 18 15:21:53 volumio volumio[26703]: error: Cannot start Volumio Streaming Daemon Feb 18 15:21:53 volumio volumio[26703]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 18 15:21:53 volumio volumio[26703]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 18 15:21:53 volumio volumio[26703]: 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 18 15:21:53 volumio go-librespot[27077]: time="2026-02-18T15:21:53+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 18 15:21:53 volumio go-librespot[27077]: time="2026-02-18T15:21:53+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 18 15:21:53 volumio go-librespot[27077]: time="2026-02-18T15:21:53+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 18 15:21:53 volumio go-librespot[27077]: time="2026-02-18T15:21:53+07:00" level=info msg="zeroconf server listening on port 38833" Feb 18 15:21:54 volumio volumio[26703]: info: CoreCommandRouter::volumioGetState Feb 18 15:21:54 volumio volumio[26703]: info: CorePlayQueue::getTrack 0 Feb 18 15:21:54 volumio volumio[26703]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Feb 18 15:21:54 volumio volumio[26703]: SPOTIFY: SPOTIFY VOLUME undefined Feb 18 15:21:54 volumio volumio[26703]: SPOTIFY: VOLUMIO VOLUME 100 Feb 18 15:21:54 volumio volumio[26703]: info: Aligning Spotify Volume to Volumio Volume Feb 18 15:21:54 volumio volumio[26703]: info: CoreCommandRouter::volumioGetState Feb 18 15:21:54 volumio volumio[26703]: info: CorePlayQueue::getTrack 0 Feb 18 15:21:54 volumio volumio[26703]: info: Setting Spotify Volume from Volumio: 100 Feb 18 15:21:54 volumio go-librespot[27077]: time="2026-02-18T15:21:54+07:00" level=debug msg="obtained new client token: AAC/DK3Md+sSwkFl72hQBArfg8X5GthoAG6RqyExRYNT50OmCaAGzxigv/LrRgpP6pEsbCq2dd2qRgeFoDKUV7ejf0dWuZTgTmqIQFQLB5Gr34Mlkrh9oK/JvN5Nm5SEH5TB2GAQsKDMgM2MaxYXSBWtJjHtxSema8U2qkKSVZ9j6V6DlF/SSpIBE1jPFkqHkjkCfvqR3iF0KIpkN3YboO8M6KNZaZ2G9HKRRMT8DYNeIuT2pWC09A4=" Feb 18 15:21:54 volumio go-librespot[27077]: time="2026-02-18T15:21:54+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 15:21:54 volumio go-librespot[27077]: time="2026-02-18T15:21:54+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 18 15:21:54 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 15:21:54 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 15:21:54 volumio volumio[26703]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 18 15:21:54 volumio volumio[26703]: Error: socket hang up Feb 18 15:21:54 volumio volumio[26703]: at connResetException (node:internal/errors:720:14) Feb 18 15:21:54 volumio volumio[26703]: at Socket.socketOnEnd (node:_http_client:519:23) Feb 18 15:21:54 volumio volumio[26703]: at Socket.emit (node:events:526:35) Feb 18 15:21:54 volumio volumio[26703]: at endReadableNT (node:internal/streams/readable:1376:12) Feb 18 15:21:54 volumio volumio[26703]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Feb 18 15:21:54 volumio volumio[26703]: code: 'ECONNRESET', Feb 18 15:21:54 volumio volumio[26703]: response: undefined Feb 18 15:21:54 volumio volumio[26703]: } Feb 18 15:21:54 volumio volumio[26703]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 18 15:21:55 volumio sudo[27105]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-18 15:20' Feb 18 15:21:55 volumio sudo[27105]: 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"