Feb 18 21:21:00 volumio volumio-remote-updater[25144]: [2026-02-18 21:21:00] [connect] Successful connection Feb 18 21:21:00 volumio volumio[7292]: info: Loading plugin "outputs"... Feb 18 21:21:00 volumio volumio[7292]: info: Loading plugin "albumart"... Feb 18 21:21:00 volumio volumio[7292]: info: Plugin example_plugin is not enabled Feb 18 21:21:00 volumio volumio[7292]: info: Loading plugin "inputs"... Feb 18 21:21:00 volumio volumio[7292]: info: Loading plugin "updater_comm"... Feb 18 21:21:01 volumio volumio[7292]: info: Plugin mpdemulation is not enabled Feb 18 21:21:01 volumio volumio[7292]: info: Loading plugin "rest_api"... Feb 18 21:21:01 volumio volumio[7292]: info: Loading plugin "websocket"... Feb 18 21:21:01 volumio volumio[7292]: info: Starting Socket.io Server version 1.7.4 Feb 18 21:21:01 volumio volumio[7292]: info: Loading plugin "RoonBridge"... Feb 18 21:21:01 volumio volumio[7292]: info: Applying required configuration parameters for plugin RoonBridge Feb 18 21:21:01 volumio volumio[7292]: info: Loading i18n strings for locale en Feb 18 21:21:01 volumio volumio[7292]: Updating browse sources language Feb 18 21:21:01 volumio volumio[7292]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 21:21:01 volumio volumio[7405]: Forking 3 albumart workers Feb 18 21:21:02 volumio volumio[7292]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 18 21:21:02 volumio volumio[7292]: info: CoreCommandRouter::initPlayerControls Feb 18 21:21:02 volumio volumio[7292]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 21:21:02 volumio volumio[7292]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 21:21:02 volumio volumio[7292]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 21:21:02 volumio volumio[7292]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 21:21:02 volumio volumio[7292]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 21:21:02 volumio volumio[7292]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 21:21:02 volumio volumio[7292]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 21:21:02 volumio volumio[7292]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 21:21:02 volumio volumio[7292]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 18 21:21:02 volumio volumio[7292]: Express server listening on port 3000 Feb 18 21:21:02 volumio volumio[7292]: [Metrics] WebUI: 16s 58.11ms Feb 18 21:21:02 volumio volumio[7292]: info: CoreStateMachine::resetVolumioState Feb 18 21:21:02 volumio volumio[7292]: info: CoreStateMachine::getcurrentVolume Feb 18 21:21:02 volumio volumio[7292]: info: CoreCommandRouter::volumioRetrievevolume Feb 18 21:21:02 volumio sudo[7448]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 18 21:21:02 volumio sudo[7448]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 21:21:02 volumio sudo[7451]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 18 21:21:02 volumio volumio[7292]: info: Volumio Network Manager: Network status updated: 1 Feb 18 21:21:02 volumio sudo[7451]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 21:21:02 volumio sudo[7448]: pam_unix(sudo:session): session closed for user root Feb 18 21:21:02 volumio sudo[7451]: pam_unix(sudo:session): session closed for user root Feb 18 21:21:02 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 20. Feb 18 21:21:02 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 21:21:02 volumio volumio[7292]: info: VolumeController:: Volume=100 Mute =false Feb 18 21:21:02 volumio volumio[7292]: info: CoreStateMachine::pushState Feb 18 21:21:02 volumio volumio[7292]: info: CorePlayQueue::getTrack 0 Feb 18 21:21:02 volumio volumio[7292]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 18 21:21:02 volumio volumio[7292]: info: CoreCommandRouter::volumioPushState Feb 18 21:21:02 volumio volumio[7292]: info: CoreStateMachine::updateTrackBlock Feb 18 21:21:02 volumio volumio[7292]: info: CorePlayQueue::getTrackBlock Feb 18 21:21:02 volumio volumio[7292]: info: CoreCommandRouter::volumioRetrievevolume Feb 18 21:21:02 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 21:21:02 volumio go-librespot[7456]: go-librespot daemon starting... Feb 18 21:21:02 volumio volumio-remote-updater[25144]: [2026-02-18 21:21:02] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1771424460 101 Feb 18 21:21:02 volumio go-librespot[7458]: time="2026-02-18T21:21:02+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 21:21:02 volumio go-librespot[7458]: time="2026-02-18T21:21:02+07:00" level=debug msg="app state loaded" Feb 18 21:21:02 volumio go-librespot[7458]: time="2026-02-18T21:21:02+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 21:21:02 volumio volumio[7292]: 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 21:21:02 volumio volumio[7292]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 21:21:02 volumio volumio[7292]: info: Reloading queue from file Feb 18 21:21:02 volumio volumio[7292]: info: CoreStateMachine::setRepeat null single undefined Feb 18 21:21:02 volumio volumio[7292]: info: CoreStateMachine::pushState Feb 18 21:21:02 volumio volumio[7292]: info: CorePlayQueue::getTrack 0 Feb 18 21:21:02 volumio volumio[7292]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 18 21:21:02 volumio volumio[7292]: info: CoreCommandRouter::volumioPushState Feb 18 21:21:02 volumio volumio[7292]: info: CoreStateMachine::setRandom null Feb 18 21:21:02 volumio volumio[7292]: info: CoreStateMachine::pushState Feb 18 21:21:02 volumio volumio[7292]: info: CorePlayQueue::getTrack 0 Feb 18 21:21:02 volumio volumio[7292]: info: CoreCommandRouter::volumioPushState Feb 18 21:21:02 volumio volumio[7292]: info: Setting Device type: Raspberry PI Feb 18 21:21:02 volumio volumio[7292]: info: Completed loading Core Plugins Feb 18 21:21:02 volumio volumio[7292]: info: Preparing to generate the ALSA configuration file Feb 18 21:21:03 volumio volumio[7292]: info: VolumeController:: Volume=100 Mute =false Feb 18 21:21:03 volumio volumio[7292]: info: CoreStateMachine::pushState Feb 18 21:21:03 volumio volumio[7292]: info: CorePlayQueue::getTrack 0 Feb 18 21:21:03 volumio volumio[7292]: info: CoreCommandRouter::volumioPushState Feb 18 21:21:03 volumio volumio[7292]: info: Asound.conf file unchanged, so no further update is needed Feb 18 21:21:03 volumio volumio[7292]: info: Output device has changed, restarting MPD Feb 18 21:21:03 volumio sudo[7473]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 18 21:21:03 volumio sudo[7473]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 21:21:03 volumio volumio[7292]: info: Output device has changed, restarting Shairport Sync Feb 18 21:21:03 volumio volumio[7292]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 21:21:03 volumio volumio[7292]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 21:21:03 volumio go-librespot[7458]: time="2026-02-18T21:21:03+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 18 21:21:03 volumio go-librespot[7458]: time="2026-02-18T21:21:03+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 18 21:21:03 volumio go-librespot[7458]: time="2026-02-18T21:21:03+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 18 21:21:03 volumio go-librespot[7458]: time="2026-02-18T21:21:03+07:00" level=info msg="zeroconf server listening on port 42435" Feb 18 21:21:03 volumio sudo[7478]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 18 21:21:03 volumio sudo[7475]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 18 21:21:03 volumio sudo[7478]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 21:21:03 volumio sudo[7475]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 21:21:03 volumio sudo[7475]: pam_unix(sudo:session): session closed for user root Feb 18 21:21:03 volumio volumio[7292]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 18 21:21:03 volumio volumio[7292]: info: ___________ START PLUGINS ___________ Feb 18 21:21:03 volumio volumio[7292]: info: ControllerMpd::onStart: Initializing MPD Feb 18 21:21:03 volumio sudo[7473]: pam_unix(sudo:session): session closed for user root Feb 18 21:21:03 volumio volumio[7292]: info: Creating MPD Configuration file Feb 18 21:21:03 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 18 21:21:03 volumio go-librespot[7458]: time="2026-02-18T21:21:03+07:00" level=debug msg="obtained new client token: AADfm5ZGdSCzpgvfo2fDxG8nuGEKzGAKkcQZvriSTlKPY6P1qR3XSy4eAgMDYKBVABrLnbBBbGGA6XRjGTCgGa+5XLq7QEVunUdnuspHPKKMk5nWqC2X1aPm479WbOSt090Svx77Dv3Hg9No6dvV24McJ82ip7YLWU0d2gbKVgyLNQTcjeEWwM4ZGMxmVnrWaB33LhQhtDNMAsF9/5e+MDKfcv3oVBXf8qVjQUbNjNc4oC4mVjrK/+gjZw==" Feb 18 21:21:03 volumio sudo[7486]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 18 21:21:03 volumio volumio[7292]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 18 21:21:03 volumio volumio[7292]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 21:21:03 volumio volumio[7292]: info: [1771424463566] CoreMusicLibrary::Adding element Media Servers Feb 18 21:21:03 volumio sudo[7486]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 21:21:03 volumio sudo[7488]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 18 21:21:03 volumio volumio[7292]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 21:21:03 volumio sudo[7488]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 21:21:03 volumio sudo[7486]: pam_unix(sudo:session): session closed for user root Feb 18 21:21:03 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 18 21:21:03 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 18 21:21:03 volumio systemd[1]: mpd.service: Consumed 6.985s CPU time. Feb 18 21:21:03 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 18 21:21:03 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 18 21:21:03 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 18 21:21:03 volumio go-librespot[7458]: time="2026-02-18T21:21:03+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 21:21:03 volumio volumio[7292]: info: UPNP Browser: Client initialized successfully Feb 18 21:21:03 volumio volumio[7292]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 21:21:03 volumio volumio[7292]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 21:21:03 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 18 21:21:03 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 18 21:21:03 volumio go-librespot[7458]: time="2026-02-18T21:21:03+07:00" level=debug msg="completed keyexchange" Feb 18 21:21:03 volumio go-librespot[7458]: time="2026-02-18T21:21:03+07:00" level=debug msg="completed challenge" Feb 18 21:21:03 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 18 21:21:03 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 18 21:21:03 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 18 21:21:03 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 18 21:21:03 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 18 21:21:03 volumio volumio[7292]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 18 21:21:03 volumio go-librespot[7458]: time="2026-02-18T21: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 21:21:03 volumio volumio[7292]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 21:21:03 volumio volumio[7292]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 21:21:03 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 18 21:21:03 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 18 21:21:03 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 21:21:03 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 21:21:04 volumio volumio[7292]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 18 21:21:04 volumio volumio[7292]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 21:21:04 volumio volumio[7292]: info: [1771424464025] CoreMusicLibrary::Adding element Last_100 Feb 18 21:21:04 volumio volumio[7292]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 21:21:04 volumio volumio[7292]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 21:21:04 volumio volumio[7292]: info: [1771424464046] CoreMusicLibrary::Adding element Webradio Feb 18 21:21:04 volumio volumio[7292]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 21:21:04 volumio volumio[7292]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 18 21:21:04 volumio volumio[7292]: info: Initializing BBC Radios Feb 18 21:21:04 volumio volumio[7292]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 18 21:21:04 volumio volumio[7292]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 21:21:04 volumio volumio[7292]: info: Creating Spotify config file Feb 18 21:21:04 volumio volumio[7292]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 21:21:04 volumio sudo[7502]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 18 21:21:04 volumio sudo[7502]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 18 21:21:04 volumio sudo[7502]: pam_unix(sudo:session): session closed for user root Feb 18 21:21:05 volumio volumio[7417]: Starting albumart workers Feb 18 21:21:05 volumio volumio[7416]: Starting albumart workers Feb 18 21:21:05 volumio volumio[7415]: Starting albumart workers Feb 18 21:21:05 volumio volumio[7292]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 21:21:05 volumio volumio[7292]: info: [1771424465664] CoreMusicLibrary::Adding element YouTube Music Feb 18 21:21:05 volumio volumio[7292]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 21:21:05 volumio volumio[7292]: Cannot find translation for source YouTube Music Feb 18 21:21:05 volumio volumio[7292]: info: Volumio Calling Home Feb 18 21:21:05 volumio sudo[7519]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Feb 18 21:21:05 volumio sudo[7519]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 21:21:05 volumio sudo[7519]: pam_unix(sudo:session): session closed for user root Feb 18 21:21:06 volumio volumio[7292]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Feb 18 21:21:06 volumio volumio[7292]: info: Discovery: Found device Volumio Feb 18 21:21:06 volumio volumio[7292]: info: CoreCommandRouter::volumioGetState Feb 18 21:21:06 volumio volumio[7292]: info: CorePlayQueue::getTrack 0 Feb 18 21:21:06 volumio volumio[7292]: info: MPD Permissions set Feb 18 21:21:06 volumio volumio[7292]: info: MPD Permissions set Feb 18 21:21:06 volumio volumio[7292]: info: Upmpdcli Daemon Started Feb 18 21:21:06 volumio volumio[7292]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Feb 18 21:21:06 volumio volumio[7292]: info: Discovery: Found device Volumio Feb 18 21:21:06 volumio volumio[7292]: info: CoreCommandRouter::volumioGetState Feb 18 21:21:06 volumio volumio[7292]: info: CorePlayQueue::getTrack 0 Feb 18 21:21:06 volumio volumio[7292]: info: Spotify config file written Feb 18 21:21:06 volumio volumio[7292]: 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 21:21:06 volumio sudo[7525]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 18 21:21:06 volumio volumio[7292]: info: Volumio called home Feb 18 21:21:06 volumio sudo[7525]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 21:21:06 volumio volumio[7292]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 21:21:06 volumio volumio[7292]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 21:21:06 volumio volumio[7292]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 21:21:06 volumio volumio[7292]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 21:21:06 volumio volumio[7292]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 21:21:06 volumio volumio[7292]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 21:21:06 volumio volumio[7292]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 21:21:06 volumio volumio[7292]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 21:21:06 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 21:21:06 volumio volumio[7292]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 21:21:06 volumio volumio[7292]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 21:21:06 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 21:21:06 volumio go-librespot[7532]: go-librespot daemon starting... Feb 18 21:21:06 volumio volumio[7292]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 21:21:06 volumio volumio[7292]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 21:21:06 volumio volumio[7292]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 21:21:06 volumio volumio[7292]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 21:21:06 volumio volumio[7292]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 21:21:06 volumio volumio[7292]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 21:21:06 volumio volumio[7292]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 21:21:06 volumio volumio[7292]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 21:21:06 volumio sudo[7525]: pam_unix(sudo:session): session closed for user root Feb 18 21:21:06 volumio go-librespot[7533]: time="2026-02-18T21:21:06+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 21:21:06 volumio go-librespot[7533]: time="2026-02-18T21:21:06+07:00" level=debug msg="app state loaded" Feb 18 21:21:06 volumio go-librespot[7533]: time="2026-02-18T21:21:06+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 21:21:06 volumio volumio[7292]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 21:21:06 volumio volumio[7292]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 21:21:06 volumio volumio[7292]: info: No need to fix Spotify hosts Feb 18 21:21:07 volumio go-librespot[7533]: time="2026-02-18T21:21:07+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 21:21:07 volumio go-librespot[7533]: time="2026-02-18T21:21:07+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 21:21:07 volumio go-librespot[7533]: time="2026-02-18T21:21:07+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 21:21:07 volumio go-librespot[7533]: time="2026-02-18T21:21:07+07:00" level=info msg="zeroconf server listening on port 45677" Feb 18 21:21:07 volumio go-librespot[7533]: time="2026-02-18T21:21:07+07:00" level=debug msg="obtained new client token: AABZdeXN5S0vNZ9Mfd2jgb2WnESa8JnUFglR1bIwihTkuwp9LciedxMCERQtO1sKZMejAOd0cFZs6GooFBg20IO3kn4C6iOk/kJLa89WkeQW+6y/Bljs31uNU+74vQr/X72zL+byWx6JZYiPjzkZ2E4iUxJUuHQA+a5gKOqLYnOygOZlcQ0kJEO3xVTNsiUHONzNWBhNgbtcXOyck9ziCah7hDChjZ9cW2gwKhM+KDgwORULDFWWDkAF1A==" Feb 18 21:21:07 volumio go-librespot[7533]: time="2026-02-18T21: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 21:21:08 volumio go-librespot[7533]: time="2026-02-18T21:21:08+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Feb 18 21:21:08 volumio go-librespot[7533]: time="2026-02-18T21:21:08+07:00" level=debug msg="completed keyexchange" Feb 18 21:21:08 volumio go-librespot[7533]: time="2026-02-18T21:21:08+07:00" level=debug msg="completed challenge" Feb 18 21:21:08 volumio go-librespot[7533]: time="2026-02-18T21:21:08+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 18 21:21:08 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 21:21:08 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 21:21:08 volumio volumio[7292]: info: Starting Shairport Sync Feb 18 21:21:08 volumio volumio[7292]: info: Starting Shairport Sync Feb 18 21:21:08 volumio volumio[7292]: info: Starting Shairport Sync Feb 18 21:21:08 volumio sudo[7564]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 18 21:21:08 volumio sudo[7564]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 21:21:08 volumio sudo[7566]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 18 21:21:08 volumio sudo[7566]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 21:21:08 volumio sudo[7568]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 18 21:21:08 volumio sudo[7568]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 21:21:08 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 18 21:21:08 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 18 21:21:08 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 18 21:21:08 volumio systemd[1]: shairport-sync.service: Consumed 2.176s CPU time. Feb 18 21:21:08 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 18 21:21:08 volumio sudo[7564]: pam_unix(sudo:session): session closed for user root Feb 18 21:21:08 volumio volumio[7292]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 18 21:21:08 volumio volumio[7292]: SPOTIFY: BQCwOc2cnhHlVRGmkWsftG-KHdGL1XSIKb2Itpac4zzUdxayzwTy1OavA1Fn_mD6B6gWOnWKMv4USkbndGCSkhLN381RxMgxjtz1DiWhiMyyYmcoNzFhQoCXVEpJlgZ41U-TMZeiKDcEZTulMJcjHZhn6kYlBoDneIDJ2HzKWr39IJn1tnAM7TSprJBHHnKIgbdUmlpl73f86Czoo3GtZCkUQRX-25vK_aPvV2Czr-zIIsFtnqvqNhRGiOJVEP6uYxsbTKbFuqRzrYNFyDssrUByc-A0s8FSYa79VcyckTPbsTLAd93kQ7zS Feb 18 21:21:08 volumio volumio[7292]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 18 21:21:08 volumio volumio[7292]: info: New Spotify access token = BQCwOc2cnhHlVRGmkWsftG-KHdGL1XSIKb2Itpac4zzUdxayzwTy1OavA1Fn_mD6B6gWOnWKMv4USkbndGCSkhLN381RxMgxjtz1DiWhiMyyYmcoNzFhQoCXVEpJlgZ41U-TMZeiKDcEZTulMJcjHZhn6kYlBoDneIDJ2HzKWr39IJn1tnAM7TSprJBHHnKIgbdUmlpl73f86Czoo3GtZCkUQRX-25vK_aPvV2Czr-zIIsFtnqvqNhRGiOJVEP6uYxsbTKbFuqRzrYNFyDssrUByc-A0s8FSYa79VcyckTPbsTLAd93kQ7zS Feb 18 21:21:08 volumio volumio[7292]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 18 21:21:08 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 18 21:21:08 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 18 21:21:08 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 18 21:21:08 volumio volumio[7292]: info: CoreCommandRouter::volumioGetState Feb 18 21:21:08 volumio volumio[7292]: info: CorePlayQueue::getTrack 0 Feb 18 21:21:08 volumio volumio[7292]: info: Shairport-Sync Started Feb 18 21:21:08 volumio volumio[7292]: Error adding Membership: Error: addMembership EINVAL Feb 18 21:21:08 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 18 21:21:08 volumio sudo[7568]: pam_unix(sudo:session): session closed for user root Feb 18 21:21:08 volumio sudo[7566]: pam_unix(sudo:session): session closed for user root Feb 18 21:21:08 volumio volumio[7292]: info: Shairport-Sync Started Feb 18 21:21:08 volumio volumio[7292]: info: Shairport-Sync Started Feb 18 21:21:09 volumio volumio[7292]: 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 21:21:09 volumio volumio[7292]: info: Spotify Successfully logged in Feb 18 21:21:09 volumio volumio[7292]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 21:21:09 volumio volumio[7292]: info: [1771424469201] CoreMusicLibrary::Adding element Spotify Feb 18 21:21:09 volumio volumio[7292]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 21:21:09 volumio volumio[7292]: Cannot find translation for source YouTube Music Feb 18 21:21:09 volumio volumio[7292]: Cannot find translation for source Spotify Feb 18 21:21:09 volumio volumio[7292]: info: [yt-cast-receiver] DIAL server listening on port 8098 Feb 18 21:21:09 volumio volumio[7292]: info: CoreCommandRouter::volumioRetrievevolume Feb 18 21:21:09 volumio volumio[7292]: info: VolumeController:: Volume=100 Mute =false Feb 18 21:21:09 volumio volumio[7292]: info: CoreCommandRouter::volumioGetState Feb 18 21:21:09 volumio volumio[7292]: info: CorePlayQueue::getTrack 0 Feb 18 21:21:09 volumio volumio[7292]: info: CoreStateMachine::pushState Feb 18 21:21:09 volumio volumio[7292]: info: CorePlayQueue::getTrack 0 Feb 18 21:21:09 volumio volumio[7292]: info: CoreCommandRouter::volumioPushState Feb 18 21:21:11 volumio volumio[7292]: info: go-librespot daemon successfully initialized Feb 18 21:21:11 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 21. Feb 18 21:21:11 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 21:21:11 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 21:21:11 volumio go-librespot[7613]: go-librespot daemon starting... Feb 18 21:21:11 volumio go-librespot[7614]: time="2026-02-18T21:21:11+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 21:21:11 volumio go-librespot[7614]: time="2026-02-18T21:21:11+07:00" level=debug msg="app state loaded" Feb 18 21:21:11 volumio go-librespot[7614]: time="2026-02-18T21:21:11+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 21:21:11 volumio mpd[7517]: 2026-02-18T21:21:11 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 18 21:21:11 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 18 21:21:11 volumio sudo[7488]: pam_unix(sudo:session): session closed for user root Feb 18 21:21:11 volumio sudo[7478]: pam_unix(sudo:session): session closed for user root Feb 18 21:21:11 volumio go-librespot[7614]: time="2026-02-18T21: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 21:21:11 volumio go-librespot[7614]: time="2026-02-18T21: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 21:21:11 volumio go-librespot[7614]: time="2026-02-18T21: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 21:21:11 volumio go-librespot[7614]: time="2026-02-18T21:21:11+07:00" level=info msg="zeroconf server listening on port 39187" Feb 18 21:21:11 volumio volumio[7292]: error: MPD error: The expression evaluated to a falsy value: Feb 18 21:21:11 volumio volumio[7292]: assert.ok(self.idling) Feb 18 21:21:11 volumio volumio[7292]: error: The expression evaluated to a falsy value: Feb 18 21:21:11 volumio volumio[7292]: assert.ok(self.idling) Feb 18 21:21:12 volumio volumio[7292]: info: MPD running with PID7517 Feb 18 21:21:12 volumio volumio[7292]: ,establishing connection Feb 18 21:21:12 volumio volumio[7292]: error: updateQueue error: null Feb 18 21:21:12 volumio volumio[7292]: info: Completed starting Core Plugins Feb 18 21:21:12 volumio volumio[7292]: info: ------------------------------------------- Feb 18 21:21:12 volumio volumio[7292]: info: ----- MyVolumio plugins startup ---- Feb 18 21:21:12 volumio volumio[7292]: info: ------------------------------------------- Feb 18 21:21:12 volumio volumio[7292]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 18 21:21:12 volumio volumio[7292]: error: updateQueue error: null Feb 18 21:21:12 volumio go-librespot[7614]: time="2026-02-18T21:21:12+07:00" level=debug msg="obtained new client token: AABNvs5yhpf4GzFWkXjxu5dNLJ9btdZHnnbbj6mduHZxwJMcTXxmzoYLvBjnon16Qhmq7xx9bcv74LqkahMMZpf2JslZi3O+kWd/HzQRE2t3Td5lOWMErCGC/fY4u/8gn0uz38bRMcCmeenFMr2A6m0Y6lx5b3QqtjIQMn4EAcOiuka+1CGXJ2Q/O+tWRwCRjEnBsACPv+4dR6SVSQehs5RNRBQebLBYOmHtJmMt2PS6gcYiVv6fRQw=" Feb 18 21:21:12 volumio go-librespot[7614]: time="2026-02-18T21:21:12+07:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:4070, retrying with a different AP" error="dial tcp 104.199.241.202:4070: connect: connection refused" Feb 18 21:21:12 volumio go-librespot[7614]: time="2026-02-18T21:21:12+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Feb 18 21:21:12 volumio go-librespot[7614]: time="2026-02-18T21:21:12+07:00" level=debug msg="completed keyexchange" Feb 18 21:21:12 volumio go-librespot[7614]: time="2026-02-18T21:21:12+07:00" level=debug msg="completed challenge" Feb 18 21:21:12 volumio go-librespot[7614]: time="2026-02-18T21:21:12+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 18 21:21:12 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 21:21:12 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 21:21:14 volumio volumio[7292]: info: Initializing connection to go-librespot Websocket Feb 18 21:21:14 volumio volumio[7292]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 18 21:21:15 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 22. Feb 18 21:21:15 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 21:21:15 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 21:21:15 volumio go-librespot[7626]: go-librespot daemon starting... Feb 18 21:21:15 volumio go-librespot[7628]: time="2026-02-18T21:21:15+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 21:21:15 volumio go-librespot[7628]: time="2026-02-18T21:21:15+07:00" level=debug msg="app state loaded" Feb 18 21:21:15 volumio go-librespot[7628]: time="2026-02-18T21:21:15+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 21:21:16 volumio go-librespot[7628]: time="2026-02-18T21:21:16+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 18 21:21:16 volumio go-librespot[7628]: time="2026-02-18T21:21:16+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 18 21:21:16 volumio go-librespot[7628]: time="2026-02-18T21:21:16+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 18 21:21:16 volumio go-librespot[7628]: time="2026-02-18T21:21:16+07:00" level=info msg="zeroconf server listening on port 37371" Feb 18 21:21:16 volumio go-librespot[7628]: time="2026-02-18T21:21:16+07:00" level=debug msg="obtained new client token: AAAXAm0F3/+dQ3ytSVOMzk0U+FXvNlsWL8aimc83ykuas03WSBRI7rU/EhmRPvrnAUKML41b4QD88LgRozLLhayWrVtU0e02rcQx8kxpnK8Nt2N+x5MFtrKG7eZ3WKExqhPc2o9LUUqc3UTR+dUIUBKFK8xkfYnsrRNU6lQWqrL8XNJkZtpJjGMCtasPB5CTjWuKeDBSNnVzFBmsAK3Quvk4otr2BZvFMAOqbZD+IjsgQoVkqZ5F7E8Q8g==" Feb 18 21:21:16 volumio go-librespot[7628]: time="2026-02-18T21:21:16+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 21:21:16 volumio go-librespot[7628]: time="2026-02-18T21:21:16+07:00" level=debug msg="completed keyexchange" Feb 18 21:21:16 volumio go-librespot[7628]: time="2026-02-18T21:21:16+07:00" level=debug msg="completed challenge" Feb 18 21:21:16 volumio go-librespot[7628]: time="2026-02-18T21:21:16+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 18 21:21:16 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 21:21:16 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 21:21:16 volumio volumio[7292]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 18 21:21:17 volumio volumio[7292]: info: Initializing connection to go-librespot Websocket Feb 18 21:21:17 volumio volumio[7292]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 18 21:21:19 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 23. Feb 18 21:21:19 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 21:21:19 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 21:21:19 volumio go-librespot[7635]: go-librespot daemon starting... Feb 18 21:21:19 volumio go-librespot[7636]: time="2026-02-18T21:21:19+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 21:21:19 volumio go-librespot[7636]: time="2026-02-18T21:21:19+07:00" level=debug msg="app state loaded" Feb 18 21:21:19 volumio go-librespot[7636]: time="2026-02-18T21:21:19+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 21:21:20 volumio volumio[7292]: info: Initializing connection to go-librespot Websocket Feb 18 21:21:20 volumio go-librespot[7636]: time="2026-02-18T21:21:20+07:00" level=debug msg="new websocket client" Feb 18 21:21:20 volumio volumio[7292]: info: Connection to go-librespot Websocket established Feb 18 21:21:20 volumio go-librespot[7636]: time="2026-02-18T21:21:20+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 21:21:20 volumio go-librespot[7636]: time="2026-02-18T21:21:20+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 21:21:20 volumio go-librespot[7636]: time="2026-02-18T21:21:20+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 21:21:20 volumio go-librespot[7636]: time="2026-02-18T21:21:20+07:00" level=info msg="zeroconf server listening on port 34667" Feb 18 21:21:20 volumio go-librespot[7636]: time="2026-02-18T21:21:20+07:00" level=debug msg="obtained new client token: AACDcVzyKTQ1ZWk9zF/56T5gagcqygqcdiXbxJ6BrkNAaDKNU4XtyHcVc0OGfbH4JD6pKzFPW/GlqnZuQhjnNDwn9h7vl6wF4NlIKtTaYAT+rSypngfndtIX5faIkFzz4HJap9/T/7JhPQoFLMpo8hYEPOzQAf4d6aCMiU8+OGsGhduzPV4EYVa5cHvEoMvmLBolSwYMEKveTfGHov+srJmMhxprdM7+l76xH1jruVerWFaCJcU/q55FjQ==" Feb 18 21:21:20 volumio go-librespot[7636]: time="2026-02-18T21:21:20+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 21:21:20 volumio volumio[7292]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 18 21:21:20 volumio volumio[7292]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 18 21:21:20 volumio volumio[7292]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 18 21:21:20 volumio volumio[7292]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 18 21:21:20 volumio volumio[7292]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 18 21:21:20 volumio volumio[7292]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 18 21:21:20 volumio volumio[7292]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 18 21:21:20 volumio volumio[7292]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 18 21:21:20 volumio volumio[7292]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 18 21:21:20 volumio volumio[7292]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 18 21:21:20 volumio volumio[7292]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 18 21:21:20 volumio volumio[7292]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 18 21:21:20 volumio volumio[7292]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 18 21:21:20 volumio volumio[7292]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 18 21:21:20 volumio volumio[7292]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 18 21:21:20 volumio volumio[7292]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 18 21:21:20 volumio volumio[7292]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 18 21:21:20 volumio volumio[7292]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 18 21:21:20 volumio volumio[7292]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 18 21:21:20 volumio volumio[7292]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 18 21:21:20 volumio volumio[7292]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 18 21:21:20 volumio volumio[7292]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 18 21:21:20 volumio volumio[7292]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 18 21:21:20 volumio volumio[7292]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 18 21:21:20 volumio volumio[7292]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 18 21:21:20 volumio volumio[7292]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 18 21:21:20 volumio volumio[7292]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 18 21:21:20 volumio volumio[7292]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 18 21:21:20 volumio volumio[7292]: info: Adding plugin bluetooth to MyMusic Plugins Feb 18 21:21:20 volumio volumio[7292]: info: Adding plugin multiroom to MyMusic Plugins Feb 18 21:21:20 volumio volumio[7292]: info: Adding plugin metavolumio to MyMusic Plugins Feb 18 21:21:20 volumio volumio[7292]: info: Adding plugin cd_controller to MyMusic Plugins Feb 18 21:21:20 volumio volumio[7292]: info: Adding plugin qobuzconnect to MyMusic Plugins Feb 18 21:21:20 volumio volumio[7292]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 18 21:21:20 volumio volumio[7292]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 18 21:21:20 volumio volumio[7292]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 18 21:21:20 volumio go-librespot[7636]: time="2026-02-18T21:21:20+07:00" level=debug msg="completed keyexchange" Feb 18 21:21:20 volumio go-librespot[7636]: time="2026-02-18T21:21:20+07:00" level=debug msg="completed challenge" Feb 18 21:21:20 volumio go-librespot[7636]: time="2026-02-18T21: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 21:21:20 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 21:21:20 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 21:21:22 volumio volumio[7292]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 18 21:21:22 volumio volumio[7292]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 18 21:21:22 volumio volumio[7292]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 21:21:22 volumio volumio[7292]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 21:21:22 volumio volumio[7292]: info: Starting MyVolumio Remote Streaming Endpoints Feb 18 21:21:22 volumio volumio[7292]: info: MyVolumio login type: Token Feb 18 21:21:22 volumio volumio[7292]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 18 21:21:22 volumio volumio[7292]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 18 21:21:24 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 24. Feb 18 21:21:24 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 21:21:24 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 21:21:24 volumio go-librespot[7658]: go-librespot daemon starting... Feb 18 21:21:24 volumio go-librespot[7659]: time="2026-02-18T21:21:24+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 21:21:24 volumio go-librespot[7659]: time="2026-02-18T21:21:24+07:00" level=debug msg="app state loaded" Feb 18 21:21:24 volumio go-librespot[7659]: time="2026-02-18T21:21:24+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 21:21:24 volumio volumio[7292]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 18 21:21:24 volumio volumio[7292]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 18 21:21:24 volumio volumio[7292]: info: Streaming services startup Feb 18 21:21:24 volumio volumio[7292]: info: Starting Streaming Daemon Feb 18 21:21:24 volumio sudo[7667]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 18 21:21:24 volumio volumio[7292]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 18 21:21:24 volumio sudo[7667]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 21:21:24 volumio go-librespot[7659]: time="2026-02-18T21: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 21:21:24 volumio go-librespot[7659]: time="2026-02-18T21: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 21:21:24 volumio go-librespot[7659]: time="2026-02-18T21: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 21:21:24 volumio sudo[7667]: pam_unix(sudo:session): session closed for user root Feb 18 21:21:24 volumio go-librespot[7659]: time="2026-02-18T21:21:24+07:00" level=info msg="zeroconf server listening on port 36841" Feb 18 21:21:24 volumio volumio[7292]: info: Getting Spotify volume Feb 18 21:21:24 volumio volumio[7292]: info: Connection to go-librespot Websocket closed Feb 18 21:21:24 volumio volumio[7292]: error: Cannot start Volumio Streaming Daemon Feb 18 21:21:24 volumio volumio[7292]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 18 21:21:24 volumio volumio[7292]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 18 21:21:24 volumio volumio[7292]: 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 21:21:24 volumio go-librespot[7659]: time="2026-02-18T21:21:24+07:00" level=debug msg="obtained new client token: AABKZF0IM24D+O7BVyB6SYpIZkKXHC577OXp/Mj6cKvSMPYf2RWN71gnw+i1e/qg351pEuyvp6yObNrBOhDf7sxy0eq9r2aHnpl1yHXvVAmYFO3I+beCynRGSXmcLdEHqUWFriS6lv0VnqbnOPKxmy3qE3EY6Mt4hRMA9VYtDItweffyjdZ5K591hwc5ya3cFMAlbgZ5AUp2aY3h4onxL17hLS2+nxPygvowxyHwtHrEFrcXHXBeAX4JOw==" Feb 18 21:21:25 volumio go-librespot[7659]: time="2026-02-18T21:21:25+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 21:21:25 volumio volumio[7292]: info: CoreCommandRouter::volumioGetState Feb 18 21:21:25 volumio volumio[7292]: info: CorePlayQueue::getTrack 0 Feb 18 21:21:25 volumio volumio[7292]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Feb 18 21:21:25 volumio volumio[7292]: SPOTIFY: SPOTIFY VOLUME undefined Feb 18 21:21:25 volumio volumio[7292]: SPOTIFY: VOLUMIO VOLUME 100 Feb 18 21:21:25 volumio volumio[7292]: info: Aligning Spotify Volume to Volumio Volume Feb 18 21:21:25 volumio volumio[7292]: info: CoreCommandRouter::volumioGetState Feb 18 21:21:25 volumio volumio[7292]: info: CorePlayQueue::getTrack 0 Feb 18 21:21:25 volumio volumio[7292]: info: Setting Spotify Volume from Volumio: 100 Feb 18 21:21:25 volumio go-librespot[7659]: time="2026-02-18T21:21:25+07:00" level=debug msg="completed keyexchange" Feb 18 21:21:25 volumio go-librespot[7659]: time="2026-02-18T21:21:25+07:00" level=debug msg="completed challenge" Feb 18 21:21:25 volumio go-librespot[7659]: time="2026-02-18T21:21:25+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 18 21:21:25 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 21:21:25 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 21:21:25 volumio volumio[7292]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 18 21:21:25 volumio volumio[7292]: Error: socket hang up Feb 18 21:21:25 volumio volumio[7292]: at connResetException (node:internal/errors:720:14) Feb 18 21:21:25 volumio volumio[7292]: at Socket.socketOnEnd (node:_http_client:519:23) Feb 18 21:21:25 volumio volumio[7292]: at Socket.emit (node:events:526:35) Feb 18 21:21:25 volumio volumio[7292]: at endReadableNT (node:internal/streams/readable:1376:12) Feb 18 21:21:25 volumio volumio[7292]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Feb 18 21:21:25 volumio volumio[7292]: code: 'ECONNRESET', Feb 18 21:21:25 volumio volumio[7292]: response: undefined Feb 18 21:21:25 volumio volumio[7292]: } Feb 18 21:21:25 volumio volumio[7292]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 18 21:21:26 volumio sudo[7688]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-18 21:20' Feb 18 21:21:26 volumio sudo[7688]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 21:21:27 volumio sudo[7688]: pam_unix(sudo:session): session closed for user root Feb 18 21:21:28 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 25. Feb 18 21:21:28 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 21:21:28 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 21:21:28 volumio go-librespot[7696]: go-librespot daemon starting... Feb 18 21:21:28 volumio go-librespot[7697]: time="2026-02-18T21:21:28+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 21:21:28 volumio go-librespot[7697]: time="2026-02-18T21:21:28+07:00" level=debug msg="app state loaded" Feb 18 21:21:28 volumio go-librespot[7697]: time="2026-02-18T21:21:28+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 21:21:28 volumio volumio-remote-updater[25144]: [2026-02-18 21:21:28] [error] handle_read_frame error: asio.system:104 (Connection reset by peer) Feb 18 21:21:28 volumio volumio-remote-updater[25144]: [2026-02-18 21:21:28] [disconnect] Disconnect close local:[1006,Connection reset by peer] remote:[1006] Feb 18 21:21:28 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Feb 18 21:21:28 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Feb 18 21:21:28 volumio systemd[1]: volumio.service: Consumed 55.756s CPU time. Feb 18 21:21:28 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 18 21:21:28 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 18 21:21:28 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 22459. Feb 18 21:21:28 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 18 21:21:28 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Feb 18 21:21:28 volumio systemd[1]: volumio.service: Consumed 55.756s CPU time. Feb 18 21:21:28 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Feb 18 21:21:28 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 18 21:21:28 volumio go-librespot[7697]: time="2026-02-18T21: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 21:21:28 volumio go-librespot[7697]: time="2026-02-18T21:21:28+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 21:21:28 volumio go-librespot[7697]: time="2026-02-18T21:21:28+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 21:21:29 volumio go-librespot[7697]: time="2026-02-18T21:21:29+07:00" level=info msg="zeroconf server listening on port 39057" Feb 18 21:21:29 volumio go-librespot[7697]: time="2026-02-18T21:21:29+07:00" level=debug msg="obtained new client token: AABWo4+Us9YZbBt+XikzTq5SDU8tM464bkvBAghMGdG60eF3WoGzqgWJ22oDjjGPSlAC4YqQih1s8naqDupEKvLHYvQKiepZElRYH4d/qQnXRx9253FyEXCnWWIQ8L6O0jL1u2CmcmhCsX7PBvqw9CFAVl2tAyZdll5TfAsBwfmsUIRbBDIo2YLIfFVGh2lrcMMdJuqwXIX4mPCY74FnbkW27p9NkXzZsDAHuhGg3x4Gup/DBdZLyXs=" Feb 18 21:21:29 volumio go-librespot[7697]: time="2026-02-18T21:21:29+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 21:21:29 volumio go-librespot[7697]: time="2026-02-18T21:21:29+07:00" level=debug msg="completed keyexchange" Feb 18 21:21:29 volumio go-librespot[7697]: time="2026-02-18T21:21:29+07:00" level=debug msg="completed challenge" Feb 18 21:21:29 volumio go-librespot[7697]: time="2026-02-18T21: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 21:21:29 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 21:21:29 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 21:21:32 volumio volumio[7719]: info: ------------------------------------------- Feb 18 21:21:32 volumio volumio[7719]: info: ----- Volumio3 ---- Feb 18 21:21:32 volumio volumio[7719]: info: ------------------------------------------- Feb 18 21:21:32 volumio volumio[7719]: info: ----- System startup ---- Feb 18 21:21:32 volumio volumio[7719]: info: ------------------------------------------- Feb 18 21:21:32 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 26. Feb 18 21:21:32 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 21:21:32 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 21:21:32 volumio go-librespot[7744]: go-librespot daemon starting... Feb 18 21:21:32 volumio go-librespot[7745]: time="2026-02-18T21:21:32+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 21:21:32 volumio go-librespot[7745]: time="2026-02-18T21:21:32+07:00" level=debug msg="app state loaded" Feb 18 21:21:32 volumio go-librespot[7745]: time="2026-02-18T21:21:32+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 21:21:33 volumio go-librespot[7745]: time="2026-02-18T21: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-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 21:21:33 volumio go-librespot[7745]: time="2026-02-18T21:21:33+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 21:21:33 volumio go-librespot[7745]: time="2026-02-18T21:21:33+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 21:21:33 volumio volumio-remote-updater[25144]: [2026-02-18 21:21:33] [connect] Successful connection Feb 18 21:21:33 volumio go-librespot[7745]: time="2026-02-18T21:21:33+07:00" level=info msg="zeroconf server listening on port 33399" Feb 18 21:21:33 volumio go-librespot[7745]: time="2026-02-18T21:21:33+07:00" level=debug msg="obtained new client token: AAC5NPoWaCmKgSYJ/XVbkNAzPEzExU7WMCuOQJa1M7ZW/tO6fC8EUyVVFXV173bYGqXuqQ2c+AIIuwBGUaPq4rSw2HN1CumajKDYR4xymSET0oPRQl7MbLO/dAH7Eeg6Dx3Ihx46HdbaiD1M/Mxu2EvzEJGAgOeJ/agu2zeR5XEzSoJ/6iCHMCw66hntSzHuh+ztps3GSEOzV+5UN4++muY3wCcESiXcMMLRKb2Hfy0a6/Wl2xUHDvirVg==" Feb 18 21:21:33 volumio volumio[7719]: info: MYVOLUMIO Environment detected Feb 18 21:21:33 volumio go-librespot[7745]: time="2026-02-18T21:21:33+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 21:21:33 volumio volumio[7719]: info: Plugin folders cleanup Feb 18 21:21:33 volumio volumio[7719]: info: Scanning into folder /volumio/app/plugins/ Feb 18 21:21:33 volumio volumio[7719]: info: Scanning category audio_interface Feb 18 21:21:33 volumio volumio[7719]: info: Scanning category miscellanea Feb 18 21:21:33 volumio volumio[7719]: info: Scanning category music_service Feb 18 21:21:33 volumio go-librespot[7745]: time="2026-02-18T21:21:33+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Feb 18 21:21:33 volumio volumio[7719]: info: Scanning category plugins.json Feb 18 21:21:33 volumio volumio[7719]: info: Scanning category system_controller Feb 18 21:21:33 volumio volumio[7719]: info: Scanning category user_interface Feb 18 21:21:33 volumio volumio[7719]: info: Scanning into folder /data/plugins/ Feb 18 21:21:33 volumio volumio[7719]: info: Scanning category music_service Feb 18 21:21:33 volumio volumio[7719]: info: Plugin folders cleanup completed Feb 18 21:21:33 volumio volumio[7719]: info: ------------------------------------------- Feb 18 21:21:33 volumio volumio[7719]: info: ----- Core plugins startup ---- Feb 18 21:21:33 volumio volumio[7719]: info: ------------------------------------------- Feb 18 21:21:33 volumio volumio[7719]: info: Loading plugins from folder /volumio/app/plugins/ Feb 18 21:21:33 volumio volumio[7719]: info: Adding plugin upnp to MyMusic Plugins Feb 18 21:21:33 volumio volumio[7719]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 18 21:21:33 volumio volumio[7719]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 18 21:21:33 volumio volumio[7719]: info: Loading plugins from folder /data/plugins/ Feb 18 21:21:33 volumio volumio[7719]: info: Loading plugin "system"... Feb 18 21:21:34 volumio go-librespot[7745]: time="2026-02-18T21:21:34+07:00" level=debug msg="completed keyexchange" Feb 18 21:21:34 volumio go-librespot[7745]: time="2026-02-18T21:21:34+07:00" level=debug msg="completed challenge" Feb 18 21:21:34 volumio volumio[7719]: info: Loading plugin "appearance"... Feb 18 21:21:34 volumio go-librespot[7745]: time="2026-02-18T21:21:34+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 21:21:34 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 21:21:34 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 21:21:35 volumio volumio[7719]: info: Loading plugin "network"... Feb 18 21:21:35 volumio volumio[7719]: info: Refreshing Cached IP Addresses Feb 18 21:21:35 volumio sudo[7761]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 18 21:21:35 volumio sudo[7761]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 21:21:36 volumio sudo[7761]: pam_unix(sudo:session): session closed for user root Feb 18 21:21:36 volumio sudo[7763]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 18 21:21:36 volumio sudo[7763]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 21:21:36 volumio volumio[7719]: info: Loading plugin "services"... Feb 18 21:21:36 volumio sudo[7763]: pam_unix(sudo:session): session closed for user root Feb 18 21:21:36 volumio volumio[7719]: info: Loading plugin "alsa_controller"... Feb 18 21:21:36 volumio sudo[7771]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 18 21:21:36 volumio sudo[7771]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 21:21:36 volumio volumio[7719]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 18 21:21:36 volumio volumio[7719]: info: Loading plugin "wizard"... Feb 18 21:21:36 volumio volumio[7719]: info: Loading plugin "networkfs"... Feb 18 21:21:36 volumio volumio[7719]: info: Starting Udev Watcher for removable devices Feb 18 21:21:36 volumio volumio[7719]: info: Ignoring mount for partition: boot Feb 18 21:21:36 volumio volumio[7719]: info: Ignoring mount for partition: volumio Feb 18 21:21:36 volumio volumio[7719]: info: Ignoring mount for partition: volumio_data Feb 18 21:21:36 volumio volumio[7719]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 18 21:21:36 volumio volumio[7719]: info: Loading plugin "volumio_command_line_client"... Feb 18 21:21:36 volumio volumio[7719]: info: Loading plugin "upnp"... Feb 18 21:21:36 volumio volumio[7719]: info: [1771424496347] Starting Upmpd Daemon Feb 18 21:21:36 volumio volumio[7719]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 18 21:21:36 volumio volumio[7719]: info: Loading plugin "my_music"... Feb 18 21:21:36 volumio volumio[7719]: info: Loading plugin "mpd"... Feb 18 21:21:37 volumio volumio[7719]: info: Loading plugin "upnp_browser"... Feb 18 21:21:37 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 27. Feb 18 21:21:37 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 21:21:37 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 21:21:37 volumio go-librespot[7794]: go-librespot daemon starting... Feb 18 21:21:37 volumio go-librespot[7795]: time="2026-02-18T21:21:37+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 21:21:37 volumio go-librespot[7795]: time="2026-02-18T21:21:37+07:00" level=debug msg="app state loaded" Feb 18 21:21:37 volumio go-librespot[7795]: time="2026-02-18T21:21:37+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 21:21:37 volumio go-librespot[7795]: time="2026-02-18T21:21:37+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 21:21:37 volumio go-librespot[7795]: time="2026-02-18T21:21:37+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 18 21:21:37 volumio go-librespot[7795]: time="2026-02-18T21:21:37+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 18 21:21:37 volumio go-librespot[7795]: time="2026-02-18T21:21:37+07:00" level=info msg="zeroconf server listening on port 43583" Feb 18 21:21:38 volumio go-librespot[7795]: time="2026-02-18T21:21:38+07:00" level=debug msg="obtained new client token: AABo7gP7ZSvxoXk4PJcppgbLAWKQgQauetuuHwnQcZQCh8Pir2aj0Eox7Ic/Wq/QaxQcs5UU5V+hYaBeUw2UMSSuKdautunbCRahl0ItcNhHrIhl+OxLImLUcuKcXrngkN8Viu5PMpSwaItyWHq+MMLuVeY8JoXvsh34zO2iWOUyj3FboRCf9eOXeXJImt9huslzI2+mqqAliyCAZm3a+iPLjPecJO7wkQgI4pMdBPZRGjl6y3oiq3E=" Feb 18 21:21:38 volumio go-librespot[7795]: time="2026-02-18T21:21:38+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 21:21:38 volumio go-librespot[7795]: time="2026-02-18T21:21:38+07:00" level=debug msg="completed keyexchange" Feb 18 21:21:38 volumio go-librespot[7795]: time="2026-02-18T21:21:38+07:00" level=debug msg="completed challenge" Feb 18 21:21:38 volumio go-librespot[7795]: time="2026-02-18T21:21:38+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 18 21:21:38 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 21:21:38 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 21:21:38 volumio sudo[7771]: pam_unix(sudo:session): session closed for user root Feb 18 21:21:39 volumio volumio[7719]: info: Starting UPNP Browser Feb 18 21:21:39 volumio volumio[7719]: info: Loading plugin "alarm-clock"... Feb 18 21:21:40 volumio volumio[7719]: info: Loading plugin "airplay_emulation"... Feb 18 21:21:40 volumio volumio[7719]: info: Starting Shairport Sync Feb 18 21:21:40 volumio volumio[7719]: info: Loading plugin "last_100"... Feb 18 21:21:40 volumio volumio[7719]: info: Loading plugin "webradio"... Feb 18 21:21:40 volumio volumio[7719]: info: Loading plugin "i2s_dacs"... Feb 18 21:21:40 volumio volumio[7719]: info: Loading plugin "volumiodiscovery"... Feb 18 21:21:40 volumio volumio[7719]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 18 21:21:40 volumio volumio[7719]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 18 21:21:40 volumio volumio[7719]: *** WARNING *** For more information see Feb 18 21:21:40 volumio volumio[7719]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 18 21:21:40 volumio volumio[7719]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 18 21:21:40 volumio volumio[7719]: *** WARNING *** For more information see Feb 18 21:21:40 volumio node[7719]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 18 21:21:40 volumio node[7719]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 18 21:21:40 volumio node[7719]: *** WARNING *** For more information see Feb 18 21:21:40 volumio node[7719]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 18 21:21:40 volumio node[7719]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 18 21:21:40 volumio node[7719]: *** WARNING *** For more information see Feb 18 21:21:40 volumio volumio[7719]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 18 21:21:40 volumio volumio[7719]: info: Discovery: Started advertising with name: Volumio Feb 18 21:21:40 volumio volumio[7719]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 18 21:21:40 volumio volumio[7719]: info: Loading plugin "spop"... Feb 18 21:21:41 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 28. Feb 18 21:21:41 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 21:21:41 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 21:21:41 volumio go-librespot[7804]: go-librespot daemon starting... Feb 18 21:21:41 volumio go-librespot[7805]: time="2026-02-18T21:21:41+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 21:21:41 volumio go-librespot[7805]: time="2026-02-18T21:21:41+07:00" level=debug msg="app state loaded" Feb 18 21:21:41 volumio go-librespot[7805]: time="2026-02-18T21:21:41+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 21:21:42 volumio go-librespot[7805]: time="2026-02-18T21:21:42+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 21:21:42 volumio go-librespot[7805]: time="2026-02-18T21:21:42+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 21:21:42 volumio go-librespot[7805]: time="2026-02-18T21:21:42+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 21:21:42 volumio go-librespot[7805]: time="2026-02-18T21:21:42+07:00" level=info msg="zeroconf server listening on port 45497" Feb 18 21:21:42 volumio go-librespot[7805]: time="2026-02-18T21:21:42+07:00" level=debug msg="obtained new client token: AAB9Mw5uHkxWhcttq8Qmc9P5FsYaWxvhiZmHH2Vd7jctAMNdszwSpi26xbBOC9qHBLV7iLQqr/z9dbqI7MgKFgRQCixezKHfIShFzCVIxwmGxS7XOGzmLu3Rfc6F47+v6EumsUfY+LCHdJfwANWR1nuSURtNZq3wzRi7u4LaBFHLHJgDS0wBexmdAO2tHlOvHhlaLNNFgRHMNnVPcfeOkxKraqMQaxP8i4Hmt0ECt/6xNpT+sjvefCdG6g==" Feb 18 21:21:42 volumio volumio[7719]: info: Loading plugin "ytcr"... Feb 18 21:21:42 volumio go-librespot[7805]: time="2026-02-18T21:21:42+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 21:21:42 volumio go-librespot[7805]: time="2026-02-18T21:21:42+07:00" level=debug msg="completed keyexchange" Feb 18 21:21:42 volumio go-librespot[7805]: time="2026-02-18T21:21:42+07:00" level=debug msg="completed challenge" Feb 18 21:21:42 volumio go-librespot[7805]: time="2026-02-18T21:21:42+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 18 21:21:42 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 21:21:42 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 21:21:45 volumio volumio[7719]: info: Loading plugin "ytmusic"... Feb 18 21:21:46 volumio volumio-remote-updater[25144]: [2026-02-18 21:21:46] [connect] Successful connection Feb 18 21:21:46 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 29. Feb 18 21:21:46 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 21:21:46 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 21:21:46 volumio go-librespot[7814]: go-librespot daemon starting... Feb 18 21:21:46 volumio go-librespot[7823]: time="2026-02-18T21:21:46+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 21:21:46 volumio go-librespot[7823]: time="2026-02-18T21:21:46+07:00" level=debug msg="app state loaded" Feb 18 21:21:46 volumio go-librespot[7823]: time="2026-02-18T21:21:46+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 21:21:46 volumio volumio[7719]: info: Loading plugin "outputs"... Feb 18 21:21:46 volumio volumio[7719]: info: Loading plugin "albumart"... Feb 18 21:21:46 volumio volumio[7719]: info: Plugin example_plugin is not enabled Feb 18 21:21:46 volumio volumio[7719]: info: Loading plugin "inputs"... Feb 18 21:21:46 volumio volumio[7719]: info: Loading plugin "updater_comm"... Feb 18 21:21:46 volumio volumio[7719]: info: Plugin mpdemulation is not enabled Feb 18 21:21:46 volumio volumio[7719]: info: Loading plugin "rest_api"... Feb 18 21:21:46 volumio volumio[7719]: info: Loading plugin "websocket"... Feb 18 21:21:46 volumio volumio[7719]: info: Starting Socket.io Server version 1.7.4 Feb 18 21:21:46 volumio volumio[7719]: info: Loading plugin "RoonBridge"... Feb 18 21:21:46 volumio go-librespot[7823]: time="2026-02-18T21:21:46+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 21:21:46 volumio go-librespot[7823]: time="2026-02-18T21:21:46+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 18 21:21:46 volumio go-librespot[7823]: time="2026-02-18T21:21:46+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 18 21:21:46 volumio go-librespot[7823]: time="2026-02-18T21:21:46+07:00" level=info msg="zeroconf server listening on port 36073" Feb 18 21:21:47 volumio go-librespot[7823]: time="2026-02-18T21:21:47+07:00" level=debug msg="obtained new client token: AABjbPofzcI+RK55zuScyadbxYHDXBhtTkfphW+YfQnsxj3SlzORVj1Mtfkgg7PXd40DvQH8zBeeLCB5TgaoYJbEeVorPKiWHfeRKPEGxHMT6elVauspp/eJht6k+F6Nf91wo40uOyWiHOWJYRdK3BzRT02UVtJImZkDDcz45zskJ/g1ka0TBuGNMNX7hLDabzI9v995JSJJJ/37B11+lTnPVH+HDSfzSWlSMSh2qP+oZBfdG/rKgQQ=" Feb 18 21:21:47 volumio go-librespot[7823]: time="2026-02-18T21:21:47+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 21:21:47 volumio volumio[7719]: info: Applying required configuration parameters for plugin RoonBridge Feb 18 21:21:47 volumio volumio[7719]: info: Loading i18n strings for locale en Feb 18 21:21:47 volumio volumio[7719]: Updating browse sources language Feb 18 21:21:47 volumio volumio[7719]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 21:21:47 volumio go-librespot[7823]: time="2026-02-18T21:21:47+07:00" level=debug msg="completed keyexchange" Feb 18 21:21:47 volumio go-librespot[7823]: time="2026-02-18T21:21:47+07:00" level=debug msg="completed challenge" Feb 18 21:21:47 volumio go-librespot[7823]: time="2026-02-18T21:21:47+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 18 21:21:47 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 21:21:47 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 21:21:47 volumio volumio[7719]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 18 21:21:47 volumio volumio[7835]: Forking 3 albumart workers Feb 18 21:21:47 volumio volumio[7719]: info: CoreCommandRouter::initPlayerControls Feb 18 21:21:47 volumio volumio[7719]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 21:21:47 volumio volumio[7719]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 21:21:47 volumio volumio[7719]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 21:21:47 volumio volumio[7719]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 21:21:47 volumio volumio[7719]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 21:21:47 volumio volumio[7719]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 21:21:47 volumio volumio[7719]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 21:21:47 volumio volumio[7719]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 21:21:47 volumio volumio[7719]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 18 21:21:47 volumio volumio[7719]: Express server listening on port 3000 Feb 18 21:21:47 volumio volumio[7719]: [Metrics] WebUI: 16s 193.81ms Feb 18 21:21:47 volumio volumio[7719]: info: CoreStateMachine::resetVolumioState Feb 18 21:21:47 volumio volumio[7719]: info: CoreStateMachine::getcurrentVolume Feb 18 21:21:47 volumio volumio[7719]: info: CoreCommandRouter::volumioRetrievevolume Feb 18 21:21:47 volumio sudo[7874]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 18 21:21:47 volumio sudo[7874]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 21:21:47 volumio sudo[7874]: pam_unix(sudo:session): session closed for user root Feb 18 21:21:47 volumio sudo[7881]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 18 21:21:47 volumio sudo[7881]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 21:21:47 volumio sudo[7881]: pam_unix(sudo:session): session closed for user root Feb 18 21:21:47 volumio volumio[7719]: info: Volumio Network Manager: Network status updated: 1 Feb 18 21:21:48 volumio volumio[7719]: info: VolumeController:: Volume=100 Mute =false Feb 18 21:21:48 volumio volumio[7719]: info: CoreStateMachine::pushState Feb 18 21:21:48 volumio volumio[7719]: info: CorePlayQueue::getTrack 0 Feb 18 21:21:48 volumio volumio[7719]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 18 21:21:48 volumio volumio[7719]: info: CoreCommandRouter::volumioPushState Feb 18 21:21:48 volumio volumio[7719]: info: CoreStateMachine::updateTrackBlock Feb 18 21:21:48 volumio volumio[7719]: info: CorePlayQueue::getTrackBlock Feb 18 21:21:48 volumio volumio[7719]: info: CoreCommandRouter::volumioRetrievevolume Feb 18 21:21:48 volumio volumio-remote-updater[25144]: [2026-02-18 21:21:48] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1771424506 101 Feb 18 21:21:48 volumio volumio[7719]: 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 21:21:48 volumio volumio[7719]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 21:21:48 volumio volumio[7719]: info: Reloading queue from file Feb 18 21:21:48 volumio volumio[7719]: info: CoreStateMachine::setRepeat null single undefined Feb 18 21:21:48 volumio volumio[7719]: info: CoreStateMachine::pushState Feb 18 21:21:48 volumio volumio[7719]: info: CorePlayQueue::getTrack 0 Feb 18 21:21:48 volumio volumio[7719]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 18 21:21:48 volumio volumio[7719]: info: CoreCommandRouter::volumioPushState Feb 18 21:21:48 volumio volumio[7719]: info: CoreStateMachine::setRandom null Feb 18 21:21:48 volumio volumio[7719]: info: CoreStateMachine::pushState Feb 18 21:21:48 volumio volumio[7719]: info: CorePlayQueue::getTrack 0 Feb 18 21:21:48 volumio volumio[7719]: info: CoreCommandRouter::volumioPushState Feb 18 21:21:48 volumio volumio[7719]: info: Setting Device type: Raspberry PI Feb 18 21:21:48 volumio volumio[7719]: info: Completed loading Core Plugins Feb 18 21:21:48 volumio volumio[7719]: info: Preparing to generate the ALSA configuration file Feb 18 21:21:48 volumio volumio[7719]: info: VolumeController:: Volume=100 Mute =false Feb 18 21:21:48 volumio volumio[7719]: info: CoreStateMachine::pushState Feb 18 21:21:48 volumio volumio[7719]: info: CorePlayQueue::getTrack 0 Feb 18 21:21:48 volumio volumio[7719]: info: CoreCommandRouter::volumioPushState Feb 18 21:21:48 volumio volumio[7719]: info: Asound.conf file unchanged, so no further update is needed Feb 18 21:21:48 volumio volumio[7719]: info: Output device has changed, restarting MPD Feb 18 21:21:48 volumio sudo[7897]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 18 21:21:48 volumio sudo[7897]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 21:21:48 volumio volumio[7719]: info: Output device has changed, restarting Shairport Sync Feb 18 21:21:48 volumio volumio[7719]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 21:21:48 volumio volumio[7719]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 21:21:48 volumio sudo[7899]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 18 21:21:48 volumio volumio[7719]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 18 21:21:48 volumio sudo[7899]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 21:21:48 volumio volumio[7719]: info: ___________ START PLUGINS ___________ Feb 18 21:21:48 volumio sudo[7899]: pam_unix(sudo:session): session closed for user root Feb 18 21:21:48 volumio sudo[7897]: pam_unix(sudo:session): session closed for user root Feb 18 21:21:48 volumio volumio[7719]: info: ControllerMpd::onStart: Initializing MPD Feb 18 21:21:48 volumio volumio[7719]: info: Creating MPD Configuration file Feb 18 21:21:48 volumio sudo[7902]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 18 21:21:48 volumio sudo[7902]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 21:21:48 volumio sudo[7910]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 18 21:21:48 volumio sudo[7910]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 21:21:48 volumio volumio[7719]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 18 21:21:48 volumio volumio[7719]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 21:21:48 volumio volumio[7719]: info: [1771424508932] CoreMusicLibrary::Adding element Media Servers Feb 18 21:21:48 volumio volumio[7719]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 21:21:48 volumio volumio[7719]: info: UPNP Browser: Client initialized successfully Feb 18 21:21:48 volumio sudo[7910]: pam_unix(sudo:session): session closed for user root Feb 18 21:21:48 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 18 21:21:49 volumio volumio[7719]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 21:21:49 volumio volumio[7719]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 21:21:49 volumio sudo[7913]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 18 21:21:49 volumio sudo[7913]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 21:21:49 volumio volumio[7719]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 18 21:21:49 volumio volumio[7719]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 21:21:49 volumio volumio[7719]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 21:21:49 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 18 21:21:49 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 18 21:21:49 volumio systemd[1]: mpd.service: Consumed 7.443s CPU time. Feb 18 21:21:49 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 18 21:21:49 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 18 21:21:49 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 18 21:21:49 volumio volumio[7719]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 18 21:21:49 volumio volumio[7719]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 21:21:49 volumio volumio[7719]: info: [1771424509219] CoreMusicLibrary::Adding element Last_100 Feb 18 21:21:49 volumio volumio[7719]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 21:21:49 volumio volumio[7719]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 21:21:49 volumio volumio[7719]: info: [1771424509229] CoreMusicLibrary::Adding element Webradio Feb 18 21:21:49 volumio volumio[7719]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 21:21:49 volumio volumio[7719]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 18 21:21:49 volumio volumio[7719]: info: Initializing BBC Radios Feb 18 21:21:49 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 18 21:21:49 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 18 21:21:49 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 18 21:21:49 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 18 21:21:49 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 18 21:21:49 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 18 21:21:49 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 18 21:21:49 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 18 21:21:49 volumio volumio[7719]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 18 21:21:49 volumio volumio[7719]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 21:21:49 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 18 21:21:49 volumio volumio[7719]: info: Creating Spotify config file Feb 18 21:21:49 volumio volumio[7719]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 21:21:49 volumio sudo[7939]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 18 21:21:49 volumio sudo[7939]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 18 21:21:49 volumio sudo[7939]: pam_unix(sudo:session): session closed for user root Feb 18 21:21:50 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 30. Feb 18 21:21:50 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 21:21:50 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 21:21:50 volumio go-librespot[7942]: go-librespot daemon starting... Feb 18 21:21:50 volumio go-librespot[7943]: time="2026-02-18T21:21:50+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 21:21:50 volumio volumio[7719]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 21:21:50 volumio volumio[7719]: info: [1771424510772] CoreMusicLibrary::Adding element YouTube Music Feb 18 21:21:50 volumio volumio[7719]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 21:21:50 volumio volumio[7719]: Cannot find translation for source YouTube Music Feb 18 21:21:50 volumio volumio[7848]: Starting albumart workers Feb 18 21:21:50 volumio volumio[7846]: Starting albumart workers Feb 18 21:21:50 volumio volumio[7719]: info: Volumio Calling Home Feb 18 21:21:50 volumio sudo[7950]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Feb 18 21:21:50 volumio sudo[7950]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 21:21:51 volumio sudo[7950]: pam_unix(sudo:session): session closed for user root Feb 18 21:21:51 volumio volumio[7847]: Starting albumart workers Feb 18 21:21:51 volumio go-librespot[7943]: time="2026-02-18T21:21:51+07:00" level=info msg="zeroconf server listening on port 40813" Feb 18 21:21:51 volumio volumio[7719]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Feb 18 21:21:51 volumio volumio[7719]: info: Discovery: Found device Volumio Feb 18 21:21:51 volumio volumio[7719]: info: CoreCommandRouter::volumioGetState Feb 18 21:21:51 volumio volumio[7719]: info: CorePlayQueue::getTrack 0 Feb 18 21:21:51 volumio volumio[7719]: info: MPD Permissions set Feb 18 21:21:51 volumio volumio[7719]: info: MPD Permissions set Feb 18 21:21:51 volumio volumio[7719]: info: Upmpdcli Daemon Started Feb 18 21:21:52 volumio volumio[7719]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Feb 18 21:21:52 volumio volumio[7719]: info: Discovery: Found device Volumio Feb 18 21:21:52 volumio volumio[7719]: info: CoreCommandRouter::volumioGetState Feb 18 21:21:52 volumio volumio[7719]: info: CorePlayQueue::getTrack 0 Feb 18 21:21:52 volumio volumio[7719]: info: Volumio called home Feb 18 21:21:52 volumio volumio[7719]: info: Spotify config file written Feb 18 21:21:52 volumio sudo[7957]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 18 21:21:52 volumio sudo[7957]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 21:21:52 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Feb 18 21:21:52 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Feb 18 21:21:52 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 21:21:52 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 21:21:52 volumio go-librespot[7959]: go-librespot daemon starting... Feb 18 21:21:52 volumio sudo[7957]: pam_unix(sudo:session): session closed for user root Feb 18 21:21:52 volumio go-librespot[7960]: time="2026-02-18T21:21:52+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 21:21:52 volumio go-librespot[7960]: time="2026-02-18T21:21:52+07:00" level=debug msg="app state loaded" Feb 18 21:21:52 volumio go-librespot[7960]: time="2026-02-18T21:21:52+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 21:21:52 volumio volumio[7719]: 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 21:21:52 volumio volumio[7719]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 21:21:52 volumio volumio[7719]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 21:21:52 volumio volumio[7719]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 21:21:52 volumio volumio[7719]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 21:21:52 volumio volumio[7719]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 21:21:52 volumio volumio[7719]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 21:21:52 volumio volumio[7719]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 21:21:52 volumio volumio[7719]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 21:21:52 volumio volumio[7719]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 21:21:52 volumio volumio[7719]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 21:21:52 volumio volumio[7719]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 21:21:52 volumio volumio[7719]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 21:21:52 volumio volumio[7719]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 21:21:52 volumio volumio[7719]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 21:21:52 volumio volumio[7719]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 21:21:52 volumio volumio[7719]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 21:21:52 volumio volumio[7719]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 21:21:52 volumio volumio[7719]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 21:21:53 volumio volumio[7719]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 21:21:53 volumio volumio[7719]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 21:21:53 volumio volumio[7719]: info: No need to fix Spotify hosts Feb 18 21:21:53 volumio go-librespot[7960]: time="2026-02-18T21: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-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 18 21:21:53 volumio go-librespot[7960]: time="2026-02-18T21:21:53+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 21:21:53 volumio go-librespot[7960]: time="2026-02-18T21:21:53+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 21:21:53 volumio go-librespot[7960]: time="2026-02-18T21:21:53+07:00" level=info msg="zeroconf server listening on port 43491" Feb 18 21:21:53 volumio go-librespot[7960]: time="2026-02-18T21:21:53+07:00" level=debug msg="obtained new client token: AAByxL3ZkXb/EAh44vKLLYPPwCKUF4quoQ5Zn28XH0q4Fq13X6atImX6y1TLdHInrs8zepqom/rKBxKmuYtcrThw59e1FwbsS5TrsVZ61Iv/K/FMjvsbSHc+kckyTAIT7vlqmWIxurSuavRgc0j9ZUfhEL6tsoBq+r4M3ly1I/++5DWyVasbxt9TZGcBdLTKyIeRGTp9TO4w2bPri4rJSGen9ACiaLsIE+F7G9qjONCwpNfK7Gdz4pHvbQ==" Feb 18 21:21:53 volumio go-librespot[7960]: time="2026-02-18T21:21:53+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 21:21:53 volumio volumio[7719]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 18 21:21:53 volumio volumio[7719]: SPOTIFY: BQAMtkFfwc6Kh8NPjPnh5A_qV25yq85felSUvesDrHSvmPr02YQgyj3vfs2yntM6fYN8BntKPYWLyqT0-g4IjfhkooTTGgUwJqbyqwctt2M5F5ED6pDYgNDkEpMYQ0-e-8I0IRcxWrHer7mA55CWJWqEdFs1lqpO_Om_Wit-lgmsEj0yuRZd1d-Nso3sDq-7yOXwryOKma3GDRBZ7Vy7GwYvMaUj6K-S7SIFaALZgt50KsRET80xS3sxMNRJPGwL4kTARZX6ZFo5ZXP6QrvaTmwNT6sgndHchpzce3q-zOqD7qizUF0ca0C2 Feb 18 21:21:53 volumio volumio[7719]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 18 21:21:53 volumio volumio[7719]: info: New Spotify access token = BQAMtkFfwc6Kh8NPjPnh5A_qV25yq85felSUvesDrHSvmPr02YQgyj3vfs2yntM6fYN8BntKPYWLyqT0-g4IjfhkooTTGgUwJqbyqwctt2M5F5ED6pDYgNDkEpMYQ0-e-8I0IRcxWrHer7mA55CWJWqEdFs1lqpO_Om_Wit-lgmsEj0yuRZd1d-Nso3sDq-7yOXwryOKma3GDRBZ7Vy7GwYvMaUj6K-S7SIFaALZgt50KsRET80xS3sxMNRJPGwL4kTARZX6ZFo5ZXP6QrvaTmwNT6sgndHchpzce3q-zOqD7qizUF0ca0C2 Feb 18 21:21:53 volumio go-librespot[7960]: time="2026-02-18T21:21:53+07:00" level=debug msg="completed keyexchange" Feb 18 21:21:53 volumio go-librespot[7960]: time="2026-02-18T21:21:53+07:00" level=debug msg="completed challenge" Feb 18 21:21:53 volumio volumio[7719]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 18 21:21:53 volumio volumio[7719]: info: Starting Shairport Sync Feb 18 21:21:53 volumio volumio[7719]: info: Starting Shairport Sync Feb 18 21:21:53 volumio go-librespot[7960]: time="2026-02-18T21:21: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 21:21:53 volumio volumio[7719]: info: Starting Shairport Sync Feb 18 21:21:53 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 21:21:53 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 21:21:54 volumio sudo[7997]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 18 21:21:54 volumio sudo[7997]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 21:21:54 volumio sudo[8001]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 18 21:21:54 volumio sudo[8001]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 21:21:54 volumio sudo[7999]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 18 21:21:54 volumio sudo[7999]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 21:21:54 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 18 21:21:54 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 18 21:21:54 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 18 21:21:54 volumio systemd[1]: shairport-sync.service: Consumed 2.306s CPU time. Feb 18 21:21:54 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 18 21:21:54 volumio volumio[7719]: info: CoreCommandRouter::volumioGetState Feb 18 21:21:54 volumio volumio[7719]: info: CorePlayQueue::getTrack 0 Feb 18 21:21:54 volumio sudo[8001]: pam_unix(sudo:session): session closed for user root Feb 18 21:21:54 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 18 21:21:54 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 18 21:21:54 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 18 21:21:54 volumio volumio[7719]: info: Shairport-Sync Started Feb 18 21:21:54 volumio volumio[7719]: Error adding Membership: Error: addMembership EINVAL Feb 18 21:21:54 volumio volumio[7719]: 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 21:21:54 volumio volumio[7719]: info: Spotify Successfully logged in Feb 18 21:21:54 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 18 21:21:54 volumio volumio[7719]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 21:21:54 volumio volumio[7719]: info: [1771424514613] CoreMusicLibrary::Adding element Spotify Feb 18 21:21:54 volumio volumio[7719]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 21:21:54 volumio sudo[7999]: pam_unix(sudo:session): session closed for user root Feb 18 21:21:54 volumio volumio[7719]: Cannot find translation for source YouTube Music Feb 18 21:21:54 volumio volumio[7719]: Cannot find translation for source Spotify Feb 18 21:21:54 volumio sudo[7997]: pam_unix(sudo:session): session closed for user root Feb 18 21:21:54 volumio volumio[7719]: info: Shairport-Sync Started Feb 18 21:21:54 volumio volumio[7719]: info: Shairport-Sync Started Feb 18 21:21:55 volumio volumio[7719]: info: [yt-cast-receiver] DIAL server listening on port 8098 Feb 18 21:21:55 volumio volumio[7719]: info: CoreCommandRouter::volumioRetrievevolume Feb 18 21:21:55 volumio volumio[7719]: info: VolumeController:: Volume=100 Mute =false Feb 18 21:21:55 volumio volumio[7719]: info: CoreCommandRouter::volumioGetState Feb 18 21:21:55 volumio volumio[7719]: info: CorePlayQueue::getTrack 0 Feb 18 21:21:55 volumio volumio[7719]: info: CoreStateMachine::pushState Feb 18 21:21:55 volumio volumio[7719]: info: CorePlayQueue::getTrack 0 Feb 18 21:21:55 volumio volumio[7719]: info: CoreCommandRouter::volumioPushState Feb 18 21:21:56 volumio volumio[7719]: info: go-librespot daemon successfully initialized Feb 18 21:21:56 volumio mpd[7941]: 2026-02-18T21:21:56 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 18 21:21:56 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Feb 18 21:21:56 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 18 21:21:56 volumio sudo[7902]: pam_unix(sudo:session): session closed for user root Feb 18 21:21:56 volumio sudo[7913]: pam_unix(sudo:session): session closed for user root Feb 18 21:21:57 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 21:21:57 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 21:21:57 volumio go-librespot[8043]: go-librespot daemon starting... Feb 18 21:21:57 volumio go-librespot[8044]: time="2026-02-18T21:21:57+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 21:21:57 volumio go-librespot[8044]: time="2026-02-18T21:21:57+07:00" level=debug msg="app state loaded" Feb 18 21:21:57 volumio go-librespot[8044]: time="2026-02-18T21:21:57+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 21:21:57 volumio volumio[7719]: error: MPD error: The expression evaluated to a falsy value: Feb 18 21:21:57 volumio volumio[7719]: assert.ok(self.idling) Feb 18 21:21:57 volumio volumio[7719]: error: The expression evaluated to a falsy value: Feb 18 21:21:57 volumio volumio[7719]: assert.ok(self.idling) Feb 18 21:21:57 volumio volumio[7719]: info: MPD running with PID7941 Feb 18 21:21:57 volumio volumio[7719]: ,establishing connection Feb 18 21:21:57 volumio volumio[7719]: error: updateQueue error: null Feb 18 21:21:57 volumio volumio[7719]: info: Completed starting Core Plugins Feb 18 21:21:57 volumio volumio[7719]: info: ------------------------------------------- Feb 18 21:21:57 volumio volumio[7719]: info: ----- MyVolumio plugins startup ---- Feb 18 21:21:57 volumio volumio[7719]: info: ------------------------------------------- Feb 18 21:21:57 volumio volumio[7719]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 18 21:21:57 volumio volumio[7719]: error: updateQueue error: null Feb 18 21:21:57 volumio go-librespot[8044]: time="2026-02-18T21:21: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 21:21:57 volumio go-librespot[8044]: time="2026-02-18T21:21:57+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 21:21:57 volumio go-librespot[8044]: time="2026-02-18T21:21:57+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 21:21:57 volumio go-librespot[8044]: time="2026-02-18T21:21:57+07:00" level=info msg="zeroconf server listening on port 37929" Feb 18 21:21:57 volumio go-librespot[8044]: time="2026-02-18T21:21:57+07:00" level=debug msg="obtained new client token: AADJnMMvoh3rn7YvL5QBEpuKDRP5/Sf9TmeoUhNEe1shMaMaaTULYb709i41HE0wDbSUtdzIYG6ZpMFjB6szxpWRtGO53FBsUioUvCZ+CgwRb1BbVi0cUoEm0KD3aSYYiOS/b7Lb7y5gBOYxDNRBOlDPsCa5P5zRf77fP+8j7yhg8QuPNNcEzZLW580fslSHzVUk1x5Jp7If4XdopDTubF0t+g9ljHLLPI2qWtJXqtdJXXtIwi2qjrK5qA==" Feb 18 21:21:58 volumio go-librespot[8044]: time="2026-02-18T21:21:58+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 21:21:58 volumio go-librespot[8044]: time="2026-02-18T21:21:58+07:00" level=debug msg="completed keyexchange" Feb 18 21:21:58 volumio go-librespot[8044]: time="2026-02-18T21:21:58+07:00" level=debug msg="completed challenge" Feb 18 21:21:58 volumio go-librespot[8044]: time="2026-02-18T21:21: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 21:21:58 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 21:21:58 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 21:21:59 volumio volumio[7719]: info: Initializing connection to go-librespot Websocket Feb 18 21:21:59 volumio volumio[7719]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 18 21:22:01 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Feb 18 21:22:01 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 21:22:01 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 21:22:01 volumio go-librespot[8054]: go-librespot daemon starting... Feb 18 21:22:01 volumio go-librespot[8055]: time="2026-02-18T21:22:01+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 21:22:01 volumio go-librespot[8055]: time="2026-02-18T21:22:01+07:00" level=debug msg="app state loaded" Feb 18 21:22:01 volumio go-librespot[8055]: time="2026-02-18T21:22:01+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 21:22:01 volumio go-librespot[8055]: time="2026-02-18T21:22: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 21:22:01 volumio go-librespot[8055]: time="2026-02-18T21:22: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 21:22:01 volumio go-librespot[8055]: time="2026-02-18T21:22: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 21:22:01 volumio go-librespot[8055]: time="2026-02-18T21:22:01+07:00" level=info msg="zeroconf server listening on port 44669" Feb 18 21:22:02 volumio volumio[7719]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 18 21:22:02 volumio go-librespot[8055]: time="2026-02-18T21:22:02+07:00" level=debug msg="obtained new client token: AABlPd+nnWVHGNUvg41mK9dx+oFHtXurJWZLTQenSEE5Z7DHm6EsNjQoZ+2UgWgMYOfJdt3uas1YYkpO1daAaXOQ9AJhc8uBFniT/7dthFmqRa/avAdPBEUFLZYvHA4ADhHjj+q66alAMtrIxYsR8OJBjKr4Ed5WCPo/QBvw6Tkhv2hfvrIaqIt0+tbr9c349TCqW9yo0BpKS99lX3mFHhAaw1WRnkvnAakQYmoham1Dx6v2DEl+ABM=" Feb 18 21:22:02 volumio go-librespot[8055]: time="2026-02-18T21:22:02+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 21:22:02 volumio go-librespot[8055]: time="2026-02-18T21:22:02+07:00" level=debug msg="completed keyexchange" Feb 18 21:22:02 volumio go-librespot[8055]: time="2026-02-18T21:22:02+07:00" level=debug msg="completed challenge" Feb 18 21:22:02 volumio go-librespot[8055]: time="2026-02-18T21:22: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 21:22:02 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 21:22:02 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 21:22:02 volumio volumio[7719]: info: Initializing connection to go-librespot Websocket Feb 18 21:22:02 volumio volumio[7719]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 18 21:22:05 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Feb 18 21:22:05 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 21:22:05 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 21:22:05 volumio go-librespot[8062]: go-librespot daemon starting... Feb 18 21:22:05 volumio go-librespot[8063]: time="2026-02-18T21:22:05+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 21:22:05 volumio go-librespot[8063]: time="2026-02-18T21:22:05+07:00" level=debug msg="app state loaded" Feb 18 21:22:05 volumio go-librespot[8063]: time="2026-02-18T21:22:05+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 21:22:05 volumio volumio[7719]: info: Initializing connection to go-librespot Websocket Feb 18 21:22:05 volumio go-librespot[8063]: time="2026-02-18T21:22:05+07:00" level=debug msg="new websocket client" Feb 18 21:22:05 volumio volumio[7719]: info: Connection to go-librespot Websocket established Feb 18 21:22:05 volumio volumio[7719]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 18 21:22:05 volumio volumio[7719]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 18 21:22:05 volumio volumio[7719]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 18 21:22:05 volumio volumio[7719]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 18 21:22:05 volumio volumio[7719]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 18 21:22:05 volumio volumio[7719]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 18 21:22:05 volumio volumio[7719]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 18 21:22:05 volumio volumio[7719]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 18 21:22:05 volumio volumio[7719]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 18 21:22:05 volumio volumio[7719]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 18 21:22:05 volumio volumio[7719]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 18 21:22:05 volumio volumio[7719]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 18 21:22:05 volumio volumio[7719]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 18 21:22:05 volumio volumio[7719]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 18 21:22:05 volumio volumio[7719]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 18 21:22:05 volumio volumio[7719]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 18 21:22:05 volumio volumio[7719]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 18 21:22:05 volumio volumio[7719]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 18 21:22:05 volumio volumio[7719]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 18 21:22:05 volumio volumio[7719]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 18 21:22:05 volumio volumio[7719]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 18 21:22:05 volumio volumio[7719]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 18 21:22:05 volumio volumio[7719]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 18 21:22:05 volumio volumio[7719]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 18 21:22:05 volumio volumio[7719]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 18 21:22:05 volumio volumio[7719]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 18 21:22:05 volumio volumio[7719]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 18 21:22:05 volumio volumio[7719]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 18 21:22:05 volumio volumio[7719]: info: Adding plugin bluetooth to MyMusic Plugins Feb 18 21:22:05 volumio volumio[7719]: info: Adding plugin multiroom to MyMusic Plugins Feb 18 21:22:05 volumio volumio[7719]: info: Adding plugin metavolumio to MyMusic Plugins Feb 18 21:22:05 volumio volumio[7719]: info: Adding plugin cd_controller to MyMusic Plugins Feb 18 21:22:05 volumio volumio[7719]: info: Adding plugin qobuzconnect to MyMusic Plugins Feb 18 21:22:05 volumio volumio[7719]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 18 21:22:05 volumio volumio[7719]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 18 21:22:05 volumio volumio[7719]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 18 21:22:06 volumio go-librespot[8063]: time="2026-02-18T21:22: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 21:22:06 volumio go-librespot[8063]: time="2026-02-18T21:22: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 21:22:06 volumio go-librespot[8063]: time="2026-02-18T21:22: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 21:22:06 volumio go-librespot[8063]: time="2026-02-18T21:22:06+07:00" level=info msg="zeroconf server listening on port 46285" Feb 18 21:22:06 volumio go-librespot[8063]: time="2026-02-18T21:22:06+07:00" level=debug msg="obtained new client token: AADNIRkGB0HY4TY/RU/21+PIxpL47vaOcMcYurYEctdY4IcCFqMFv5+aq+MLG+Qlh2FEMb3z/8QM6Gmv+PoZqN277pmNKTupeLyO+STg5bnnGemLrv9QdooOaTCCdhEmumecvLcOQRJvFtv25yWH++xM1LbE2rEpvAwuZTNdh1LqmmaYtrpU+PmQ4Zb78RFnklaaJ4idCUG+8aok687Y74zXxjCTtvnRDGVp9DEkbeOkyVkF3tBtVCDWOA==" Feb 18 21:22:06 volumio go-librespot[8063]: time="2026-02-18T21:22:06+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 21:22:06 volumio go-librespot[8063]: time="2026-02-18T21:22:06+07:00" level=debug msg="completed keyexchange" Feb 18 21:22:06 volumio go-librespot[8063]: time="2026-02-18T21:22:06+07:00" level=debug msg="completed challenge" Feb 18 21:22:06 volumio go-librespot[8063]: time="2026-02-18T21:22: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 21:22:06 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 21:22:06 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 21:22:07 volumio volumio[7719]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 18 21:22:07 volumio volumio[7719]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 18 21:22:07 volumio volumio[7719]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 21:22:07 volumio volumio[7719]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 21:22:07 volumio volumio[7719]: info: Starting MyVolumio Remote Streaming Endpoints Feb 18 21:22:07 volumio volumio[7719]: info: MyVolumio login type: Token Feb 18 21:22:07 volumio volumio[7719]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 18 21:22:07 volumio volumio[7719]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 18 21:22:09 volumio volumio[7719]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 18 21:22:09 volumio volumio[7719]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 18 21:22:09 volumio volumio[7719]: info: Streaming services startup Feb 18 21:22:09 volumio volumio[7719]: info: Starting Streaming Daemon Feb 18 21:22:09 volumio sudo[8086]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 18 21:22:09 volumio sudo[8086]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 21:22:09 volumio volumio[7719]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 18 21:22:09 volumio sudo[8086]: pam_unix(sudo:session): session closed for user root Feb 18 21:22:09 volumio volumio[7719]: info: Getting Spotify volume Feb 18 21:22:09 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Feb 18 21:22:09 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 21:22:09 volumio volumio[7719]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 18 21:22:09 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 21:22:09 volumio go-librespot[8092]: go-librespot daemon starting... Feb 18 21:22:09 volumio volumio[7719]: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 18 21:22:09 volumio volumio[7719]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Feb 18 21:22:09 volumio volumio[7719]: errno: -111, Feb 18 21:22:09 volumio volumio[7719]: code: 'ECONNREFUSED', Feb 18 21:22:09 volumio volumio[7719]: syscall: 'connect', Feb 18 21:22:09 volumio volumio[7719]: address: '127.0.0.1', Feb 18 21:22:09 volumio volumio[7719]: port: 9879, Feb 18 21:22:09 volumio volumio[7719]: response: undefined Feb 18 21:22:09 volumio volumio[7719]: } Feb 18 21:22:09 volumio volumio[7719]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 18 21:22:09 volumio go-librespot[8093]: time="2026-02-18T21:22:09+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 21:22:09 volumio go-librespot[8093]: time="2026-02-18T21:22:09+07:00" level=debug msg="app state loaded" Feb 18 21:22:09 volumio go-librespot[8093]: time="2026-02-18T21:22:09+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 21:22:10 volumio go-librespot[8093]: time="2026-02-18T21:22: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 21:22:10 volumio go-librespot[8093]: time="2026-02-18T21:22:10+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 21:22:10 volumio go-librespot[8093]: time="2026-02-18T21:22:10+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 21:22:10 volumio go-librespot[8093]: time="2026-02-18T21:22:10+07:00" level=info msg="zeroconf server listening on port 42305" Feb 18 21:22:10 volumio go-librespot[8093]: time="2026-02-18T21:22:10+07:00" level=debug msg="obtained new client token: AADM3PPkD9jc0+/fibQy54OaIMl0lk3Z2dP/ouZ/4Ey8+AmR2gctlu0xHvc0DMymLvIrwryXbRBkvIq3+y6ZjJ27ykAnODd0Mfx+/PKIbsrDkxmnWwhHlp0VPjPOs0/73Sns27sTq9/9u9MzXJbECCP+ctNvYUmBWNOWH5gGJ1I0qUiikt5tTkOFWbxQpEsIZldZidrD5GS9slkvmpn4p19myHbVRXIGvj2IXn0lJ6V9ehMSnt+mg7V0Hw==" Feb 18 21:22:10 volumio go-librespot[8093]: time="2026-02-18T21:22:10+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 21:22:10 volumio go-librespot[8093]: time="2026-02-18T21:22:10+07:00" level=debug msg="completed keyexchange" Feb 18 21:22:10 volumio go-librespot[8093]: time="2026-02-18T21:22:10+07:00" level=debug msg="completed challenge" Feb 18 21:22:10 volumio go-librespot[8093]: time="2026-02-18T21:22: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 21:22:10 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 21:22:10 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 21:22:11 volumio sudo[8115]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-18 21:21' Feb 18 21:22:11 volumio sudo[8115]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 21:22:11 volumio sudo[8115]: pam_unix(sudo:session): session closed for user root Feb 18 21:22:13 volumio volumio-remote-updater[25144]: [2026-02-18 21:22:13] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Feb 18 21:22:13 volumio volumio-remote-updater[25144]: [2026-02-18 21:22:13] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Feb 18 21:22:13 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Feb 18 21:22:13 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Feb 18 21:22:13 volumio systemd[1]: volumio.service: Consumed 55.386s CPU time. Feb 18 21:22:13 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 18 21:22:13 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 18 21:22:13 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 22460. Feb 18 21:22:13 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 18 21:22:13 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Feb 18 21:22:13 volumio systemd[1]: volumio.service: Consumed 55.386s CPU time. Feb 18 21:22:13 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Feb 18 21:22:13 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 18 21:22:14 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Feb 18 21:22:14 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 21:22:14 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 21:22:14 volumio go-librespot[8146]: go-librespot daemon starting... Feb 18 21:22:14 volumio go-librespot[8147]: time="2026-02-18T21:22:14+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 21:22:14 volumio go-librespot[8147]: time="2026-02-18T21:22:14+07:00" level=debug msg="app state loaded" Feb 18 21:22:14 volumio go-librespot[8147]: time="2026-02-18T21:22:14+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 21:22:14 volumio go-librespot[8147]: time="2026-02-18T21:22: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 21:22:14 volumio go-librespot[8147]: time="2026-02-18T21:22:14+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 21:22:14 volumio go-librespot[8147]: time="2026-02-18T21:22:14+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 21:22:14 volumio go-librespot[8147]: time="2026-02-18T21:22:14+07:00" level=info msg="zeroconf server listening on port 45871" Feb 18 21:22:14 volumio go-librespot[8147]: time="2026-02-18T21:22:14+07:00" level=debug msg="obtained new client token: AADFC7QWWNCV2SY/BeZ7SCrAhE6nQDkdV0XwJpQrfC0L0kirMHMU0M4BehMMF5ElK9jUiQSU+4drHOvZp7nUB7SddHGL1Pg/wui8r5F3bMM8Nj5C/qEo+9nS3YISUDVpRPYNyIDE6BUC8PxNWKokN531sy19KPZZ8GXKJQ+1cMf6N9IReECqIxfw/PzysO/X8kK6j6QsQsKH/OvELVVjm1PGn4wfD/UCFQHNmV8bF5kM/GhYSq70Fyp9Cg==" Feb 18 21:22:15 volumio go-librespot[8147]: time="2026-02-18T21:22:15+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 21:22:15 volumio go-librespot[8147]: time="2026-02-18T21:22:15+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Feb 18 21:22:15 volumio go-librespot[8147]: time="2026-02-18T21:22:15+07:00" level=debug msg="completed keyexchange" Feb 18 21:22:15 volumio go-librespot[8147]: time="2026-02-18T21:22:15+07:00" level=debug msg="completed challenge" Feb 18 21:22:15 volumio go-librespot[8147]: time="2026-02-18T21:22: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 21:22:15 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 21:22:15 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 21:22:16 volumio volumio[8130]: info: ------------------------------------------- Feb 18 21:22:16 volumio volumio[8130]: info: ----- Volumio3 ---- Feb 18 21:22:16 volumio volumio[8130]: info: ------------------------------------------- Feb 18 21:22:16 volumio volumio[8130]: info: ----- System startup ---- Feb 18 21:22:16 volumio volumio[8130]: info: ------------------------------------------- Feb 18 21:22:18 volumio volumio-remote-updater[25144]: [2026-02-18 21:22:18] [connect] Successful connection Feb 18 21:22:18 volumio volumio[8130]: info: MYVOLUMIO Environment detected Feb 18 21:22:18 volumio volumio[8130]: info: Plugin folders cleanup Feb 18 21:22:18 volumio volumio[8130]: info: Scanning into folder /volumio/app/plugins/ Feb 18 21:22:18 volumio volumio[8130]: info: Scanning category audio_interface Feb 18 21:22:18 volumio volumio[8130]: info: Scanning category miscellanea Feb 18 21:22:18 volumio volumio[8130]: info: Scanning category music_service Feb 18 21:22:18 volumio volumio[8130]: info: Scanning category plugins.json Feb 18 21:22:18 volumio volumio[8130]: info: Scanning category system_controller Feb 18 21:22:18 volumio volumio[8130]: info: Scanning category user_interface Feb 18 21:22:18 volumio volumio[8130]: info: Scanning into folder /data/plugins/ Feb 18 21:22:18 volumio volumio[8130]: info: Scanning category music_service Feb 18 21:22:18 volumio volumio[8130]: info: Plugin folders cleanup completed Feb 18 21:22:18 volumio volumio[8130]: info: ------------------------------------------- Feb 18 21:22:18 volumio volumio[8130]: info: ----- Core plugins startup ---- Feb 18 21:22:18 volumio volumio[8130]: info: ------------------------------------------- Feb 18 21:22:18 volumio volumio[8130]: info: Loading plugins from folder /volumio/app/plugins/ Feb 18 21:22:18 volumio volumio[8130]: info: Adding plugin upnp to MyMusic Plugins Feb 18 21:22:18 volumio volumio[8130]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 18 21:22:18 volumio volumio[8130]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 18 21:22:18 volumio volumio[8130]: info: Loading plugins from folder /data/plugins/ Feb 18 21:22:18 volumio volumio[8130]: info: Loading plugin "system"... Feb 18 21:22:18 volumio volumio[8130]: info: Loading plugin "appearance"... Feb 18 21:22:18 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Feb 18 21:22:18 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 21:22:18 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 21:22:18 volumio go-librespot[8167]: go-librespot daemon starting... Feb 18 21:22:18 volumio go-librespot[8168]: time="2026-02-18T21:22:18+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 21:22:18 volumio go-librespot[8168]: time="2026-02-18T21:22:18+07:00" level=debug msg="app state loaded" Feb 18 21:22:18 volumio go-librespot[8168]: time="2026-02-18T21:22:18+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 21:22:19 volumio go-librespot[8168]: time="2026-02-18T21:22: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 21:22:19 volumio go-librespot[8168]: time="2026-02-18T21:22:19+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 21:22:19 volumio go-librespot[8168]: time="2026-02-18T21:22:19+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 21:22:19 volumio go-librespot[8168]: time="2026-02-18T21:22:19+07:00" level=info msg="zeroconf server listening on port 32785" Feb 18 21:22:19 volumio go-librespot[8168]: time="2026-02-18T21:22:19+07:00" level=debug msg="obtained new client token: AACOcR6Fdp498rYSUIFT64opbIKZLbILMndHJ6UhxsI1IF0xnytsCT7HcEjvw/WFcH6s1sa9T7YP/vk3dARLvWIy3YEML7bteW4CGi69pnDntXIsGjgGNz1yICiCCp9D5i+3D6wni/sSlsTc9wEPrOzR8xdrUjwFoqWLvfZlibwo++CcTOMqqaOkcMPRGJSXLzMbkPdd5ZsRQEsGgkTiZSj9txvHDhPUFoKUx7Md/NRaFB8tVYUqf3LuXA==" Feb 18 21:22:19 volumio go-librespot[8168]: time="2026-02-18T21:22:19+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 21:22:19 volumio go-librespot[8168]: time="2026-02-18T21:22:19+07:00" level=debug msg="completed keyexchange" Feb 18 21:22:19 volumio go-librespot[8168]: time="2026-02-18T21:22:19+07:00" level=debug msg="completed challenge" Feb 18 21:22:19 volumio go-librespot[8168]: time="2026-02-18T21:22: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 21:22:19 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 21:22:19 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 21:22:20 volumio volumio[8130]: info: Loading plugin "network"... Feb 18 21:22:20 volumio volumio[8130]: info: Refreshing Cached IP Addresses Feb 18 21:22:20 volumio sudo[8176]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 18 21:22:20 volumio sudo[8176]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 21:22:20 volumio volumio[8130]: info: Loading plugin "services"... Feb 18 21:22:20 volumio sudo[8178]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 18 21:22:20 volumio sudo[8178]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 21:22:20 volumio volumio[8130]: info: Loading plugin "alsa_controller"... Feb 18 21:22:20 volumio sudo[8176]: pam_unix(sudo:session): session closed for user root Feb 18 21:22:20 volumio sudo[8178]: pam_unix(sudo:session): session closed for user root Feb 18 21:22:20 volumio sudo[8185]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 18 21:22:20 volumio sudo[8185]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 21:22:20 volumio volumio[8130]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 18 21:22:20 volumio volumio[8130]: info: Loading plugin "wizard"... Feb 18 21:22:20 volumio volumio[8130]: info: Loading plugin "networkfs"... Feb 18 21:22:20 volumio volumio[8130]: info: Starting Udev Watcher for removable devices Feb 18 21:22:20 volumio volumio[8130]: info: Ignoring mount for partition: boot Feb 18 21:22:20 volumio volumio[8130]: info: Ignoring mount for partition: volumio Feb 18 21:22:20 volumio volumio[8130]: info: Ignoring mount for partition: volumio_data Feb 18 21:22:20 volumio volumio[8130]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 18 21:22:20 volumio volumio[8130]: info: Loading plugin "volumio_command_line_client"... Feb 18 21:22:20 volumio volumio[8130]: info: Loading plugin "upnp"... Feb 18 21:22:20 volumio volumio[8130]: info: [1771424540887] Starting Upmpd Daemon Feb 18 21:22:20 volumio volumio[8130]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 18 21:22:20 volumio volumio[8130]: info: Loading plugin "my_music"... Feb 18 21:22:20 volumio volumio[8130]: info: Loading plugin "mpd"... Feb 18 21:22:21 volumio volumio[8130]: info: Loading plugin "upnp_browser"... Feb 18 21:22:23 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Feb 18 21:22:23 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 21:22:23 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 21:22:23 volumio go-librespot[8209]: go-librespot daemon starting... Feb 18 21:22:23 volumio go-librespot[8210]: time="2026-02-18T21:22:23+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 21:22:23 volumio go-librespot[8210]: time="2026-02-18T21:22:23+07:00" level=debug msg="app state loaded" Feb 18 21:22:23 volumio go-librespot[8210]: time="2026-02-18T21:22:23+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 21:22:23 volumio sudo[8185]: pam_unix(sudo:session): session closed for user root Feb 18 21:22:23 volumio go-librespot[8210]: time="2026-02-18T21:22: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 21:22:23 volumio go-librespot[8210]: time="2026-02-18T21:22: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 21:22:23 volumio go-librespot[8210]: time="2026-02-18T21:22: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 21:22:23 volumio go-librespot[8210]: time="2026-02-18T21:22:23+07:00" level=info msg="zeroconf server listening on port 38663" Feb 18 21:22:23 volumio go-librespot[8210]: time="2026-02-18T21:22:23+07:00" level=debug msg="obtained new client token: AADfNHUDyLHkOGPpiEVyq6DMaCJPBCLS96oHs7bjsb2ukbiFbZIK4xp3JtznDOafgRywHISQMe87ZuOvqc071AEgU2xZ7LPnwTscBzLcApRo4yNY++4Rbg4r6gIQol64wE1z3OwGnhjZXPqrSUf8ETLKIgDEprm6DRWjK2k3PmSaU0fb1IXA32aQoEEIDhB+cNagHXKDEcQwCK73A9Q4n6wcQ5yGD+vE3oRgdC25ypcxcgjWmqMl325cmg==" Feb 18 21:22:23 volumio go-librespot[8210]: time="2026-02-18T21:22:23+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 21:22:24 volumio go-librespot[8210]: time="2026-02-18T21:22:24+07:00" level=debug msg="completed keyexchange" Feb 18 21:22:24 volumio go-librespot[8210]: time="2026-02-18T21:22:24+07:00" level=debug msg="completed challenge" Feb 18 21:22:24 volumio go-librespot[8210]: time="2026-02-18T21:22: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 21:22:24 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 21:22:24 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 21:22:24 volumio volumio[8130]: info: Starting UPNP Browser Feb 18 21:22:24 volumio volumio[8130]: info: Loading plugin "alarm-clock"... Feb 18 21:22:24 volumio volumio[8130]: info: Loading plugin "airplay_emulation"... Feb 18 21:22:24 volumio volumio[8130]: info: Starting Shairport Sync Feb 18 21:22:24 volumio volumio[8130]: info: Loading plugin "last_100"... Feb 18 21:22:24 volumio volumio[8130]: info: Loading plugin "webradio"... Feb 18 21:22:25 volumio volumio[8130]: info: Loading plugin "i2s_dacs"... Feb 18 21:22:25 volumio volumio[8130]: info: Loading plugin "volumiodiscovery"... Feb 18 21:22:25 volumio volumio[8130]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 18 21:22:25 volumio volumio[8130]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 18 21:22:25 volumio node[8130]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 18 21:22:25 volumio volumio[8130]: *** WARNING *** For more information see Feb 18 21:22:25 volumio volumio[8130]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 18 21:22:25 volumio volumio[8130]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 18 21:22:25 volumio volumio[8130]: *** WARNING *** For more information see Feb 18 21:22:25 volumio node[8130]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 18 21:22:25 volumio node[8130]: *** WARNING *** For more information see Feb 18 21:22:25 volumio node[8130]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 18 21:22:25 volumio node[8130]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 18 21:22:25 volumio node[8130]: *** WARNING *** For more information see Feb 18 21:22:25 volumio volumio[8130]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 18 21:22:25 volumio volumio[8130]: info: Discovery: Started advertising with name: Volumio Feb 18 21:22:25 volumio volumio[8130]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 18 21:22:25 volumio volumio[8130]: info: Loading plugin "spop"... Feb 18 21:22:27 volumio volumio[8130]: info: Loading plugin "ytcr"... Feb 18 21:22:27 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Feb 18 21:22:27 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 21:22:27 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 21:22:27 volumio go-librespot[8219]: go-librespot daemon starting... Feb 18 21:22:27 volumio go-librespot[8220]: time="2026-02-18T21:22:27+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 21:22:27 volumio go-librespot[8220]: time="2026-02-18T21:22:27+07:00" level=debug msg="app state loaded" Feb 18 21:22:27 volumio go-librespot[8220]: time="2026-02-18T21:22:27+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 21:22:27 volumio go-librespot[8220]: time="2026-02-18T21:22: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 21:22:27 volumio go-librespot[8220]: time="2026-02-18T21:22: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 21:22:27 volumio go-librespot[8220]: time="2026-02-18T21:22: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 21:22:27 volumio go-librespot[8220]: time="2026-02-18T21:22:27+07:00" level=info msg="zeroconf server listening on port 37741" Feb 18 21:22:28 volumio go-librespot[8220]: time="2026-02-18T21:22:28+07:00" level=debug msg="obtained new client token: AABjZHZfaQ94nR4sJlnKVrW1rSFOgvV+rGCKBIBXPazG9QGSCtSq++cAaXWXgpfRrKDSBFgdBxQPxScDjxGUz9DwbZXtG+/8CMuK80mf6W00J3VUVUwY7lSjYUFvz11V7+zHvN/W06g0vF6RO6iKYv7hM9f0swEpJfsh9queTo/c09waTBcYR+tfK2q41q0bAtIe+pyy0+apGguLzBAsBHqbYGSi2TLRcpp9VD3dFe64KrsbfIJx1Oo=" Feb 18 21:22:28 volumio go-librespot[8220]: time="2026-02-18T21:22:28+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 21:22:28 volumio go-librespot[8220]: time="2026-02-18T21:22:28+07:00" level=debug msg="completed keyexchange" Feb 18 21:22:28 volumio go-librespot[8220]: time="2026-02-18T21:22:28+07:00" level=debug msg="completed challenge" Feb 18 21:22:28 volumio go-librespot[8220]: time="2026-02-18T21:22: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 21:22:28 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 21:22:28 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 21:22:29 volumio volumio[8130]: info: Loading plugin "ytmusic"... Feb 18 21:22:30 volumio volumio-remote-updater[25144]: [2026-02-18 21:22:30] [connect] Successful connection Feb 18 21:22:30 volumio volumio[8130]: info: Loading plugin "outputs"... Feb 18 21:22:30 volumio volumio[8130]: info: Loading plugin "albumart"... Feb 18 21:22:30 volumio volumio[8130]: info: Plugin example_plugin is not enabled Feb 18 21:22:30 volumio volumio[8130]: info: Loading plugin "inputs"... Feb 18 21:22:30 volumio volumio[8130]: info: Loading plugin "updater_comm"... Feb 18 21:22:31 volumio volumio[8130]: info: Plugin mpdemulation is not enabled Feb 18 21:22:31 volumio volumio[8130]: info: Loading plugin "rest_api"... Feb 18 21:22:31 volumio volumio[8130]: info: Loading plugin "websocket"... Feb 18 21:22:31 volumio volumio[8130]: info: Starting Socket.io Server version 1.7.4 Feb 18 21:22:31 volumio volumio[8130]: info: Loading plugin "RoonBridge"... Feb 18 21:22:31 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Feb 18 21:22:31 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 21:22:31 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 21:22:31 volumio go-librespot[8251]: go-librespot daemon starting... Feb 18 21:22:31 volumio go-librespot[8252]: time="2026-02-18T21:22:31+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 21:22:31 volumio go-librespot[8252]: time="2026-02-18T21:22:31+07:00" level=debug msg="app state loaded" Feb 18 21:22:31 volumio go-librespot[8252]: time="2026-02-18T21:22:31+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 21:22:31 volumio volumio[8130]: info: Applying required configuration parameters for plugin RoonBridge Feb 18 21:22:31 volumio volumio[8130]: info: Loading i18n strings for locale en Feb 18 21:22:31 volumio volumio[8130]: Updating browse sources language Feb 18 21:22:31 volumio volumio[8130]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 21:22:31 volumio volumio[8241]: Forking 3 albumart workers Feb 18 21:22:32 volumio volumio[8130]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 18 21:22:32 volumio volumio[8130]: info: CoreCommandRouter::initPlayerControls Feb 18 21:22:32 volumio volumio[8130]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 21:22:32 volumio volumio[8130]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 21:22:32 volumio volumio[8130]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 21:22:32 volumio volumio[8130]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 21:22:32 volumio volumio[8130]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 21:22:32 volumio volumio[8130]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 21:22:32 volumio volumio[8130]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 21:22:32 volumio volumio[8130]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 21:22:32 volumio volumio[8130]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 18 21:22:32 volumio volumio[8130]: Express server listening on port 3000 Feb 18 21:22:32 volumio volumio[8130]: [Metrics] WebUI: 16s 145.15ms Feb 18 21:22:32 volumio volumio[8130]: info: CoreStateMachine::resetVolumioState Feb 18 21:22:32 volumio volumio[8130]: info: CoreStateMachine::getcurrentVolume Feb 18 21:22:32 volumio volumio[8130]: info: CoreCommandRouter::volumioRetrievevolume Feb 18 21:22:32 volumio go-librespot[8252]: time="2026-02-18T21:22:32+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 21:22:32 volumio go-librespot[8252]: time="2026-02-18T21:22:32+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 18 21:22:32 volumio go-librespot[8252]: time="2026-02-18T21:22:32+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 18 21:22:32 volumio go-librespot[8252]: time="2026-02-18T21:22:32+07:00" level=info msg="zeroconf server listening on port 42857" Feb 18 21:22:32 volumio sudo[8297]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 18 21:22:32 volumio sudo[8297]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 21:22:32 volumio sudo[8297]: pam_unix(sudo:session): session closed for user root Feb 18 21:22:32 volumio sudo[8294]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 18 21:22:32 volumio sudo[8294]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 21:22:32 volumio sudo[8294]: pam_unix(sudo:session): session closed for user root Feb 18 21:22:32 volumio volumio[8130]: info: Volumio Network Manager: Network status updated: 1 Feb 18 21:22:32 volumio go-librespot[8252]: time="2026-02-18T21:22:32+07:00" level=debug msg="obtained new client token: AACsfM+QlnlOx+irrbw/i1I/WhNxkPTe1+C1IgmrX9ozZrRX1T0mNH3NYgsPCldwBXB2NUbXGUyZ2g02QdagGSoaWfbSDACIJYrjBYCbXgc9cpNr8RktCLHSTsI3+liYYRVp46QGIbnp51xOJBg6KVzprASh2+6OxAxFFzRfWiygi8S625G4gI7eMVv6XekbcM3THtRb+Ecnpja1s2naqyCFTsnOx/EGL8CjjaG3iIaKtmsz1/DPV1xswg==" Feb 18 21:22:32 volumio go-librespot[8252]: time="2026-02-18T21:22:32+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 21:22:32 volumio go-librespot[8252]: time="2026-02-18T21:22:32+07:00" level=debug msg="completed keyexchange" Feb 18 21:22:32 volumio go-librespot[8252]: time="2026-02-18T21:22:32+07:00" level=debug msg="completed challenge" Feb 18 21:22:32 volumio volumio-remote-updater[25144]: [2026-02-18 21:22:32] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1771424550 101 Feb 18 21:22:32 volumio volumio[8130]: 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 21:22:32 volumio volumio[8130]: info: VolumeController:: Volume=100 Mute =false Feb 18 21:22:32 volumio volumio[8130]: info: CoreStateMachine::pushState Feb 18 21:22:32 volumio volumio[8130]: info: CorePlayQueue::getTrack 0 Feb 18 21:22:32 volumio volumio[8130]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 18 21:22:32 volumio go-librespot[8252]: time="2026-02-18T21:22: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 21:22:32 volumio volumio[8130]: info: CoreCommandRouter::volumioPushState Feb 18 21:22:32 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 21:22:32 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 21:22:32 volumio volumio[8130]: info: CoreStateMachine::updateTrackBlock Feb 18 21:22:32 volumio volumio[8130]: info: CorePlayQueue::getTrackBlock Feb 18 21:22:32 volumio volumio[8130]: info: CoreCommandRouter::volumioRetrievevolume Feb 18 21:22:32 volumio volumio[8130]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 21:22:32 volumio volumio[8130]: info: Reloading queue from file Feb 18 21:22:33 volumio volumio[8130]: info: CoreStateMachine::setRepeat null single undefined Feb 18 21:22:33 volumio volumio[8130]: info: CoreStateMachine::pushState Feb 18 21:22:33 volumio volumio[8130]: info: CorePlayQueue::getTrack 0 Feb 18 21:22:33 volumio volumio[8130]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 18 21:22:33 volumio volumio[8130]: info: CoreCommandRouter::volumioPushState Feb 18 21:22:33 volumio volumio[8130]: info: CoreStateMachine::setRandom null Feb 18 21:22:33 volumio volumio[8130]: info: CoreStateMachine::pushState Feb 18 21:22:33 volumio volumio[8130]: info: CorePlayQueue::getTrack 0 Feb 18 21:22:33 volumio volumio[8130]: info: CoreCommandRouter::volumioPushState Feb 18 21:22:33 volumio volumio[8130]: info: Setting Device type: Raspberry PI Feb 18 21:22:33 volumio volumio[8130]: info: Completed loading Core Plugins Feb 18 21:22:33 volumio volumio[8130]: info: Preparing to generate the ALSA configuration file Feb 18 21:22:33 volumio volumio[8130]: info: VolumeController:: Volume=100 Mute =false Feb 18 21:22:33 volumio volumio[8130]: info: CoreStateMachine::pushState Feb 18 21:22:33 volumio volumio[8130]: info: CorePlayQueue::getTrack 0 Feb 18 21:22:33 volumio volumio[8130]: info: CoreCommandRouter::volumioPushState Feb 18 21:22:33 volumio volumio[8130]: info: Asound.conf file unchanged, so no further update is needed Feb 18 21:22:33 volumio volumio[8130]: info: Output device has changed, restarting MPD Feb 18 21:22:33 volumio volumio[8130]: info: Output device has changed, restarting Shairport Sync Feb 18 21:22:33 volumio volumio[8130]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 21:22:33 volumio volumio[8130]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 21:22:33 volumio sudo[8312]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 18 21:22:33 volumio sudo[8312]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 21:22:33 volumio volumio[8130]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 18 21:22:33 volumio volumio[8130]: info: ___________ START PLUGINS ___________ Feb 18 21:22:33 volumio sudo[8314]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 18 21:22:33 volumio sudo[8314]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 21:22:33 volumio sudo[8314]: pam_unix(sudo:session): session closed for user root Feb 18 21:22:33 volumio volumio[8130]: info: ControllerMpd::onStart: Initializing MPD Feb 18 21:22:33 volumio volumio[8130]: info: Creating MPD Configuration file Feb 18 21:22:33 volumio sudo[8312]: pam_unix(sudo:session): session closed for user root Feb 18 21:22:33 volumio sudo[8316]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 18 21:22:33 volumio sudo[8316]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 21:22:33 volumio volumio[8130]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 18 21:22:33 volumio volumio[8130]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 21:22:33 volumio volumio[8130]: info: [1771424553536] CoreMusicLibrary::Adding element Media Servers Feb 18 21:22:33 volumio volumio[8130]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 21:22:33 volumio volumio[8130]: info: UPNP Browser: Client initialized successfully Feb 18 21:22:33 volumio sudo[8325]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 18 21:22:33 volumio sudo[8327]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 18 21:22:33 volumio sudo[8327]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 21:22:33 volumio sudo[8325]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 21:22:33 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 18 21:22:33 volumio volumio[8130]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 21:22:33 volumio volumio[8130]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 21:22:33 volumio sudo[8325]: pam_unix(sudo:session): session closed for user root Feb 18 21:22:33 volumio volumio[8130]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 18 21:22:33 volumio volumio[8130]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 21:22:33 volumio volumio[8130]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 21:22:33 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 18 21:22:33 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 18 21:22:33 volumio systemd[1]: mpd.service: Consumed 7.195s CPU time. Feb 18 21:22:33 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 18 21:22:33 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 18 21:22:33 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 18 21:22:33 volumio volumio[8130]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 18 21:22:33 volumio volumio[8130]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 21:22:33 volumio volumio[8130]: info: [1771424553872] CoreMusicLibrary::Adding element Last_100 Feb 18 21:22:33 volumio volumio[8130]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 21:22:33 volumio volumio[8130]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 21:22:33 volumio volumio[8130]: info: [1771424553891] CoreMusicLibrary::Adding element Webradio Feb 18 21:22:33 volumio volumio[8130]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 21:22:33 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 18 21:22:33 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 18 21:22:33 volumio volumio[8130]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 18 21:22:33 volumio volumio[8130]: info: Initializing BBC Radios Feb 18 21:22:34 volumio volumio[8130]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 18 21:22:34 volumio volumio[8130]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 21:22:34 volumio volumio[8130]: info: Creating Spotify config file Feb 18 21:22:34 volumio volumio[8130]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 21:22:34 volumio sudo[8339]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 18 21:22:34 volumio sudo[8339]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 18 21:22:34 volumio sudo[8339]: pam_unix(sudo:session): session closed for user root Feb 18 21:22:35 volumio volumio[8260]: Starting albumart workers Feb 18 21:22:35 volumio volumio[8130]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 21:22:35 volumio volumio[8130]: info: [1771424555197] CoreMusicLibrary::Adding element YouTube Music Feb 18 21:22:35 volumio volumio[8130]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 21:22:35 volumio volumio[8130]: Cannot find translation for source YouTube Music Feb 18 21:22:35 volumio volumio[8130]: info: Volumio Calling Home Feb 18 21:22:35 volumio sudo[8356]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Feb 18 21:22:35 volumio sudo[8356]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 21:22:35 volumio volumio[8259]: Starting albumart workers Feb 18 21:22:35 volumio sudo[8356]: pam_unix(sudo:session): session closed for user root Feb 18 21:22:35 volumio volumio[8258]: Starting albumart workers Feb 18 21:22:35 volumio volumio[8130]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Feb 18 21:22:35 volumio volumio[8130]: info: Discovery: Found device Volumio Feb 18 21:22:35 volumio volumio[8130]: info: CoreCommandRouter::volumioGetState Feb 18 21:22:35 volumio volumio[8130]: info: CorePlayQueue::getTrack 0 Feb 18 21:22:35 volumio volumio[8130]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Feb 18 21:22:35 volumio volumio[8130]: info: Discovery: Found device Volumio Feb 18 21:22:35 volumio volumio[8130]: info: CoreCommandRouter::volumioGetState Feb 18 21:22:35 volumio volumio[8130]: info: CorePlayQueue::getTrack 0 Feb 18 21:22:36 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Feb 18 21:22:36 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 21:22:36 volumio volumio[8130]: info: MPD Permissions set Feb 18 21:22:36 volumio volumio[8130]: info: MPD Permissions set Feb 18 21:22:36 volumio volumio[8130]: info: Upmpdcli Daemon Started Feb 18 21:22:36 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 21:22:36 volumio go-librespot[8362]: go-librespot daemon starting... Feb 18 21:22:36 volumio volumio[8130]: 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 21:22:36 volumio volumio[8130]: info: Spotify config file written Feb 18 21:22:36 volumio go-librespot[8363]: time="2026-02-18T21:22:36+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 21:22:36 volumio go-librespot[8363]: time="2026-02-18T21:22:36+07:00" level=debug msg="app state loaded" Feb 18 21:22:36 volumio go-librespot[8363]: time="2026-02-18T21:22:36+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 21:22:36 volumio sudo[8370]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 18 21:22:36 volumio sudo[8370]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 21:22:36 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Feb 18 21:22:36 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Feb 18 21:22:36 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 21:22:36 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 21:22:36 volumio go-librespot[8372]: go-librespot daemon starting... Feb 18 21:22:36 volumio sudo[8370]: pam_unix(sudo:session): session closed for user root Feb 18 21:22:36 volumio go-librespot[8373]: time="2026-02-18T21:22:36+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 21:22:36 volumio go-librespot[8373]: time="2026-02-18T21:22:36+07:00" level=debug msg="app state loaded" Feb 18 21:22:36 volumio go-librespot[8373]: time="2026-02-18T21:22:36+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 21:22:37 volumio volumio[8130]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 21:22:37 volumio volumio[8130]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 21:22:37 volumio volumio[8130]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 21:22:37 volumio volumio[8130]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 21:22:37 volumio volumio[8130]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 21:22:37 volumio volumio[8130]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 21:22:37 volumio volumio[8130]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 21:22:37 volumio volumio[8130]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 21:22:37 volumio volumio[8130]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 21:22:37 volumio volumio[8130]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 21:22:37 volumio volumio[8130]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 21:22:37 volumio volumio[8130]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 21:22:37 volumio volumio[8130]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 21:22:37 volumio volumio[8130]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 21:22:37 volumio volumio[8130]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 21:22:37 volumio volumio[8130]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 21:22:37 volumio volumio[8130]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 21:22:37 volumio volumio[8130]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 21:22:37 volumio volumio[8130]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 21:22:37 volumio volumio[8130]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 21:22:37 volumio volumio[8130]: info: No need to fix Spotify hosts Feb 18 21:22:37 volumio go-librespot[8373]: time="2026-02-18T21:22:37+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 21:22:37 volumio go-librespot[8373]: time="2026-02-18T21:22:37+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 21:22:37 volumio go-librespot[8373]: time="2026-02-18T21:22:37+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 21:22:37 volumio go-librespot[8373]: time="2026-02-18T21:22:37+07:00" level=info msg="zeroconf server listening on port 41455" Feb 18 21:22:37 volumio go-librespot[8373]: time="2026-02-18T21:22:37+07:00" level=debug msg="obtained new client token: AACObElZVtuA81R8aDwvNmx7xAs6aY9NHqfYz0T8ESWon1ybh123pjoh+A1iIK2CP/6bBxn9gOXBHpdbqwvMvuJnWSTJeADuoncI/iFh2a6JmFhGnnFf4I9MO/gyQYuHEeJb1kzFHnfOuRRA/+EIDbXSeZdJFmAi0TUWspP4NdrVGVNbBUO1k3zTMW2HD4UyNIu8iTyNDq6Q5E/lAP6kFf/YrdF1N+Z8T42WRD73han+/l6dMb5AXPMmAg==" Feb 18 21:22:37 volumio go-librespot[8373]: time="2026-02-18T21:22:37+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 21:22:38 volumio go-librespot[8373]: time="2026-02-18T21:22:38+07:00" level=debug msg="completed keyexchange" Feb 18 21:22:38 volumio go-librespot[8373]: time="2026-02-18T21:22:38+07:00" level=debug msg="completed challenge" Feb 18 21:22:38 volumio go-librespot[8373]: time="2026-02-18T21:22:38+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 18 21:22:38 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 21:22:38 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 21:22:38 volumio volumio[8130]: info: Volumio called home Feb 18 21:22:38 volumio volumio[8130]: info: Starting Shairport Sync Feb 18 21:22:38 volumio volumio[8130]: info: Starting Shairport Sync Feb 18 21:22:38 volumio volumio[8130]: info: Starting Shairport Sync Feb 18 21:22:38 volumio sudo[8409]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 18 21:22:38 volumio sudo[8409]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 21:22:38 volumio sudo[8411]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 18 21:22:38 volumio sudo[8411]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 21:22:38 volumio sudo[8413]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 18 21:22:38 volumio sudo[8413]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 21:22:38 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 18 21:22:38 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 18 21:22:38 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 18 21:22:38 volumio systemd[1]: shairport-sync.service: Consumed 2.287s CPU time. Feb 18 21:22:38 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 18 21:22:38 volumio sudo[8409]: pam_unix(sudo:session): session closed for user root Feb 18 21:22:38 volumio volumio[8130]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 18 21:22:38 volumio volumio[8130]: SPOTIFY: BQBbkzSNnKt7OCMQmuBsQ45FHJNBoU2zd9EyGraSMpk7NrfqK22tP34EBIJtCxYh0h0on_NO0HExqVW5763oEA-Q1eF2AHJVczAuvr0meyrky-u1eqPPl8RABemZhza62l-cL82sYzF3-OieIjichC4P-PRl1tY_PAu4VvhkXDLyUqzJatUH65pyluYWB2CyJHmEnFOOuTJKhhk5LDzduCgAgfDHInpUkcdizl1Ufx5gqpeZ4I_Fe9htEDeZmGJUAWdrpXOUV44vbcbwqgf94XYYr4-sG_nBBa-ortMXMGbREF9eMPoAdxkm Feb 18 21:22:38 volumio volumio[8130]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 18 21:22:38 volumio volumio[8130]: info: New Spotify access token = BQBbkzSNnKt7OCMQmuBsQ45FHJNBoU2zd9EyGraSMpk7NrfqK22tP34EBIJtCxYh0h0on_NO0HExqVW5763oEA-Q1eF2AHJVczAuvr0meyrky-u1eqPPl8RABemZhza62l-cL82sYzF3-OieIjichC4P-PRl1tY_PAu4VvhkXDLyUqzJatUH65pyluYWB2CyJHmEnFOOuTJKhhk5LDzduCgAgfDHInpUkcdizl1Ufx5gqpeZ4I_Fe9htEDeZmGJUAWdrpXOUV44vbcbwqgf94XYYr4-sG_nBBa-ortMXMGbREF9eMPoAdxkm Feb 18 21:22:38 volumio volumio[8130]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 18 21:22:38 volumio sudo[8411]: pam_unix(sudo:session): session closed for user root Feb 18 21:22:38 volumio volumio[8130]: info: Shairport-Sync Started Feb 18 21:22:38 volumio volumio[8130]: Error adding Membership: Error: addMembership EINVAL Feb 18 21:22:38 volumio volumio[8130]: info: CoreCommandRouter::volumioGetState Feb 18 21:22:38 volumio volumio[8130]: info: CorePlayQueue::getTrack 0 Feb 18 21:22:38 volumio volumio[8130]: info: Shairport-Sync Started Feb 18 21:22:38 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 18 21:22:38 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 18 21:22:38 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 18 21:22:38 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 18 21:22:38 volumio sudo[8413]: pam_unix(sudo:session): session closed for user root Feb 18 21:22:39 volumio volumio[8130]: info: Shairport-Sync Started Feb 18 21:22:39 volumio volumio[8130]: 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 21:22:39 volumio volumio[8130]: info: Spotify Successfully logged in Feb 18 21:22:39 volumio volumio[8130]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 21:22:39 volumio volumio[8130]: info: [1771424559249] CoreMusicLibrary::Adding element Spotify Feb 18 21:22:39 volumio volumio[8130]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 21:22:39 volumio volumio[8130]: Cannot find translation for source YouTube Music Feb 18 21:22:39 volumio volumio[8130]: Cannot find translation for source Spotify Feb 18 21:22:39 volumio volumio[8130]: info: [yt-cast-receiver] DIAL server listening on port 8098 Feb 18 21:22:39 volumio volumio[8130]: info: CoreCommandRouter::volumioRetrievevolume Feb 18 21:22:39 volumio volumio[8130]: info: VolumeController:: Volume=100 Mute =false Feb 18 21:22:39 volumio volumio[8130]: info: CoreCommandRouter::volumioGetState Feb 18 21:22:39 volumio volumio[8130]: info: CorePlayQueue::getTrack 0 Feb 18 21:22:39 volumio volumio[8130]: info: CoreStateMachine::pushState Feb 18 21:22:39 volumio volumio[8130]: info: CorePlayQueue::getTrack 0 Feb 18 21:22:39 volumio volumio[8130]: info: CoreCommandRouter::volumioPushState Feb 18 21:22:41 volumio volumio[8130]: info: go-librespot daemon successfully initialized Feb 18 21:22:41 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Feb 18 21:22:41 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 21:22:41 volumio mpd[8354]: 2026-02-18T21:22:41 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 18 21:22:41 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 21:22:41 volumio go-librespot[8450]: go-librespot daemon starting... Feb 18 21:22:41 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 18 21:22:41 volumio sudo[8327]: pam_unix(sudo:session): session closed for user root Feb 18 21:22:41 volumio sudo[8316]: pam_unix(sudo:session): session closed for user root Feb 18 21:22:41 volumio go-librespot[8453]: time="2026-02-18T21:22:41+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 21:22:41 volumio go-librespot[8453]: time="2026-02-18T21:22:41+07:00" level=debug msg="app state loaded" Feb 18 21:22:41 volumio go-librespot[8453]: time="2026-02-18T21:22:41+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 21:22:41 volumio volumio[8130]: error: MPD error: The expression evaluated to a falsy value: Feb 18 21:22:41 volumio volumio[8130]: assert.ok(self.idling) Feb 18 21:22:41 volumio volumio[8130]: error: The expression evaluated to a falsy value: Feb 18 21:22:41 volumio volumio[8130]: assert.ok(self.idling) Feb 18 21:22:41 volumio volumio[8130]: error: updateQueue error: null Feb 18 21:22:41 volumio volumio[8130]: info: MPD running with PID8354 Feb 18 21:22:41 volumio volumio[8130]: ,establishing connection Feb 18 21:22:41 volumio volumio[8130]: info: Completed starting Core Plugins Feb 18 21:22:41 volumio volumio[8130]: info: ------------------------------------------- Feb 18 21:22:41 volumio volumio[8130]: info: ----- MyVolumio plugins startup ---- Feb 18 21:22:41 volumio volumio[8130]: info: ------------------------------------------- Feb 18 21:22:41 volumio volumio[8130]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 18 21:22:41 volumio volumio[8130]: error: updateQueue error: null Feb 18 21:22:41 volumio go-librespot[8453]: time="2026-02-18T21:22:41+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 21:22:41 volumio go-librespot[8453]: time="2026-02-18T21:22:41+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 21:22:41 volumio go-librespot[8453]: time="2026-02-18T21:22:41+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 21:22:42 volumio go-librespot[8453]: time="2026-02-18T21:22:42+07:00" level=info msg="zeroconf server listening on port 33489" Feb 18 21:22:42 volumio go-librespot[8453]: time="2026-02-18T21:22:42+07:00" level=debug msg="obtained new client token: AAA74Dn8qieqfP1Qlds+nP22cCLgCv37H1mtCCK+UltDcBfN01KbXLB315LHqYKe7knLYbbtE0jauv6w47qvpME2uzIvz+bJSuiU4rOJw/7BuoKJ3WrgUTDjsSbQTJpMxZCyWJao8PtiYzMKXy5ur69qRcdX2rcTBDl0vGUYIVEfaP9aSvb1usGH7xbPg2Ofc0Fg/QBIlArKqQauVIJ7DQ4s6W7oExuHJUaw81DKkeQ/s9NWa04ZbN8=" Feb 18 21:22:42 volumio go-librespot[8453]: time="2026-02-18T21:22:42+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 21:22:42 volumio go-librespot[8453]: time="2026-02-18T21:22:42+07:00" level=debug msg="completed keyexchange" Feb 18 21:22:42 volumio go-librespot[8453]: time="2026-02-18T21:22:42+07:00" level=debug msg="completed challenge" Feb 18 21:22:42 volumio go-librespot[8453]: time="2026-02-18T21:22:42+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 18 21:22:42 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 21:22:42 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 21:22:44 volumio volumio[8130]: info: Initializing connection to go-librespot Websocket Feb 18 21:22:44 volumio volumio[8130]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 18 21:22:45 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Feb 18 21:22:45 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 21:22:45 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 21:22:45 volumio go-librespot[8462]: go-librespot daemon starting... Feb 18 21:22:45 volumio go-librespot[8463]: time="2026-02-18T21:22:45+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 21:22:45 volumio go-librespot[8463]: time="2026-02-18T21:22:45+07:00" level=debug msg="app state loaded" Feb 18 21:22:45 volumio go-librespot[8463]: time="2026-02-18T21:22:45+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 21:22:46 volumio go-librespot[8463]: time="2026-02-18T21:22:46+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 18 21:22:46 volumio go-librespot[8463]: time="2026-02-18T21:22:46+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 18 21:22:46 volumio go-librespot[8463]: time="2026-02-18T21:22:46+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 18 21:22:46 volumio go-librespot[8463]: time="2026-02-18T21:22:46+07:00" level=info msg="zeroconf server listening on port 33549" Feb 18 21:22:46 volumio volumio[8130]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 18 21:22:46 volumio go-librespot[8463]: time="2026-02-18T21:22:46+07:00" level=debug msg="obtained new client token: AABvsDr54HEaNFS5Y13MsRhSTczoCGvZ4J52J9jrPOMsGqH+f1lhs0DcT42yTBRyciQqiL8iYrPUZm5a+iu0y/M74CCts4hmcS1/6P+UZZljGVqPxoQ9GrW/mufbT0YrtABdh4BrVrqYR7f425HyS5+c34hM1DgIJ+UZ8vFESctXf1JH0cu4AIS2j9St0ev60dzsBddh4QJT5jVq0gLFIfSdNvyqFS3ni+ZyHXFtWJFu3f9aNJq3ANn+3Q==" Feb 18 21:22:46 volumio go-librespot[8463]: time="2026-02-18T21:22:46+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 21:22:46 volumio go-librespot[8463]: time="2026-02-18T21:22:46+07:00" level=debug msg="completed keyexchange" Feb 18 21:22:46 volumio go-librespot[8463]: time="2026-02-18T21:22:46+07:00" level=debug msg="completed challenge" Feb 18 21:22:46 volumio go-librespot[8463]: time="2026-02-18T21:22:46+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 18 21:22:46 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 21:22:46 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 21:22:47 volumio volumio[8130]: info: Initializing connection to go-librespot Websocket Feb 18 21:22:47 volumio volumio[8130]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 18 21:22:50 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Feb 18 21:22:50 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 21:22:50 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 21:22:50 volumio go-librespot[8470]: go-librespot daemon starting... Feb 18 21:22:50 volumio go-librespot[8471]: time="2026-02-18T21:22:50+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 21:22:50 volumio go-librespot[8471]: time="2026-02-18T21:22:50+07:00" level=debug msg="app state loaded" Feb 18 21:22:50 volumio go-librespot[8471]: time="2026-02-18T21:22:50+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 21:22:50 volumio volumio[8130]: info: Initializing connection to go-librespot Websocket Feb 18 21:22:50 volumio go-librespot[8471]: time="2026-02-18T21:22:50+07:00" level=debug msg="new websocket client" Feb 18 21:22:50 volumio volumio[8130]: info: Connection to go-librespot Websocket established Feb 18 21:22:50 volumio go-librespot[8471]: time="2026-02-18T21:22:50+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 18 21:22:50 volumio go-librespot[8471]: time="2026-02-18T21:22:50+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 18 21:22:50 volumio go-librespot[8471]: time="2026-02-18T21:22:50+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 18 21:22:50 volumio go-librespot[8471]: time="2026-02-18T21:22:50+07:00" level=info msg="zeroconf server listening on port 40221" Feb 18 21:22:50 volumio volumio[8130]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 18 21:22:50 volumio volumio[8130]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 18 21:22:50 volumio volumio[8130]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 18 21:22:50 volumio volumio[8130]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 18 21:22:50 volumio volumio[8130]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 18 21:22:50 volumio volumio[8130]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 18 21:22:50 volumio volumio[8130]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 18 21:22:50 volumio volumio[8130]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 18 21:22:50 volumio volumio[8130]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 18 21:22:50 volumio volumio[8130]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 18 21:22:50 volumio volumio[8130]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 18 21:22:50 volumio volumio[8130]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 18 21:22:50 volumio volumio[8130]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 18 21:22:50 volumio volumio[8130]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 18 21:22:50 volumio volumio[8130]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 18 21:22:50 volumio volumio[8130]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 18 21:22:50 volumio volumio[8130]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 18 21:22:50 volumio volumio[8130]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 18 21:22:50 volumio volumio[8130]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 18 21:22:50 volumio volumio[8130]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 18 21:22:50 volumio volumio[8130]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 18 21:22:50 volumio volumio[8130]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 18 21:22:50 volumio volumio[8130]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 18 21:22:50 volumio volumio[8130]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 18 21:22:50 volumio volumio[8130]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 18 21:22:50 volumio volumio[8130]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 18 21:22:50 volumio volumio[8130]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 18 21:22:50 volumio volumio[8130]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 18 21:22:50 volumio volumio[8130]: info: Adding plugin bluetooth to MyMusic Plugins Feb 18 21:22:50 volumio volumio[8130]: info: Adding plugin multiroom to MyMusic Plugins Feb 18 21:22:50 volumio volumio[8130]: info: Adding plugin metavolumio to MyMusic Plugins Feb 18 21:22:50 volumio volumio[8130]: info: Adding plugin cd_controller to MyMusic Plugins Feb 18 21:22:50 volumio volumio[8130]: info: Adding plugin qobuzconnect to MyMusic Plugins Feb 18 21:22:50 volumio volumio[8130]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 18 21:22:50 volumio volumio[8130]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 18 21:22:50 volumio volumio[8130]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 18 21:22:50 volumio go-librespot[8471]: time="2026-02-18T21:22:50+07:00" level=debug msg="obtained new client token: AAD1bXDeOzAFAI5y+RSPYoPL2v4YZjcE8LNXPwXMEB/p5WgB8kZ5owyQiYutICGFIdn1hodqSv8F8AVnXRFhG3maYZ93RitrTPSXOUt/GRluoENqY79AlI85gcn3fmR+9XCx8qu98nSx9+0Zced0nwbyr66VxclbugKi+zMP4o5pQ4F9Lr6JXbP/4veP3aYWKZ5joQ8aoFEaFU4/BigQevCqTz0UKL120Q5w9P6qpJvA7sWkjqpKaxt+lw==" Feb 18 21:22:50 volumio go-librespot[8471]: time="2026-02-18T21:22:50+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 21:22:51 volumio go-librespot[8471]: time="2026-02-18T21:22:51+07:00" level=debug msg="completed keyexchange" Feb 18 21:22:51 volumio go-librespot[8471]: time="2026-02-18T21:22:51+07:00" level=debug msg="completed challenge" Feb 18 21:22:51 volumio go-librespot[8471]: time="2026-02-18T21:22:51+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 18 21:22:51 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 21:22:51 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 21:22:52 volumio volumio[8130]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 18 21:22:52 volumio volumio[8130]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 18 21:22:52 volumio volumio[8130]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 21:22:52 volumio volumio[8130]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 21:22:52 volumio volumio[8130]: info: Starting MyVolumio Remote Streaming Endpoints Feb 18 21:22:52 volumio volumio[8130]: info: MyVolumio login type: Token Feb 18 21:22:52 volumio volumio[8130]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 18 21:22:52 volumio volumio[8130]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 18 21:22:54 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Feb 18 21:22:54 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 21:22:54 volumio volumio[8130]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 18 21:22:54 volumio volumio[8130]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 18 21:22:54 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 21:22:54 volumio volumio[8130]: info: Streaming services startup Feb 18 21:22:54 volumio go-librespot[8492]: go-librespot daemon starting... Feb 18 21:22:54 volumio volumio[8130]: info: Starting Streaming Daemon Feb 18 21:22:54 volumio go-librespot[8493]: time="2026-02-18T21:22:54+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 21:22:54 volumio go-librespot[8493]: time="2026-02-18T21:22:54+07:00" level=debug msg="app state loaded" Feb 18 21:22:54 volumio go-librespot[8493]: time="2026-02-18T21:22:54+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 21:22:54 volumio volumio[8130]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 18 21:22:54 volumio sudo[8500]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 18 21:22:54 volumio sudo[8500]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 21:22:54 volumio sudo[8500]: pam_unix(sudo:session): session closed for user root Feb 18 21:22:54 volumio volumio[8130]: info: Getting Spotify volume Feb 18 21:22:54 volumio volumio[8130]: info: Connection to go-librespot Websocket closed Feb 18 21:22:54 volumio volumio[8130]: error: Cannot start Volumio Streaming Daemon Feb 18 21:22:54 volumio volumio[8130]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 18 21:22:54 volumio volumio[8130]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 18 21:22:54 volumio volumio[8130]: 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 21:22:54 volumio volumio[8130]: info: CoreCommandRouter::volumioGetState Feb 18 21:22:54 volumio volumio[8130]: info: CorePlayQueue::getTrack 0 Feb 18 21:22:54 volumio volumio[8130]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Feb 18 21:22:54 volumio volumio[8130]: SPOTIFY: SPOTIFY VOLUME undefined Feb 18 21:22:54 volumio volumio[8130]: SPOTIFY: VOLUMIO VOLUME 100 Feb 18 21:22:54 volumio volumio[8130]: info: Aligning Spotify Volume to Volumio Volume Feb 18 21:22:54 volumio volumio[8130]: info: CoreCommandRouter::volumioGetState Feb 18 21:22:54 volumio volumio[8130]: info: CorePlayQueue::getTrack 0 Feb 18 21:22:54 volumio volumio[8130]: info: Setting Spotify Volume from Volumio: 100 Feb 18 21:22:55 volumio go-librespot[8493]: time="2026-02-18T21:22:55+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 18 21:22:55 volumio go-librespot[8493]: time="2026-02-18T21:22:55+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 21:22:55 volumio go-librespot[8493]: time="2026-02-18T21:22:55+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 21:22:55 volumio go-librespot[8493]: time="2026-02-18T21:22:55+07:00" level=info msg="zeroconf server listening on port 43383" Feb 18 21:22:55 volumio go-librespot[8493]: time="2026-02-18T21:22:55+07:00" level=debug msg="obtained new client token: AAAB4wWBR9VnwkR2cayGQOp4RG5j4Zh30EYSAR4laj4Vw3KvGUwsaCN6LUE6/Wrx4nilEqiXkScOijsY0yfN2BhemZWeHKpGbsYKdAXtPZKJycGcgVgxhSp/Su+JWKnICePQ5NE8PaURm9Zj2aWM/C3ojw86iTShlZjbe9x0plZsDEjy/lrg03oPvO3m4YulUBFPz502IPex6gtl/INVhYUW4FzjwWyiUEc3HqqhFhPnXYFXbIBzdYw=" Feb 18 21:22:55 volumio go-librespot[8493]: time="2026-02-18T21:22:55+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 21:22:55 volumio go-librespot[8493]: time="2026-02-18T21:22:55+07:00" level=debug msg="completed keyexchange" Feb 18 21:22:55 volumio go-librespot[8493]: time="2026-02-18T21:22:55+07:00" level=debug msg="completed challenge" Feb 18 21:22:55 volumio go-librespot[8493]: time="2026-02-18T21:22:55+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 18 21:22:55 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 21:22:55 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 21:22:55 volumio volumio[8130]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 18 21:22:55 volumio volumio[8130]: Error: socket hang up Feb 18 21:22:55 volumio volumio[8130]: at connResetException (node:internal/errors:720:14) Feb 18 21:22:55 volumio volumio[8130]: at Socket.socketOnEnd (node:_http_client:519:23) Feb 18 21:22:55 volumio volumio[8130]: at Socket.emit (node:events:526:35) Feb 18 21:22:55 volumio volumio[8130]: at endReadableNT (node:internal/streams/readable:1376:12) Feb 18 21:22:55 volumio volumio[8130]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Feb 18 21:22:55 volumio volumio[8130]: code: 'ECONNRESET', Feb 18 21:22:55 volumio volumio[8130]: response: undefined Feb 18 21:22:55 volumio volumio[8130]: } Feb 18 21:22:55 volumio volumio[8130]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 18 21:22:57 volumio sudo[8522]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-18 21:21' Feb 18 21:22:57 volumio sudo[8522]: 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"