Feb 17 20:55:00 volumio go-librespot[5301]: time="2026-02-17T20:55:00+07:00" level=info msg="zeroconf server listening on port 35445" Feb 17 20:55:00 volumio volumio[5290]: Forking 3 albumart workers Feb 17 20:55:00 volumio volumio[5178]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 17 20:55:00 volumio volumio[5178]: info: CoreCommandRouter::initPlayerControls Feb 17 20:55:00 volumio volumio[5178]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 20:55:00 volumio volumio[5178]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 20:55:00 volumio volumio[5178]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 20:55:00 volumio volumio[5178]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 20:55:00 volumio volumio[5178]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 20:55:00 volumio volumio[5178]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 20:55:00 volumio volumio[5178]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 20:55:00 volumio volumio[5178]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 20:55:00 volumio volumio[5178]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 17 20:55:00 volumio volumio[5178]: Express server listening on port 3000 Feb 17 20:55:00 volumio volumio[5178]: [Metrics] WebUI: 16s 84.16ms Feb 17 20:55:00 volumio volumio[5178]: info: CoreStateMachine::resetVolumioState Feb 17 20:55:00 volumio volumio[5178]: info: CoreStateMachine::getcurrentVolume Feb 17 20:55:00 volumio volumio[5178]: info: CoreCommandRouter::volumioRetrievevolume Feb 17 20:55:00 volumio go-librespot[5301]: time="2026-02-17T20:55:00+07:00" level=debug msg="obtained new client token: AAAtJUJhbvFdWOyjgbF7qZAfgwO+gNPdq0HxlBKytYKZHXMdxjJqfNZXPwWlQZ6xXlR/KDBL4CMUN9ijXps6jBJqaKEu/d7yX7jUtNq8OYrlspn729HqhFvwtrwrPRnOGWkaDJE1Sqc7HV0mBh/9k7h156vjL7NwD5Ev0SFHQheZrV+JkM2O1QVok99eBZUfyqW2qdBf7o5B8PBGjhCRxVQLE88pA4cKV51yABbGcKX2eLmPgrpTtNc=" Feb 17 20:55:00 volumio go-librespot[5301]: time="2026-02-17T20:55:00+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 17 20:55:00 volumio sudo[5343]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 17 20:55:00 volumio sudo[5343]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 20:55:00 volumio sudo[5343]: pam_unix(sudo:session): session closed for user root Feb 17 20:55:00 volumio go-librespot[5301]: time="2026-02-17T20:55:00+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 17 20:55:00 volumio sudo[5346]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 17 20:55:00 volumio sudo[5346]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 20:55:00 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 20:55:00 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 20:55:00 volumio sudo[5346]: pam_unix(sudo:session): session closed for user root Feb 17 20:55:00 volumio volumio[5178]: info: Volumio Network Manager: Network status updated: 1 Feb 17 20:55:00 volumio volumio[5178]: info: VolumeController:: Volume=100 Mute =false Feb 17 20:55:00 volumio volumio[5178]: info: CoreStateMachine::pushState Feb 17 20:55:00 volumio volumio[5178]: info: CorePlayQueue::getTrack 0 Feb 17 20:55:00 volumio volumio[5178]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 17 20:55:00 volumio volumio[5178]: info: CoreCommandRouter::volumioPushState Feb 17 20:55:00 volumio volumio[5178]: info: CoreStateMachine::updateTrackBlock Feb 17 20:55:00 volumio volumio[5178]: info: CorePlayQueue::getTrackBlock Feb 17 20:55:00 volumio volumio[5178]: info: CoreCommandRouter::volumioRetrievevolume Feb 17 20:55:00 volumio volumio-remote-updater[25144]: [2026-02-17 20:55:00] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1771336498 101 Feb 17 20:55:00 volumio volumio[5178]: 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 17 20:55:00 volumio volumio[5178]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 20:55:00 volumio volumio[5178]: info: Reloading queue from file Feb 17 20:55:01 volumio volumio[5178]: info: CoreStateMachine::setRepeat null single undefined Feb 17 20:55:01 volumio volumio[5178]: info: CoreStateMachine::pushState Feb 17 20:55:01 volumio volumio[5178]: info: CorePlayQueue::getTrack 0 Feb 17 20:55:01 volumio volumio[5178]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 17 20:55:01 volumio volumio[5178]: info: CoreCommandRouter::volumioPushState Feb 17 20:55:01 volumio volumio[5178]: info: CoreStateMachine::setRandom null Feb 17 20:55:01 volumio volumio[5178]: info: CoreStateMachine::pushState Feb 17 20:55:01 volumio volumio[5178]: info: CorePlayQueue::getTrack 0 Feb 17 20:55:01 volumio volumio[5178]: info: CoreCommandRouter::volumioPushState Feb 17 20:55:01 volumio volumio[5178]: info: Setting Device type: Raspberry PI Feb 17 20:55:01 volumio volumio[5178]: info: Completed loading Core Plugins Feb 17 20:55:01 volumio volumio[5178]: info: Preparing to generate the ALSA configuration file Feb 17 20:55:01 volumio volumio[5178]: info: VolumeController:: Volume=100 Mute =false Feb 17 20:55:01 volumio volumio[5178]: info: CoreStateMachine::pushState Feb 17 20:55:01 volumio volumio[5178]: info: CorePlayQueue::getTrack 0 Feb 17 20:55:01 volumio volumio[5178]: info: CoreCommandRouter::volumioPushState Feb 17 20:55:01 volumio volumio[5178]: info: Asound.conf file unchanged, so no further update is needed Feb 17 20:55:01 volumio volumio[5178]: info: Output device has changed, restarting MPD Feb 17 20:55:01 volumio volumio[5178]: info: Output device has changed, restarting Shairport Sync Feb 17 20:55:01 volumio volumio[5178]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 20:55:01 volumio volumio[5178]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 20:55:01 volumio sudo[5360]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 17 20:55:01 volumio sudo[5360]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 20:55:01 volumio sudo[5362]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 17 20:55:01 volumio sudo[5362]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 20:55:01 volumio sudo[5364]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 17 20:55:01 volumio sudo[5364]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 20:55:01 volumio volumio[5178]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 17 20:55:01 volumio sudo[5362]: pam_unix(sudo:session): session closed for user root Feb 17 20:55:01 volumio volumio[5178]: info: ___________ START PLUGINS ___________ Feb 17 20:55:01 volumio volumio[5178]: info: ControllerMpd::onStart: Initializing MPD Feb 17 20:55:01 volumio volumio[5178]: info: Creating MPD Configuration file Feb 17 20:55:01 volumio sudo[5360]: pam_unix(sudo:session): session closed for user root Feb 17 20:55:01 volumio volumio[5178]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 17 20:55:01 volumio volumio[5178]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 17 20:55:01 volumio volumio[5178]: info: [1771336501521] CoreMusicLibrary::Adding element Media Servers Feb 17 20:55:01 volumio volumio[5178]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 17 20:55:01 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 17 20:55:01 volumio sudo[5375]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 17 20:55:01 volumio sudo[5375]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 20:55:01 volumio sudo[5373]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 17 20:55:01 volumio sudo[5373]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 20:55:01 volumio volumio[5178]: info: UPNP Browser: Client initialized successfully Feb 17 20:55:01 volumio sudo[5373]: pam_unix(sudo:session): session closed for user root Feb 17 20:55:01 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 17 20:55:01 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 17 20:55:01 volumio systemd[1]: mpd.service: Consumed 7.199s CPU time. Feb 17 20:55:01 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 17 20:55:01 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 17 20:55:01 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 17 20:55:01 volumio volumio[5178]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 20:55:01 volumio volumio[5178]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 20:55:01 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 17 20:55:01 volumio volumio[5178]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 17 20:55:01 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 17 20:55:01 volumio volumio[5178]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 20:55:01 volumio volumio[5178]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 20:55:01 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 17 20:55:01 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 17 20:55:01 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 17 20:55:01 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 17 20:55:01 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 17 20:55:01 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 17 20:55:01 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 17 20:55:01 volumio volumio[5178]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 17 20:55:01 volumio volumio[5178]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 17 20:55:01 volumio volumio[5178]: info: [1771336501935] CoreMusicLibrary::Adding element Last_100 Feb 17 20:55:01 volumio volumio[5178]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 17 20:55:01 volumio volumio[5178]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 17 20:55:01 volumio volumio[5178]: info: [1771336501949] CoreMusicLibrary::Adding element Webradio Feb 17 20:55:01 volumio volumio[5178]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 17 20:55:01 volumio volumio[5178]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 17 20:55:01 volumio volumio[5178]: info: Initializing BBC Radios Feb 17 20:55:02 volumio volumio[5178]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 17 20:55:02 volumio volumio[5178]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 20:55:02 volumio volumio[5178]: info: Creating Spotify config file Feb 17 20:55:02 volumio volumio[5178]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 20:55:02 volumio sudo[5389]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 17 20:55:02 volumio sudo[5389]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 17 20:55:02 volumio sudo[5389]: pam_unix(sudo:session): session closed for user root Feb 17 20:55:03 volumio volumio[5312]: Starting albumart workers Feb 17 20:55:03 volumio volumio[5178]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 17 20:55:03 volumio volumio[5178]: info: [1771336503335] CoreMusicLibrary::Adding element YouTube Music Feb 17 20:55:03 volumio volumio[5178]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 17 20:55:03 volumio volumio[5178]: Cannot find translation for source YouTube Music Feb 17 20:55:03 volumio volumio[5178]: info: Volumio Calling Home Feb 17 20:55:03 volumio sudo[5406]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Feb 17 20:55:03 volumio sudo[5406]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 20:55:03 volumio volumio[5310]: Starting albumart workers Feb 17 20:55:03 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Feb 17 20:55:03 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 20:55:03 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 20:55:03 volumio go-librespot[5411]: go-librespot daemon starting... Feb 17 20:55:03 volumio sudo[5406]: pam_unix(sudo:session): session closed for user root Feb 17 20:55:03 volumio go-librespot[5412]: time="2026-02-17T20:55:03+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 20:55:03 volumio volumio[5311]: Starting albumart workers Feb 17 20:55:04 volumio volumio[5178]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Feb 17 20:55:04 volumio volumio[5178]: info: Discovery: Found device Volumio Feb 17 20:55:04 volumio volumio[5178]: info: CoreCommandRouter::volumioGetState Feb 17 20:55:04 volumio volumio[5178]: info: CorePlayQueue::getTrack 0 Feb 17 20:55:04 volumio volumio[5178]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Feb 17 20:55:04 volumio volumio[5178]: info: Discovery: Found device Volumio Feb 17 20:55:04 volumio volumio[5178]: info: CoreCommandRouter::volumioGetState Feb 17 20:55:04 volumio volumio[5178]: info: CorePlayQueue::getTrack 0 Feb 17 20:55:04 volumio volumio[5178]: info: MPD Permissions set Feb 17 20:55:04 volumio volumio[5178]: info: MPD Permissions set Feb 17 20:55:04 volumio volumio[5178]: info: Upmpdcli Daemon Started Feb 17 20:55:04 volumio volumio[5178]: info: Spotify config file written Feb 17 20:55:04 volumio sudo[5420]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 17 20:55:04 volumio sudo[5420]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 20:55:04 volumio go-librespot[5412]: time="2026-02-17T20:55:04+07:00" level=info msg="zeroconf server listening on port 36005" Feb 17 20:55:04 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Feb 17 20:55:04 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Feb 17 20:55:04 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 20:55:04 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 20:55:04 volumio volumio[5178]: 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 17 20:55:04 volumio go-librespot[5422]: go-librespot daemon starting... Feb 17 20:55:04 volumio volumio[5178]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 20:55:04 volumio sudo[5420]: pam_unix(sudo:session): session closed for user root Feb 17 20:55:04 volumio volumio[5178]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 20:55:04 volumio volumio[5178]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 20:55:04 volumio volumio[5178]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 20:55:04 volumio volumio[5178]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 20:55:04 volumio volumio[5178]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 20:55:04 volumio volumio[5178]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 20:55:04 volumio volumio[5178]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 20:55:05 volumio go-librespot[5423]: time="2026-02-17T20:55:05+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 20:55:05 volumio go-librespot[5423]: time="2026-02-17T20:55:05+07:00" level=debug msg="app state loaded" Feb 17 20:55:05 volumio go-librespot[5423]: time="2026-02-17T20:55:05+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 20:55:05 volumio volumio[5178]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 20:55:05 volumio volumio[5178]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 20:55:05 volumio volumio[5178]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 20:55:05 volumio volumio[5178]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 20:55:05 volumio volumio[5178]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 20:55:05 volumio volumio[5178]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 20:55:05 volumio volumio[5178]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 20:55:05 volumio volumio[5178]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 20:55:05 volumio volumio[5178]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 20:55:05 volumio volumio[5178]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 20:55:05 volumio volumio[5178]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 20:55:05 volumio volumio[5178]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 20:55:05 volumio volumio[5178]: info: No need to fix Spotify hosts Feb 17 20:55:05 volumio go-librespot[5423]: time="2026-02-17T20:55:05+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 17 20:55:05 volumio go-librespot[5423]: time="2026-02-17T20:55:05+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 17 20:55:05 volumio go-librespot[5423]: time="2026-02-17T20:55:05+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 17 20:55:05 volumio go-librespot[5423]: time="2026-02-17T20:55:05+07:00" level=info msg="zeroconf server listening on port 40657" Feb 17 20:55:06 volumio volumio[5178]: info: Volumio called home Feb 17 20:55:06 volumio go-librespot[5423]: time="2026-02-17T20:55:06+07:00" level=debug msg="obtained new client token: AABqnXU11LgrYw9qgRSolpXChtBV+/evQ2viubi6TVgvZ5a1ELCYkvlVul9p3EV/WypznsDPWi7gyL4p5+In7aYMhSF1zA1AKQe1qHAj7LpydEutGjvAIAGTfZyt1FPhpiFGe6bApmN3zdgMCzH7fCFyVpZFIHuSGMmZN9Nxc+2WR4UgDTOdaDMMWGK3rzdMk0wqCzXHuOmXtDKOpZQXihen6LDkbeB/BQHnHpMw8fuHTW2l3KioTUS78w==" Feb 17 20:55:06 volumio go-librespot[5423]: time="2026-02-17T20:55:06+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 17 20:55:06 volumio volumio[5178]: info: Starting Shairport Sync Feb 17 20:55:06 volumio go-librespot[5423]: time="2026-02-17T20:55:06+07:00" level=debug msg="completed keyexchange" Feb 17 20:55:06 volumio go-librespot[5423]: time="2026-02-17T20:55:06+07:00" level=debug msg="completed challenge" Feb 17 20:55:06 volumio volumio[5178]: info: Starting Shairport Sync Feb 17 20:55:06 volumio volumio[5178]: info: Starting Shairport Sync Feb 17 20:55:06 volumio go-librespot[5423]: time="2026-02-17T20:55: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 17 20:55:06 volumio sudo[5456]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 17 20:55:06 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 20:55:06 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 20:55:06 volumio sudo[5456]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 20:55:06 volumio volumio[5178]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 17 20:55:06 volumio volumio[5178]: SPOTIFY: BQBM0l1d1BlOTUxbHX2BhdxLhNMwJAT-WPDhvOLOxhQtWDqKNNkYuC0nU4Q7sasCloXIrpZAN7K4ZXSca5G7KViWCMQtFvrAM0uCvdUhns9NGmvS4B1ncQ1xLO03CIudmZyr_hKiYhQVTq_PYD2f4aOk8adkmxRmekVpDsrwUQav2CWGNbskzXdU3WloWbyavtiDiIgqLFL2taLRSjrinOC7BUkqXEElNxWvWUbg0LLkuz0zhnrBD2j-1EOsba6NIxaRiiZ73mzpuBERjXu2iQI3PkBarevOWk6l4TxC0SIm1BPq6-PDPfNL Feb 17 20:55:06 volumio volumio[5178]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 17 20:55:06 volumio volumio[5178]: info: New Spotify access token = BQBM0l1d1BlOTUxbHX2BhdxLhNMwJAT-WPDhvOLOxhQtWDqKNNkYuC0nU4Q7sasCloXIrpZAN7K4ZXSca5G7KViWCMQtFvrAM0uCvdUhns9NGmvS4B1ncQ1xLO03CIudmZyr_hKiYhQVTq_PYD2f4aOk8adkmxRmekVpDsrwUQav2CWGNbskzXdU3WloWbyavtiDiIgqLFL2taLRSjrinOC7BUkqXEElNxWvWUbg0LLkuz0zhnrBD2j-1EOsba6NIxaRiiZ73mzpuBERjXu2iQI3PkBarevOWk6l4TxC0SIm1BPq6-PDPfNL Feb 17 20:55:06 volumio volumio[5178]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 17 20:55:06 volumio sudo[5461]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 17 20:55:06 volumio sudo[5463]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 17 20:55:06 volumio sudo[5461]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 20:55:06 volumio sudo[5463]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 20:55:06 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 17 20:55:06 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 17 20:55:06 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 17 20:55:06 volumio systemd[1]: shairport-sync.service: Consumed 2.350s CPU time. Feb 17 20:55:06 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 17 20:55:06 volumio sudo[5456]: pam_unix(sudo:session): session closed for user root Feb 17 20:55:06 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 17 20:55:06 volumio sudo[5463]: pam_unix(sudo:session): session closed for user root Feb 17 20:55:06 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 17 20:55:06 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 17 20:55:06 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 17 20:55:06 volumio sudo[5461]: pam_unix(sudo:session): session closed for user root Feb 17 20:55:06 volumio volumio[5178]: info: Shairport-Sync Started Feb 17 20:55:06 volumio volumio[5178]: Error adding Membership: Error: addMembership EINVAL Feb 17 20:55:06 volumio volumio[5178]: info: Shairport-Sync Started Feb 17 20:55:06 volumio volumio[5178]: info: Shairport-Sync Started Feb 17 20:55:06 volumio volumio[5178]: info: CoreCommandRouter::volumioGetState Feb 17 20:55:06 volumio volumio[5178]: info: CorePlayQueue::getTrack 0 Feb 17 20:55:07 volumio volumio[5178]: 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 17 20:55:07 volumio volumio[5178]: info: Spotify Successfully logged in Feb 17 20:55:07 volumio volumio[5178]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 17 20:55:07 volumio volumio[5178]: info: [1771336507245] CoreMusicLibrary::Adding element Spotify Feb 17 20:55:07 volumio volumio[5178]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 17 20:55:07 volumio volumio[5178]: Cannot find translation for source YouTube Music Feb 17 20:55:07 volumio volumio[5178]: Cannot find translation for source Spotify Feb 17 20:55:07 volumio volumio[5178]: info: [yt-cast-receiver] DIAL server listening on port 8098 Feb 17 20:55:07 volumio volumio[5178]: info: CoreCommandRouter::volumioRetrievevolume Feb 17 20:55:08 volumio volumio[5178]: info: VolumeController:: Volume=100 Mute =false Feb 17 20:55:08 volumio volumio[5178]: info: CoreCommandRouter::volumioGetState Feb 17 20:55:08 volumio volumio[5178]: info: CorePlayQueue::getTrack 0 Feb 17 20:55:08 volumio volumio[5178]: info: CoreStateMachine::pushState Feb 17 20:55:08 volumio volumio[5178]: info: CorePlayQueue::getTrack 0 Feb 17 20:55:08 volumio volumio[5178]: info: CoreCommandRouter::volumioPushState Feb 17 20:55:09 volumio volumio[5178]: info: go-librespot daemon successfully initialized Feb 17 20:55:09 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Feb 17 20:55:09 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 20:55:09 volumio mpd[5404]: 2026-02-17T20:55:09 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 17 20:55:09 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 20:55:09 volumio go-librespot[5502]: go-librespot daemon starting... Feb 17 20:55:09 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 17 20:55:09 volumio sudo[5364]: pam_unix(sudo:session): session closed for user root Feb 17 20:55:09 volumio sudo[5375]: pam_unix(sudo:session): session closed for user root Feb 17 20:55:09 volumio go-librespot[5503]: time="2026-02-17T20:55:09+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 20:55:09 volumio go-librespot[5503]: time="2026-02-17T20:55:09+07:00" level=debug msg="app state loaded" Feb 17 20:55:09 volumio go-librespot[5503]: time="2026-02-17T20:55:09+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 20:55:09 volumio volumio[5178]: error: MPD error: The expression evaluated to a falsy value: Feb 17 20:55:09 volumio volumio[5178]: assert.ok(self.idling) Feb 17 20:55:09 volumio volumio[5178]: error: The expression evaluated to a falsy value: Feb 17 20:55:09 volumio volumio[5178]: assert.ok(self.idling) Feb 17 20:55:09 volumio volumio[5178]: info: MPD running with PID5404 Feb 17 20:55:09 volumio volumio[5178]: ,establishing connection Feb 17 20:55:09 volumio volumio[5178]: error: updateQueue error: null Feb 17 20:55:10 volumio volumio[5178]: info: Completed starting Core Plugins Feb 17 20:55:10 volumio volumio[5178]: info: ------------------------------------------- Feb 17 20:55:10 volumio volumio[5178]: info: ----- MyVolumio plugins startup ---- Feb 17 20:55:10 volumio volumio[5178]: info: ------------------------------------------- Feb 17 20:55:10 volumio volumio[5178]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 17 20:55:10 volumio volumio[5178]: error: updateQueue error: null Feb 17 20:55:10 volumio go-librespot[5503]: time="2026-02-17T20:55:10+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 17 20:55:10 volumio go-librespot[5503]: time="2026-02-17T20:55:10+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 17 20:55:10 volumio go-librespot[5503]: time="2026-02-17T20:55:10+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 17 20:55:10 volumio go-librespot[5503]: time="2026-02-17T20:55:10+07:00" level=info msg="zeroconf server listening on port 42995" Feb 17 20:55:10 volumio go-librespot[5503]: time="2026-02-17T20:55:10+07:00" level=debug msg="obtained new client token: AAB0ke3K+xugLv4jL3u46tpHhSb89dciI6C27b3MHCJybHNWiWG2NL4X7TW1v5bnpCQyH6mu6kzI8EvooDlfGSDPTYL6yOI5yU2OWDA7Cfy4JP3/Vk7jZbSlDr8q/rdbK6Dsp14I5kVFJJ8gdARCaDDbmU8sj/ZcBbpX7gIkcD6HO2JPxSra0pTqeGHASiw2yQnLyH4JhDZ/ICCnM/aRIwInjd9k7BUco4sKDS+3+HtDWwi6nJnp0B5wCw==" Feb 17 20:55:10 volumio go-librespot[5503]: time="2026-02-17T20:55:10+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 17 20:55:10 volumio go-librespot[5503]: time="2026-02-17T20:55:10+07:00" level=debug msg="completed keyexchange" Feb 17 20:55:10 volumio go-librespot[5503]: time="2026-02-17T20:55:10+07:00" level=debug msg="completed challenge" Feb 17 20:55:10 volumio go-librespot[5503]: time="2026-02-17T20:55: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 17 20:55:10 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 20:55:10 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 20:55:12 volumio volumio[5178]: info: Initializing connection to go-librespot Websocket Feb 17 20:55:12 volumio volumio[5178]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 17 20:55:13 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Feb 17 20:55:13 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 20:55:13 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 20:55:13 volumio go-librespot[5515]: go-librespot daemon starting... Feb 17 20:55:13 volumio go-librespot[5516]: time="2026-02-17T20:55:13+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 20:55:13 volumio go-librespot[5516]: time="2026-02-17T20:55:13+07:00" level=debug msg="app state loaded" Feb 17 20:55:13 volumio go-librespot[5516]: time="2026-02-17T20:55:13+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 20:55:14 volumio go-librespot[5516]: time="2026-02-17T20:55:14+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 17 20:55:14 volumio go-librespot[5516]: time="2026-02-17T20:55:14+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 17 20:55:14 volumio go-librespot[5516]: time="2026-02-17T20:55:14+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 17 20:55:14 volumio go-librespot[5516]: time="2026-02-17T20:55:14+07:00" level=info msg="zeroconf server listening on port 34129" Feb 17 20:55:14 volumio go-librespot[5516]: time="2026-02-17T20:55:14+07:00" level=debug msg="obtained new client token: AAAi1TllTuiUEQRUOGvl/iJhwVGm8zNxSoKMDoX3GpZvuxpKD/fkmuzOisb3p1XtKEiOTId6LwQyieD66mHb/9h7EI6SsmG1FOE0PET4ze12DdnID+QlGa0L+kXj2qM+V1ItiFJnbGR3p7YuueAdvZ1NUs3X9Efwu+0RUclD91w7Tfzk/w6k6Tj4AzFTUH1ETLWbk7JJdpeI5A0+GRVjG1F8ue3jU6cOuplSPEA9fgAUr4gPB59DvVqb7w==" Feb 17 20:55:14 volumio go-librespot[5516]: time="2026-02-17T20:55:14+07:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:4070, retrying with a different AP" error="dial tcp 104.199.241.202:4070: connect: connection refused" Feb 17 20:55:14 volumio volumio[5178]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 17 20:55:14 volumio go-librespot[5516]: time="2026-02-17T20:55:14+07:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:443, retrying with a different AP" error="dial tcp 104.199.241.202:443: connect: connection refused" Feb 17 20:55:14 volumio go-librespot[5516]: time="2026-02-17T20:55:14+07:00" level=debug msg="connected to ap-gae2.spotify.com:80" Feb 17 20:55:14 volumio go-librespot[5516]: time="2026-02-17T20:55:14+07:00" level=debug msg="completed keyexchange" Feb 17 20:55:14 volumio go-librespot[5516]: time="2026-02-17T20:55:14+07:00" level=debug msg="completed challenge" Feb 17 20:55:14 volumio go-librespot[5516]: time="2026-02-17T20:55:14+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 17 20:55:14 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 20:55:14 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 20:55:15 volumio volumio[5178]: info: Initializing connection to go-librespot Websocket Feb 17 20:55:15 volumio volumio[5178]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 17 20:55:18 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Feb 17 20:55:18 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 20:55:18 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 20:55:18 volumio go-librespot[5523]: go-librespot daemon starting... Feb 17 20:55:18 volumio go-librespot[5524]: time="2026-02-17T20:55:18+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 20:55:18 volumio go-librespot[5524]: time="2026-02-17T20:55:18+07:00" level=debug msg="app state loaded" Feb 17 20:55:18 volumio go-librespot[5524]: time="2026-02-17T20:55:18+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 20:55:18 volumio volumio[5178]: info: Initializing connection to go-librespot Websocket Feb 17 20:55:18 volumio go-librespot[5524]: time="2026-02-17T20:55:18+07:00" level=debug msg="new websocket client" Feb 17 20:55:18 volumio volumio[5178]: info: Connection to go-librespot Websocket established Feb 17 20:55:18 volumio go-librespot[5524]: time="2026-02-17T20:55:18+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 17 20:55:18 volumio go-librespot[5524]: time="2026-02-17T20:55:18+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 17 20:55:18 volumio go-librespot[5524]: time="2026-02-17T20:55:18+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 17 20:55:18 volumio go-librespot[5524]: time="2026-02-17T20:55:18+07:00" level=info msg="zeroconf server listening on port 33195" Feb 17 20:55:18 volumio volumio[5178]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 17 20:55:18 volumio volumio[5178]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 17 20:55:18 volumio volumio[5178]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 17 20:55:18 volumio volumio[5178]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 17 20:55:18 volumio volumio[5178]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 17 20:55:18 volumio volumio[5178]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 17 20:55:18 volumio volumio[5178]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 17 20:55:18 volumio volumio[5178]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 17 20:55:18 volumio volumio[5178]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 17 20:55:18 volumio volumio[5178]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 17 20:55:18 volumio volumio[5178]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 17 20:55:18 volumio volumio[5178]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 17 20:55:18 volumio volumio[5178]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 17 20:55:18 volumio volumio[5178]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 17 20:55:18 volumio volumio[5178]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 17 20:55:18 volumio volumio[5178]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 17 20:55:18 volumio volumio[5178]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 17 20:55:18 volumio volumio[5178]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 17 20:55:18 volumio volumio[5178]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 17 20:55:18 volumio volumio[5178]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 17 20:55:18 volumio volumio[5178]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 17 20:55:18 volumio volumio[5178]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 17 20:55:18 volumio volumio[5178]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 17 20:55:18 volumio volumio[5178]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 17 20:55:18 volumio volumio[5178]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 17 20:55:18 volumio volumio[5178]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 17 20:55:18 volumio volumio[5178]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 17 20:55:18 volumio volumio[5178]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 17 20:55:18 volumio volumio[5178]: info: Adding plugin bluetooth to MyMusic Plugins Feb 17 20:55:18 volumio volumio[5178]: info: Adding plugin multiroom to MyMusic Plugins Feb 17 20:55:18 volumio volumio[5178]: info: Adding plugin metavolumio to MyMusic Plugins Feb 17 20:55:18 volumio volumio[5178]: info: Adding plugin cd_controller to MyMusic Plugins Feb 17 20:55:18 volumio volumio[5178]: info: Adding plugin qobuzconnect to MyMusic Plugins Feb 17 20:55:18 volumio volumio[5178]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 17 20:55:18 volumio volumio[5178]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 17 20:55:18 volumio volumio[5178]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 17 20:55:18 volumio go-librespot[5524]: time="2026-02-17T20:55:18+07:00" level=debug msg="obtained new client token: AADj8s+b5N6glKalYTf3SBAUo/xjkt9pFE2wnUdD1A6kHnVC2LJbiS8tbv3/gr/+/BxtZ+73sApBe6giSabBSAXmtbPoGVbHPGh7oq8QrfLRk9Ea+2i7BQ0tN+lOLY+wJRYafqnSFW3KNj1wTOAJY2RI19/o3YO5/xfnST9vGsoPQjo3dUtrwOH9mKO5PSnEyr5vCW9kTfKp10KaO7X6Fi+jgSR0kT1eWbCI5w/HL6ehU/HoMBoFJVXDKA==" Feb 17 20:55:19 volumio go-librespot[5524]: time="2026-02-17T20:55:19+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 17 20:55:19 volumio go-librespot[5524]: time="2026-02-17T20:55:19+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 17 20:55:19 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 20:55:19 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 20:55:20 volumio volumio[5178]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 17 20:55:20 volumio volumio[5178]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 17 20:55:20 volumio volumio[5178]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 20:55:20 volumio volumio[5178]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 20:55:20 volumio volumio[5178]: info: Starting MyVolumio Remote Streaming Endpoints Feb 17 20:55:20 volumio volumio[5178]: info: MyVolumio login type: Token Feb 17 20:55:20 volumio volumio[5178]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 17 20:55:20 volumio volumio[5178]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 17 20:55:22 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Feb 17 20:55:22 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 20:55:22 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 20:55:22 volumio go-librespot[5547]: go-librespot daemon starting... Feb 17 20:55:22 volumio go-librespot[5548]: time="2026-02-17T20:55:22+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 20:55:22 volumio go-librespot[5548]: time="2026-02-17T20:55:22+07:00" level=debug msg="app state loaded" Feb 17 20:55:22 volumio go-librespot[5548]: time="2026-02-17T20:55:22+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 20:55:22 volumio volumio[5178]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 17 20:55:22 volumio volumio[5178]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 17 20:55:22 volumio volumio[5178]: info: Streaming services startup Feb 17 20:55:22 volumio volumio[5178]: info: Starting Streaming Daemon Feb 17 20:55:22 volumio sudo[5556]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 17 20:55:22 volumio sudo[5556]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 20:55:22 volumio volumio[5178]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 17 20:55:22 volumio sudo[5556]: pam_unix(sudo:session): session closed for user root Feb 17 20:55:22 volumio volumio[5178]: info: Getting Spotify volume Feb 17 20:55:22 volumio volumio[5178]: info: Connection to go-librespot Websocket closed Feb 17 20:55:22 volumio volumio[5178]: error: Cannot start Volumio Streaming Daemon Feb 17 20:55:22 volumio volumio[5178]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 17 20:55:22 volumio volumio[5178]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 17 20:55:22 volumio volumio[5178]: 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 17 20:55:22 volumio volumio[5178]: info: CoreCommandRouter::volumioGetState Feb 17 20:55:22 volumio volumio[5178]: info: CorePlayQueue::getTrack 0 Feb 17 20:55:23 volumio go-librespot[5548]: time="2026-02-17T20:55: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-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 17 20:55:23 volumio go-librespot[5548]: time="2026-02-17T20:55:23+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 17 20:55:23 volumio go-librespot[5548]: time="2026-02-17T20:55:23+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 17 20:55:23 volumio volumio[5178]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Feb 17 20:55:23 volumio volumio[5178]: SPOTIFY: SPOTIFY VOLUME undefined Feb 17 20:55:23 volumio volumio[5178]: SPOTIFY: VOLUMIO VOLUME 100 Feb 17 20:55:23 volumio volumio[5178]: info: Aligning Spotify Volume to Volumio Volume Feb 17 20:55:23 volumio volumio[5178]: info: CoreCommandRouter::volumioGetState Feb 17 20:55:23 volumio volumio[5178]: info: CorePlayQueue::getTrack 0 Feb 17 20:55:23 volumio volumio[5178]: info: Setting Spotify Volume from Volumio: 100 Feb 17 20:55:23 volumio go-librespot[5548]: time="2026-02-17T20:55:23+07:00" level=info msg="zeroconf server listening on port 40303" Feb 17 20:55:23 volumio go-librespot[5548]: time="2026-02-17T20:55:23+07:00" level=debug msg="obtained new client token: AACrVeydRa+tysunqTH8/bKL+rNdZWBC8R3LASyTC7ZT+VHmNhxJQBScp/7REs3/v02z49JZx4CNojX6MrwMDlo+UGkN/20aHQwn9wRhKVB1sFfsQhM62ajAoQaP3q+pPOq3s9X5nUiB4dx+dJ+2I04nPpguqOByywx0kOtZd1uSILK0XSBNt90KcZW18TFH3jHDDA3e/lgZgOZaY9J7NNXRfdCoy3QTG9ltfvPoUH/BSnDTut1djR0=" Feb 17 20:55:23 volumio go-librespot[5548]: time="2026-02-17T20:55:23+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 17 20:55:23 volumio go-librespot[5548]: time="2026-02-17T20:55:23+07:00" level=debug msg="completed keyexchange" Feb 17 20:55:23 volumio go-librespot[5548]: time="2026-02-17T20:55:23+07:00" level=debug msg="completed challenge" Feb 17 20:55:23 volumio go-librespot[5548]: time="2026-02-17T20:55:23+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 17 20:55:23 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 20:55:23 volumio volumio[5178]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 17 20:55:23 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 20:55:23 volumio volumio[5178]: Error: socket hang up Feb 17 20:55:23 volumio volumio[5178]: at connResetException (node:internal/errors:720:14) Feb 17 20:55:23 volumio volumio[5178]: at Socket.socketOnEnd (node:_http_client:519:23) Feb 17 20:55:23 volumio volumio[5178]: at Socket.emit (node:events:526:35) Feb 17 20:55:23 volumio volumio[5178]: at endReadableNT (node:internal/streams/readable:1376:12) Feb 17 20:55:23 volumio volumio[5178]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Feb 17 20:55:23 volumio volumio[5178]: code: 'ECONNRESET', Feb 17 20:55:23 volumio volumio[5178]: response: undefined Feb 17 20:55:23 volumio volumio[5178]: } Feb 17 20:55:23 volumio volumio[5178]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 17 20:55:24 volumio sudo[5576]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-17 20:54' Feb 17 20:55:24 volumio sudo[5576]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 20:55:25 volumio sudo[5576]: pam_unix(sudo:session): session closed for user root Feb 17 20:55:25 volumio volumio-remote-updater[25144]: [2026-02-17 20:55:25] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Feb 17 20:55:25 volumio volumio-remote-updater[25144]: [2026-02-17 20:55:25] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Feb 17 20:55:25 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Feb 17 20:55:25 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Feb 17 20:55:25 volumio systemd[1]: volumio.service: Consumed 55.510s CPU time. Feb 17 20:55:25 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 17 20:55:25 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 17 20:55:25 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 20873. Feb 17 20:55:25 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 17 20:55:25 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Feb 17 20:55:25 volumio systemd[1]: volumio.service: Consumed 55.510s CPU time. Feb 17 20:55:25 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Feb 17 20:55:25 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 17 20:55:26 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Feb 17 20:55:26 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 20:55:26 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 20:55:26 volumio go-librespot[5605]: go-librespot daemon starting... Feb 17 20:55:26 volumio go-librespot[5606]: time="2026-02-17T20:55:26+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 20:55:26 volumio go-librespot[5606]: time="2026-02-17T20:55:26+07:00" level=debug msg="app state loaded" Feb 17 20:55:26 volumio go-librespot[5606]: time="2026-02-17T20:55:26+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 20:55:27 volumio go-librespot[5606]: time="2026-02-17T20:55: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 17 20:55:27 volumio go-librespot[5606]: time="2026-02-17T20:55: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 17 20:55:27 volumio go-librespot[5606]: time="2026-02-17T20:55: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 17 20:55:27 volumio go-librespot[5606]: time="2026-02-17T20:55:27+07:00" level=info msg="zeroconf server listening on port 39835" Feb 17 20:55:27 volumio go-librespot[5606]: time="2026-02-17T20:55:27+07:00" level=debug msg="obtained new client token: AACTvJ25AFjDy/5DeCfUST16hJY21N7mjxDQZlIiB/RiSMaOG33R38yXE69PSDNNMNwRVfz4ktyYFY6nFbL4rxiebnk0PNcyyFyf672xVJLfD/pTYDs3sDE+WG7hWc7zI7PsnJ/rcC3ddsaXg6WABhna5fHGHLfkgEOdFlkD81e6q76k4gajSR3FKXWXt7z2O6qMbj5mRIh7MbkxwrhtrGaaLrS5LkImk3/sUCaqu5xRiRJabJGER/z4sw==" Feb 17 20:55:27 volumio go-librespot[5606]: time="2026-02-17T20:55:27+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 17 20:55:27 volumio go-librespot[5606]: time="2026-02-17T20:55:27+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 17 20:55:27 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 20:55:27 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 20:55:29 volumio volumio[5590]: info: ------------------------------------------- Feb 17 20:55:29 volumio volumio[5590]: info: ----- Volumio3 ---- Feb 17 20:55:29 volumio volumio[5590]: info: ------------------------------------------- Feb 17 20:55:29 volumio volumio[5590]: info: ----- System startup ---- Feb 17 20:55:29 volumio volumio[5590]: info: ------------------------------------------- Feb 17 20:55:30 volumio volumio-remote-updater[25144]: [2026-02-17 20:55:30] [connect] Successful connection Feb 17 20:55:30 volumio volumio[5590]: info: MYVOLUMIO Environment detected Feb 17 20:55:30 volumio volumio[5590]: info: Plugin folders cleanup Feb 17 20:55:30 volumio volumio[5590]: info: Scanning into folder /volumio/app/plugins/ Feb 17 20:55:30 volumio volumio[5590]: info: Scanning category audio_interface Feb 17 20:55:30 volumio volumio[5590]: info: Scanning category miscellanea Feb 17 20:55:30 volumio volumio[5590]: info: Scanning category music_service Feb 17 20:55:30 volumio volumio[5590]: info: Scanning category plugins.json Feb 17 20:55:30 volumio volumio[5590]: info: Scanning category system_controller Feb 17 20:55:30 volumio volumio[5590]: info: Scanning category user_interface Feb 17 20:55:30 volumio volumio[5590]: info: Scanning into folder /data/plugins/ Feb 17 20:55:30 volumio volumio[5590]: info: Scanning category music_service Feb 17 20:55:30 volumio volumio[5590]: info: Plugin folders cleanup completed Feb 17 20:55:30 volumio volumio[5590]: info: ------------------------------------------- Feb 17 20:55:30 volumio volumio[5590]: info: ----- Core plugins startup ---- Feb 17 20:55:30 volumio volumio[5590]: info: ------------------------------------------- Feb 17 20:55:30 volumio volumio[5590]: info: Loading plugins from folder /volumio/app/plugins/ Feb 17 20:55:30 volumio volumio[5590]: info: Adding plugin upnp to MyMusic Plugins Feb 17 20:55:30 volumio volumio[5590]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 17 20:55:30 volumio volumio[5590]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 17 20:55:30 volumio volumio[5590]: info: Loading plugins from folder /data/plugins/ Feb 17 20:55:30 volumio volumio[5590]: info: Loading plugin "system"... Feb 17 20:55:30 volumio volumio[5590]: info: Loading plugin "appearance"... Feb 17 20:55:31 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Feb 17 20:55:31 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 20:55:31 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 20:55:31 volumio go-librespot[5625]: go-librespot daemon starting... Feb 17 20:55:31 volumio go-librespot[5626]: time="2026-02-17T20:55:31+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 20:55:31 volumio go-librespot[5626]: time="2026-02-17T20:55:31+07:00" level=debug msg="app state loaded" Feb 17 20:55:31 volumio go-librespot[5626]: time="2026-02-17T20:55:31+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 20:55:31 volumio go-librespot[5626]: time="2026-02-17T20:55:31+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 17 20:55:31 volumio go-librespot[5626]: time="2026-02-17T20:55:31+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 17 20:55:31 volumio go-librespot[5626]: time="2026-02-17T20:55:31+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 17 20:55:31 volumio go-librespot[5626]: time="2026-02-17T20:55:31+07:00" level=info msg="zeroconf server listening on port 39147" Feb 17 20:55:31 volumio go-librespot[5626]: time="2026-02-17T20:55:31+07:00" level=debug msg="obtained new client token: AADEEap7izVy4Y5cv1u7RBC5PeGBb2+pQaaYP75ToZw92XrMB3Fg90SZSo8nf+5WQaqFRFz0zlzapA+alSyiMvtyBcfBbA1l6znVVLyo85Eq7NZwwvyWkLZpnUtE7Yy9T0c1vL94cHX8hMZlFKKEFaKK1iaO9sJ0EYb/wv+F8IyA/FnqZKPHb7yBIHykTfgKvzXq2jwlVsD/oA72Xv1V98VO5SCdsiM4aJkodZW7fPZSNH4BgIr+/0eDXA==" Feb 17 20:55:32 volumio go-librespot[5626]: time="2026-02-17T20:55:32+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 17 20:55:32 volumio go-librespot[5626]: time="2026-02-17T20:55:32+07:00" level=debug msg="completed keyexchange" Feb 17 20:55:32 volumio go-librespot[5626]: time="2026-02-17T20:55:32+07:00" level=debug msg="completed challenge" Feb 17 20:55:32 volumio go-librespot[5626]: time="2026-02-17T20:55: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 17 20:55:32 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 20:55:32 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 20:55:32 volumio volumio[5590]: info: Loading plugin "network"... Feb 17 20:55:32 volumio volumio[5590]: info: Refreshing Cached IP Addresses Feb 17 20:55:32 volumio sudo[5634]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 17 20:55:32 volumio sudo[5634]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 20:55:32 volumio sudo[5636]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 17 20:55:33 volumio sudo[5634]: pam_unix(sudo:session): session closed for user root Feb 17 20:55:33 volumio sudo[5636]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 20:55:33 volumio volumio[5590]: info: Loading plugin "services"... Feb 17 20:55:33 volumio sudo[5636]: pam_unix(sudo:session): session closed for user root Feb 17 20:55:33 volumio volumio[5590]: info: Loading plugin "alsa_controller"... Feb 17 20:55:33 volumio sudo[5648]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 17 20:55:33 volumio sudo[5648]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 20:55:33 volumio volumio[5590]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 17 20:55:33 volumio volumio[5590]: info: Loading plugin "wizard"... Feb 17 20:55:33 volumio volumio[5590]: info: Loading plugin "networkfs"... Feb 17 20:55:33 volumio volumio[5590]: info: Starting Udev Watcher for removable devices Feb 17 20:55:33 volumio volumio[5590]: info: Ignoring mount for partition: boot Feb 17 20:55:33 volumio volumio[5590]: info: Ignoring mount for partition: volumio Feb 17 20:55:33 volumio volumio[5590]: info: Ignoring mount for partition: volumio_data Feb 17 20:55:33 volumio volumio[5590]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 17 20:55:33 volumio volumio[5590]: info: Loading plugin "volumio_command_line_client"... Feb 17 20:55:33 volumio volumio[5590]: info: Loading plugin "upnp"... Feb 17 20:55:33 volumio volumio[5590]: info: [1771336533313] Starting Upmpd Daemon Feb 17 20:55:33 volumio volumio[5590]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 17 20:55:33 volumio volumio[5590]: info: Loading plugin "my_music"... Feb 17 20:55:33 volumio volumio[5590]: info: Loading plugin "mpd"... Feb 17 20:55:33 volumio volumio[5590]: info: Loading plugin "upnp_browser"... Feb 17 20:55:35 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Feb 17 20:55:35 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 20:55:35 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 20:55:35 volumio go-librespot[5667]: go-librespot daemon starting... Feb 17 20:55:35 volumio go-librespot[5668]: time="2026-02-17T20:55:35+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 20:55:35 volumio go-librespot[5668]: time="2026-02-17T20:55:35+07:00" level=debug msg="app state loaded" Feb 17 20:55:35 volumio go-librespot[5668]: time="2026-02-17T20:55:35+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 20:55:35 volumio sudo[5648]: pam_unix(sudo:session): session closed for user root Feb 17 20:55:35 volumio go-librespot[5668]: time="2026-02-17T20:55:35+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 17 20:55:35 volumio go-librespot[5668]: time="2026-02-17T20:55:35+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 17 20:55:35 volumio go-librespot[5668]: time="2026-02-17T20:55:35+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 17 20:55:35 volumio go-librespot[5668]: time="2026-02-17T20:55:35+07:00" level=info msg="zeroconf server listening on port 46057" Feb 17 20:55:36 volumio go-librespot[5668]: time="2026-02-17T20:55:36+07:00" level=debug msg="obtained new client token: AAB86eBz5HmZQay0DMkNLdOC9Jg8Qv2VVx3abmmNlpuCN+APAJ1fK3RuHBxbaTZGkREzg061juN7G561yTbicEBF9fvifOQSSjsPkdtRMkgrXCCGlFf7KDhwDi/q0Sb9JUrsSKV/H0lHbKLfjxKiVYhck04AaEESbygiX9RNhE/xgUfDPliFMsFadi+aYw/WoxJ5WeZeXTFzozcJYXzQcSODNpYzjQEjYkP7md7P7BSnwbYnPh4W7mQ=" Feb 17 20:55:36 volumio go-librespot[5668]: time="2026-02-17T20:55:36+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 17 20:55:36 volumio go-librespot[5668]: time="2026-02-17T20:55:36+07:00" level=debug msg="completed keyexchange" Feb 17 20:55:36 volumio go-librespot[5668]: time="2026-02-17T20:55:36+07:00" level=debug msg="completed challenge" Feb 17 20:55:36 volumio go-librespot[5668]: time="2026-02-17T20:55:36+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 17 20:55:36 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 20:55:36 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 20:55:37 volumio volumio[5590]: info: Starting UPNP Browser Feb 17 20:55:37 volumio volumio[5590]: info: Loading plugin "alarm-clock"... Feb 17 20:55:37 volumio volumio[5590]: info: Loading plugin "airplay_emulation"... Feb 17 20:55:37 volumio volumio[5590]: info: Starting Shairport Sync Feb 17 20:55:37 volumio volumio[5590]: info: Loading plugin "last_100"... Feb 17 20:55:37 volumio volumio[5590]: info: Loading plugin "webradio"... Feb 17 20:55:37 volumio volumio[5590]: info: Loading plugin "i2s_dacs"... Feb 17 20:55:37 volumio volumio[5590]: info: Loading plugin "volumiodiscovery"... Feb 17 20:55:37 volumio volumio[5590]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 17 20:55:37 volumio volumio[5590]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 17 20:55:37 volumio node[5590]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 17 20:55:37 volumio volumio[5590]: *** WARNING *** For more information see Feb 17 20:55:37 volumio volumio[5590]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 17 20:55:37 volumio volumio[5590]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 17 20:55:37 volumio volumio[5590]: *** WARNING *** For more information see Feb 17 20:55:37 volumio node[5590]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 17 20:55:37 volumio node[5590]: *** WARNING *** For more information see Feb 17 20:55:37 volumio node[5590]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 17 20:55:37 volumio node[5590]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 17 20:55:37 volumio node[5590]: *** WARNING *** For more information see Feb 17 20:55:37 volumio volumio[5590]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 17 20:55:37 volumio volumio[5590]: info: Discovery: Started advertising with name: Volumio Feb 17 20:55:37 volumio volumio[5590]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 17 20:55:37 volumio volumio[5590]: info: Loading plugin "spop"... Feb 17 20:55:39 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Feb 17 20:55:39 volumio volumio[5590]: info: Loading plugin "ytcr"... Feb 17 20:55:39 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 20:55:39 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 20:55:39 volumio go-librespot[5678]: go-librespot daemon starting... Feb 17 20:55:39 volumio go-librespot[5679]: time="2026-02-17T20:55:39+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 20:55:39 volumio go-librespot[5679]: time="2026-02-17T20:55:39+07:00" level=debug msg="app state loaded" Feb 17 20:55:39 volumio go-librespot[5679]: time="2026-02-17T20:55:39+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 20:55:40 volumio go-librespot[5679]: time="2026-02-17T20:55:40+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 17 20:55:40 volumio go-librespot[5679]: time="2026-02-17T20:55:40+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 17 20:55:40 volumio go-librespot[5679]: time="2026-02-17T20:55:40+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 17 20:55:40 volumio go-librespot[5679]: time="2026-02-17T20:55:40+07:00" level=info msg="zeroconf server listening on port 35391" Feb 17 20:55:40 volumio go-librespot[5679]: time="2026-02-17T20:55:40+07:00" level=debug msg="obtained new client token: AABny42WGuOLZMg0dOExMVmUbuum53hvPHjsy0kfE8fhYHZ7bcK3ZAQjkNr7n1IkNfwySvi90KIqh6b5BU7MS0ZhuScaciqkKZHHa6EXSwNCijP/lTeD2Uf8pSojvcGpxBJndyjZWvVgFSpSQ90RX+dRSSDDvGhmsa1O2535gjDqW8uVL2Y18mVuSvHPYltQFYQdBT2GTNd1ui5j/LQwM6cxt9T/oO2cnZUmWh1zHIe+p9IXZoGOghbvZg==" Feb 17 20:55:40 volumio go-librespot[5679]: time="2026-02-17T20:55:40+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 17 20:55:40 volumio go-librespot[5679]: time="2026-02-17T20:55:40+07:00" level=debug msg="completed keyexchange" Feb 17 20:55:40 volumio go-librespot[5679]: time="2026-02-17T20:55:40+07:00" level=debug msg="completed challenge" Feb 17 20:55:40 volumio go-librespot[5679]: time="2026-02-17T20:55:40+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 17 20:55:40 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 20:55:40 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 20:55:42 volumio volumio[5590]: info: Loading plugin "ytmusic"... Feb 17 20:55:42 volumio volumio-remote-updater[25144]: [2026-02-17 20:55:42] [connect] Successful connection Feb 17 20:55:43 volumio volumio[5590]: info: Loading plugin "outputs"... Feb 17 20:55:43 volumio volumio[5590]: info: Loading plugin "albumart"... Feb 17 20:55:43 volumio volumio[5590]: info: Plugin example_plugin is not enabled Feb 17 20:55:43 volumio volumio[5590]: info: Loading plugin "inputs"... Feb 17 20:55:43 volumio volumio[5590]: info: Loading plugin "updater_comm"... Feb 17 20:55:43 volumio volumio[5590]: info: Plugin mpdemulation is not enabled Feb 17 20:55:43 volumio volumio[5590]: info: Loading plugin "rest_api"... Feb 17 20:55:43 volumio volumio[5590]: info: Loading plugin "websocket"... Feb 17 20:55:43 volumio volumio[5590]: info: Starting Socket.io Server version 1.7.4 Feb 17 20:55:43 volumio volumio[5590]: info: Loading plugin "RoonBridge"... Feb 17 20:55:44 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Feb 17 20:55:44 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 20:55:44 volumio volumio[5590]: info: Applying required configuration parameters for plugin RoonBridge Feb 17 20:55:44 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 20:55:44 volumio go-librespot[5710]: go-librespot daemon starting... Feb 17 20:55:44 volumio volumio[5590]: info: Loading i18n strings for locale en Feb 17 20:55:44 volumio volumio[5590]: Updating browse sources language Feb 17 20:55:44 volumio go-librespot[5711]: time="2026-02-17T20:55:44+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 20:55:44 volumio go-librespot[5711]: time="2026-02-17T20:55:44+07:00" level=debug msg="app state loaded" Feb 17 20:55:44 volumio volumio[5590]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 17 20:55:44 volumio go-librespot[5711]: time="2026-02-17T20:55:44+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 20:55:44 volumio volumio[5590]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 17 20:55:44 volumio volumio[5590]: info: CoreCommandRouter::initPlayerControls Feb 17 20:55:44 volumio volumio[5590]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 20:55:44 volumio volumio[5590]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 20:55:44 volumio volumio[5590]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 20:55:44 volumio volumio[5590]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 20:55:44 volumio volumio[5590]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 20:55:44 volumio volumio[5590]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 20:55:44 volumio volumio[5590]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 20:55:44 volumio volumio[5590]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 20:55:44 volumio volumio[5590]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 17 20:55:44 volumio volumio[5590]: Express server listening on port 3000 Feb 17 20:55:44 volumio volumio[5590]: [Metrics] WebUI: 16s 164.73ms Feb 17 20:55:44 volumio volumio[5700]: Forking 3 albumart workers Feb 17 20:55:44 volumio volumio[5590]: info: CoreStateMachine::resetVolumioState Feb 17 20:55:44 volumio volumio[5590]: info: CoreStateMachine::getcurrentVolume Feb 17 20:55:44 volumio volumio[5590]: info: CoreCommandRouter::volumioRetrievevolume Feb 17 20:55:44 volumio sudo[5743]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 17 20:55:44 volumio sudo[5743]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 20:55:44 volumio sudo[5743]: pam_unix(sudo:session): session closed for user root Feb 17 20:55:44 volumio sudo[5752]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 17 20:55:44 volumio sudo[5752]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 20:55:44 volumio sudo[5752]: pam_unix(sudo:session): session closed for user root Feb 17 20:55:44 volumio go-librespot[5711]: time="2026-02-17T20:55:44+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 17 20:55:44 volumio go-librespot[5711]: time="2026-02-17T20:55:44+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 17 20:55:44 volumio go-librespot[5711]: time="2026-02-17T20:55:44+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 17 20:55:44 volumio volumio[5590]: info: Volumio Network Manager: Network status updated: 1 Feb 17 20:55:44 volumio go-librespot[5711]: time="2026-02-17T20:55:44+07:00" level=info msg="zeroconf server listening on port 46773" Feb 17 20:55:45 volumio go-librespot[5711]: time="2026-02-17T20:55:45+07:00" level=debug msg="obtained new client token: AAB49nbwtQ1iwbWvDqPas1w63L8NMtnXQnesDCxyRShBhiuVtNYnd0nJoNDhD4z4b7EsDX5Fn/yYMeweTbGIe/wRj+jhz29IXIpGt+Kyr8j884NXhvPQD51pUTjcWbvT97c453qHdZhSsO7AppR03MhrHSnWPPbE5LEMJjfrRsJKvFTFROb8BmBRIUTykOZiBqZ+BG9mBumUp7xq99/TqINaz97t95BEiPGIhz81hfd3qx5kFWW5bps=" Feb 17 20:55:45 volumio volumio[5590]: info: VolumeController:: Volume=100 Mute =false Feb 17 20:55:45 volumio volumio[5590]: info: CoreStateMachine::pushState Feb 17 20:55:45 volumio volumio[5590]: info: CorePlayQueue::getTrack 0 Feb 17 20:55:45 volumio volumio[5590]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 17 20:55:45 volumio volumio[5590]: info: CoreCommandRouter::volumioPushState Feb 17 20:55:45 volumio volumio[5590]: info: CoreStateMachine::updateTrackBlock Feb 17 20:55:45 volumio volumio[5590]: info: CorePlayQueue::getTrackBlock Feb 17 20:55:45 volumio volumio[5590]: info: CoreCommandRouter::volumioRetrievevolume Feb 17 20:55:45 volumio go-librespot[5711]: time="2026-02-17T20:55:45+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 17 20:55:45 volumio volumio-remote-updater[25144]: [2026-02-17 20:55:45] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1771336542 101 Feb 17 20:55:45 volumio go-librespot[5711]: time="2026-02-17T20:55:45+07:00" level=debug msg="completed keyexchange" Feb 17 20:55:45 volumio go-librespot[5711]: time="2026-02-17T20:55:45+07:00" level=debug msg="completed challenge" Feb 17 20:55:45 volumio volumio[5590]: 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 17 20:55:45 volumio go-librespot[5711]: time="2026-02-17T20:55:45+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 17 20:55:45 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 20:55:45 volumio volumio[5590]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 20:55:45 volumio volumio[5590]: info: Reloading queue from file Feb 17 20:55:45 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 20:55:45 volumio volumio[5590]: info: CoreStateMachine::setRepeat null single undefined Feb 17 20:55:45 volumio volumio[5590]: info: CoreStateMachine::pushState Feb 17 20:55:45 volumio volumio[5590]: info: CorePlayQueue::getTrack 0 Feb 17 20:55:45 volumio volumio[5590]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 17 20:55:45 volumio volumio[5590]: info: CoreCommandRouter::volumioPushState Feb 17 20:55:45 volumio volumio[5590]: info: CoreStateMachine::setRandom null Feb 17 20:55:45 volumio volumio[5590]: info: CoreStateMachine::pushState Feb 17 20:55:45 volumio volumio[5590]: info: CorePlayQueue::getTrack 0 Feb 17 20:55:45 volumio volumio[5590]: info: CoreCommandRouter::volumioPushState Feb 17 20:55:45 volumio volumio[5590]: info: Setting Device type: Raspberry PI Feb 17 20:55:45 volumio volumio[5590]: info: Completed loading Core Plugins Feb 17 20:55:45 volumio volumio[5590]: info: Preparing to generate the ALSA configuration file Feb 17 20:55:45 volumio volumio[5590]: info: VolumeController:: Volume=100 Mute =false Feb 17 20:55:45 volumio volumio[5590]: info: CoreStateMachine::pushState Feb 17 20:55:45 volumio volumio[5590]: info: CorePlayQueue::getTrack 0 Feb 17 20:55:45 volumio volumio[5590]: info: CoreCommandRouter::volumioPushState Feb 17 20:55:45 volumio volumio[5590]: info: Asound.conf file unchanged, so no further update is needed Feb 17 20:55:45 volumio volumio[5590]: info: Output device has changed, restarting MPD Feb 17 20:55:45 volumio sudo[5770]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 17 20:55:45 volumio sudo[5770]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 20:55:45 volumio volumio[5590]: info: Output device has changed, restarting Shairport Sync Feb 17 20:55:45 volumio volumio[5590]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 20:55:45 volumio volumio[5590]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 20:55:45 volumio sudo[5772]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 17 20:55:45 volumio sudo[5772]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 20:55:45 volumio sudo[5772]: pam_unix(sudo:session): session closed for user root Feb 17 20:55:45 volumio sudo[5775]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 17 20:55:45 volumio sudo[5775]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 20:55:46 volumio volumio[5590]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 17 20:55:46 volumio volumio[5590]: info: ___________ START PLUGINS ___________ Feb 17 20:55:46 volumio volumio[5590]: info: ControllerMpd::onStart: Initializing MPD Feb 17 20:55:46 volumio volumio[5590]: info: Creating MPD Configuration file Feb 17 20:55:46 volumio sudo[5770]: pam_unix(sudo:session): session closed for user root Feb 17 20:55:46 volumio volumio[5590]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 17 20:55:46 volumio volumio[5590]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 17 20:55:46 volumio volumio[5590]: info: [1771336546097] CoreMusicLibrary::Adding element Media Servers Feb 17 20:55:46 volumio volumio[5590]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 17 20:55:46 volumio volumio[5590]: info: UPNP Browser: Client initialized successfully Feb 17 20:55:46 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 17 20:55:46 volumio sudo[5783]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 17 20:55:46 volumio sudo[5783]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 20:55:46 volumio sudo[5783]: pam_unix(sudo:session): session closed for user root Feb 17 20:55:46 volumio sudo[5785]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 17 20:55:46 volumio sudo[5785]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 20:55:46 volumio volumio[5590]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 20:55:46 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 17 20:55:46 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 17 20:55:46 volumio systemd[1]: mpd.service: Consumed 7.162s CPU time. Feb 17 20:55:46 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 17 20:55:46 volumio volumio[5590]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 20:55:46 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 17 20:55:46 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 17 20:55:46 volumio volumio[5590]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 17 20:55:46 volumio volumio[5590]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 20:55:46 volumio volumio[5590]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 20:55:46 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 17 20:55:46 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 17 20:55:46 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 17 20:55:46 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 17 20:55:46 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 17 20:55:46 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 17 20:55:46 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 17 20:55:46 volumio volumio[5590]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 17 20:55:46 volumio volumio[5590]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 17 20:55:46 volumio volumio[5590]: info: [1771336546476] CoreMusicLibrary::Adding element Last_100 Feb 17 20:55:46 volumio volumio[5590]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 17 20:55:46 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 17 20:55:46 volumio volumio[5590]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 17 20:55:46 volumio volumio[5590]: info: [1771336546503] CoreMusicLibrary::Adding element Webradio Feb 17 20:55:46 volumio volumio[5590]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 17 20:55:46 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 17 20:55:46 volumio volumio[5590]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 17 20:55:46 volumio volumio[5590]: info: Initializing BBC Radios Feb 17 20:55:46 volumio volumio[5590]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 17 20:55:46 volumio volumio[5590]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 20:55:46 volumio volumio[5590]: info: Creating Spotify config file Feb 17 20:55:46 volumio volumio[5590]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 20:55:47 volumio sudo[5799]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 17 20:55:47 volumio sudo[5799]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 17 20:55:47 volumio sudo[5799]: pam_unix(sudo:session): session closed for user root Feb 17 20:55:47 volumio volumio[5721]: Starting albumart workers Feb 17 20:55:47 volumio volumio[5725]: Starting albumart workers Feb 17 20:55:47 volumio volumio[5724]: Starting albumart workers Feb 17 20:55:48 volumio volumio[5590]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 17 20:55:48 volumio volumio[5590]: info: [1771336548027] CoreMusicLibrary::Adding element YouTube Music Feb 17 20:55:48 volumio volumio[5590]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 17 20:55:48 volumio volumio[5590]: Cannot find translation for source YouTube Music Feb 17 20:55:48 volumio volumio[5590]: info: Volumio Calling Home Feb 17 20:55:48 volumio sudo[5816]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Feb 17 20:55:48 volumio sudo[5816]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 20:55:48 volumio sudo[5816]: pam_unix(sudo:session): session closed for user root Feb 17 20:55:48 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Feb 17 20:55:48 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 20:55:48 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 20:55:48 volumio go-librespot[5821]: go-librespot daemon starting... Feb 17 20:55:48 volumio go-librespot[5822]: time="2026-02-17T20:55:48+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 20:55:48 volumio volumio[5590]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Feb 17 20:55:48 volumio volumio[5590]: info: Discovery: Found device Volumio Feb 17 20:55:48 volumio volumio[5590]: info: CoreCommandRouter::volumioGetState Feb 17 20:55:48 volumio volumio[5590]: info: CorePlayQueue::getTrack 0 Feb 17 20:55:49 volumio volumio[5590]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Feb 17 20:55:49 volumio volumio[5590]: info: Discovery: Found device Volumio Feb 17 20:55:49 volumio volumio[5590]: info: CoreCommandRouter::volumioGetState Feb 17 20:55:49 volumio volumio[5590]: info: CorePlayQueue::getTrack 0 Feb 17 20:55:49 volumio volumio[5590]: info: MPD Permissions set Feb 17 20:55:49 volumio volumio[5590]: info: MPD Permissions set Feb 17 20:55:49 volumio volumio[5590]: info: Upmpdcli Daemon Started Feb 17 20:55:49 volumio volumio[5590]: info: Volumio called home Feb 17 20:55:49 volumio volumio[5590]: info: Spotify config file written Feb 17 20:55:49 volumio sudo[5830]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 17 20:55:49 volumio sudo[5830]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 20:55:49 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Feb 17 20:55:49 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Feb 17 20:55:49 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 20:55:49 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 20:55:49 volumio go-librespot[5834]: go-librespot daemon starting... Feb 17 20:55:49 volumio sudo[5830]: pam_unix(sudo:session): session closed for user root Feb 17 20:55:49 volumio go-librespot[5835]: time="2026-02-17T20:55:49+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 20:55:49 volumio go-librespot[5835]: time="2026-02-17T20:55:49+07:00" level=debug msg="app state loaded" Feb 17 20:55:49 volumio go-librespot[5835]: time="2026-02-17T20:55:49+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 20:55:49 volumio volumio[5590]: 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 17 20:55:49 volumio volumio[5590]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 20:55:49 volumio volumio[5590]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 20:55:49 volumio volumio[5590]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 20:55:49 volumio volumio[5590]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 20:55:49 volumio volumio[5590]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 20:55:49 volumio volumio[5590]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 20:55:49 volumio volumio[5590]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 20:55:49 volumio volumio[5590]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 20:55:49 volumio volumio[5590]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 20:55:49 volumio volumio[5590]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 20:55:49 volumio volumio[5590]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 20:55:49 volumio volumio[5590]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 20:55:49 volumio volumio[5590]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 20:55:49 volumio volumio[5590]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 20:55:49 volumio volumio[5590]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 20:55:49 volumio volumio[5590]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 20:55:49 volumio volumio[5590]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 20:55:49 volumio volumio[5590]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 20:55:50 volumio volumio[5590]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 20:55:50 volumio volumio[5590]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 17 20:55:50 volumio volumio[5590]: info: No need to fix Spotify hosts Feb 17 20:55:50 volumio go-librespot[5835]: time="2026-02-17T20:55: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-gew4.spotify.com:80]" Feb 17 20:55:50 volumio go-librespot[5835]: time="2026-02-17T20:55:50+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 17 20:55:50 volumio go-librespot[5835]: time="2026-02-17T20:55:50+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 17 20:55:50 volumio go-librespot[5835]: time="2026-02-17T20:55:50+07:00" level=info msg="zeroconf server listening on port 44805" Feb 17 20:55:50 volumio go-librespot[5835]: time="2026-02-17T20:55:50+07:00" level=debug msg="obtained new client token: AADvPOYuV1Q2yZ1gJOQ6Qm8aUAneC2HAWoKoy2DbAxRLO3k51bDtMzhhYantsSlb81AisOj2kIMqSrO9FnbGzEKTqQAOKrJd+iqCpmP4eGM0NZxGIkFJgLIgoIGpvgMucc6Px+/PxJTk7+LSPDJGhQuifaQzq508VaFKgntmcuazlndbs3P7ti2lfYNQERxlnOA6BRxiLh3yb5bJnkwbKvJAM78f4LmoPkUt2rCXUANjSdaWcs2fU7mREg==" Feb 17 20:55:50 volumio volumio[5590]: info: Starting Shairport Sync Feb 17 20:55:50 volumio volumio[5590]: info: Starting Shairport Sync Feb 17 20:55:50 volumio go-librespot[5835]: time="2026-02-17T20:55:50+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 17 20:55:50 volumio volumio[5590]: info: Starting Shairport Sync Feb 17 20:55:50 volumio sudo[5871]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 17 20:55:50 volumio sudo[5871]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 20:55:50 volumio sudo[5875]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 17 20:55:50 volumio sudo[5875]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 20:55:50 volumio go-librespot[5835]: time="2026-02-17T20:55:50+07:00" level=debug msg="completed keyexchange" Feb 17 20:55:50 volumio go-librespot[5835]: time="2026-02-17T20:55:50+07:00" level=debug msg="completed challenge" Feb 17 20:55:50 volumio sudo[5873]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 17 20:55:50 volumio sudo[5873]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 20:55:51 volumio go-librespot[5835]: time="2026-02-17T20:55: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 17 20:55:51 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 20:55:51 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 20:55:51 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 17 20:55:51 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 17 20:55:51 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 17 20:55:51 volumio systemd[1]: shairport-sync.service: Consumed 2.303s CPU time. Feb 17 20:55:51 volumio volumio[5590]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 17 20:55:51 volumio volumio[5590]: SPOTIFY: BQC7wFlOBHUXaly-eqaAuR0o7GPYH98oIYKlJmrtNbFCfBTOLyJLmzUr1jR8F9vp1vPMq15lEL8_198P95tDe-Zqywk1ogLmd399V-nHDekH7a8KHpKz2PD80bqz8uRyF2gU5SW00gEknd320jqcSRtloRMHmLUqDPJchWuFIIrC5SC9jjD5b2Riis0fc5dpEWKl-BggdcbpDR20dD5lApdQVupOEQXni62kKiBrzZRv8nqp2UzmBNMF65rjATB6hbT-ZpZ9or98VnvIUkDvSRkolS_OtZ9j5uN0mCpi-mVGOTf0d8_eWagV Feb 17 20:55:51 volumio volumio[5590]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 17 20:55:51 volumio volumio[5590]: info: New Spotify access token = BQC7wFlOBHUXaly-eqaAuR0o7GPYH98oIYKlJmrtNbFCfBTOLyJLmzUr1jR8F9vp1vPMq15lEL8_198P95tDe-Zqywk1ogLmd399V-nHDekH7a8KHpKz2PD80bqz8uRyF2gU5SW00gEknd320jqcSRtloRMHmLUqDPJchWuFIIrC5SC9jjD5b2Riis0fc5dpEWKl-BggdcbpDR20dD5lApdQVupOEQXni62kKiBrzZRv8nqp2UzmBNMF65rjATB6hbT-ZpZ9or98VnvIUkDvSRkolS_OtZ9j5uN0mCpi-mVGOTf0d8_eWagV Feb 17 20:55:51 volumio volumio[5590]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 17 20:55:51 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 17 20:55:51 volumio sudo[5875]: pam_unix(sudo:session): session closed for user root Feb 17 20:55:51 volumio volumio[5590]: info: CoreCommandRouter::volumioGetState Feb 17 20:55:51 volumio volumio[5590]: info: CorePlayQueue::getTrack 0 Feb 17 20:55:51 volumio sudo[5873]: pam_unix(sudo:session): session closed for user root Feb 17 20:55:51 volumio sudo[5871]: pam_unix(sudo:session): session closed for user root Feb 17 20:55:51 volumio volumio[5590]: info: Shairport-Sync Started Feb 17 20:55:51 volumio volumio[5590]: Error adding Membership: Error: addMembership EINVAL Feb 17 20:55:51 volumio volumio[5590]: info: Shairport-Sync Started Feb 17 20:55:51 volumio volumio[5590]: info: Shairport-Sync Started Feb 17 20:55:51 volumio volumio[5590]: 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 17 20:55:51 volumio volumio[5590]: info: Spotify Successfully logged in Feb 17 20:55:51 volumio volumio[5590]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 17 20:55:51 volumio volumio[5590]: info: [1771336551918] CoreMusicLibrary::Adding element Spotify Feb 17 20:55:51 volumio volumio[5590]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 17 20:55:51 volumio volumio[5590]: Cannot find translation for source YouTube Music Feb 17 20:55:51 volumio volumio[5590]: Cannot find translation for source Spotify Feb 17 20:55:52 volumio volumio[5590]: info: [yt-cast-receiver] DIAL server listening on port 8098 Feb 17 20:55:52 volumio volumio[5590]: info: CoreCommandRouter::volumioRetrievevolume Feb 17 20:55:52 volumio volumio[5590]: info: VolumeController:: Volume=100 Mute =false Feb 17 20:55:52 volumio volumio[5590]: info: CoreCommandRouter::volumioGetState Feb 17 20:55:52 volumio volumio[5590]: info: CorePlayQueue::getTrack 0 Feb 17 20:55:52 volumio volumio[5590]: info: CoreStateMachine::pushState Feb 17 20:55:52 volumio volumio[5590]: info: CorePlayQueue::getTrack 0 Feb 17 20:55:52 volumio volumio[5590]: info: CoreCommandRouter::volumioPushState Feb 17 20:55:53 volumio volumio[5590]: info: go-librespot daemon successfully initialized Feb 17 20:55:54 volumio mpd[5814]: 2026-02-17T20:55:54 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 17 20:55:54 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 17 20:55:54 volumio sudo[5775]: pam_unix(sudo:session): session closed for user root Feb 17 20:55:54 volumio sudo[5785]: pam_unix(sudo:session): session closed for user root Feb 17 20:55:54 volumio volumio[5590]: error: MPD error: The expression evaluated to a falsy value: Feb 17 20:55:54 volumio volumio[5590]: assert.ok(self.idling) Feb 17 20:55:54 volumio volumio[5590]: error: The expression evaluated to a falsy value: Feb 17 20:55:54 volumio volumio[5590]: assert.ok(self.idling) Feb 17 20:55:54 volumio volumio[5590]: info: MPD running with PID5814 Feb 17 20:55:54 volumio volumio[5590]: ,establishing connection Feb 17 20:55:54 volumio volumio[5590]: error: updateQueue error: null Feb 17 20:55:54 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Feb 17 20:55:54 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 20:55:54 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 20:55:54 volumio go-librespot[5916]: go-librespot daemon starting... Feb 17 20:55:54 volumio volumio[5590]: info: Completed starting Core Plugins Feb 17 20:55:54 volumio volumio[5590]: info: ------------------------------------------- Feb 17 20:55:54 volumio volumio[5590]: info: ----- MyVolumio plugins startup ---- Feb 17 20:55:54 volumio volumio[5590]: info: ------------------------------------------- Feb 17 20:55:54 volumio volumio[5590]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 17 20:55:54 volumio volumio[5590]: error: updateQueue error: null Feb 17 20:55:54 volumio go-librespot[5917]: time="2026-02-17T20:55:54+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 20:55:54 volumio go-librespot[5917]: time="2026-02-17T20:55:54+07:00" level=debug msg="app state loaded" Feb 17 20:55:54 volumio go-librespot[5917]: time="2026-02-17T20:55:54+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 20:55:54 volumio go-librespot[5917]: time="2026-02-17T20:55:54+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 17 20:55:54 volumio go-librespot[5917]: time="2026-02-17T20:55:54+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 17 20:55:54 volumio go-librespot[5917]: time="2026-02-17T20:55:54+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 17 20:55:54 volumio go-librespot[5917]: time="2026-02-17T20:55:54+07:00" level=info msg="zeroconf server listening on port 46789" Feb 17 20:55:55 volumio go-librespot[5917]: time="2026-02-17T20:55:55+07:00" level=debug msg="obtained new client token: AAAkgPktmHx64y1EIEyyVvxRNKQyVDDiCmJgNOP7UJAfFj7sOCkowBxC35hssMcVs+C8W1/O29O4nwzkVzdZJpR2v9P/w9JkbKPQ3ZlBfbfJgiunajCkohO4+xkud7eMkriwWhjLf/5siW2Z8xviP1Q8qe78XZO7RlJtB+8sebsPaxlwvV//BC3IozIfro4EOX0rvUMaCWpMUCA52uD9gNhJJPFVWQsi0c9K/NIBLiJbO4xS69rbYSk=" Feb 17 20:55:55 volumio go-librespot[5917]: time="2026-02-17T20:55:55+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 17 20:55:55 volumio go-librespot[5917]: time="2026-02-17T20:55:55+07:00" level=debug msg="completed keyexchange" Feb 17 20:55:55 volumio go-librespot[5917]: time="2026-02-17T20:55:55+07:00" level=debug msg="completed challenge" Feb 17 20:55:55 volumio go-librespot[5917]: time="2026-02-17T20:55: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 17 20:55:55 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 20:55:55 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 20:55:56 volumio volumio[5590]: info: Initializing connection to go-librespot Websocket Feb 17 20:55:56 volumio volumio[5590]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 17 20:55:58 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Feb 17 20:55:58 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 20:55:58 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 20:55:58 volumio go-librespot[5924]: go-librespot daemon starting... Feb 17 20:55:58 volumio go-librespot[5925]: time="2026-02-17T20:55:58+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 20:55:58 volumio go-librespot[5925]: time="2026-02-17T20:55:58+07:00" level=debug msg="app state loaded" Feb 17 20:55:58 volumio go-librespot[5925]: time="2026-02-17T20:55:58+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 20:55:59 volumio volumio[5590]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 17 20:55:59 volumio go-librespot[5925]: time="2026-02-17T20:55:59+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 17 20:55:59 volumio go-librespot[5925]: time="2026-02-17T20:55:59+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 17 20:55:59 volumio go-librespot[5925]: time="2026-02-17T20:55:59+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 17 20:55:59 volumio go-librespot[5925]: time="2026-02-17T20:55:59+07:00" level=info msg="zeroconf server listening on port 44177" Feb 17 20:55:59 volumio go-librespot[5925]: time="2026-02-17T20:55:59+07:00" level=debug msg="obtained new client token: AADs8GFTsnK1wRGvxZpsCNtKiq3SG+CLmd7EQ04cmFfmpuSphwXmRrc2XUUsP4Wy0eLrFnc1yErWst78hKHmWUaXGPy7ovk9odiZt0RPFpkXpCX7+PtZ+6om8DprRk/miSnS1OAh2d0ufm/dRqAj3IJ0q/JpGW1D1mM2Ii7maUJ5nKml+0n+g3PFQFYgDVEYomJ8uGCOm4CFZrz3PkvaYzaZMpJOwzVUTLLcbuq4bMrxYzQB1rDrexHIQA==" Feb 17 20:55:59 volumio go-librespot[5925]: time="2026-02-17T20:55:59+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 17 20:55:59 volumio go-librespot[5925]: time="2026-02-17T20:55:59+07:00" level=debug msg="completed keyexchange" Feb 17 20:55:59 volumio go-librespot[5925]: time="2026-02-17T20:55:59+07:00" level=debug msg="completed challenge" Feb 17 20:55:59 volumio go-librespot[5925]: time="2026-02-17T20:55:59+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 17 20:55:59 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 20:55:59 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 20:55:59 volumio volumio[5590]: info: Initializing connection to go-librespot Websocket Feb 17 20:55:59 volumio volumio[5590]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 17 20:56:02 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Feb 17 20:56:02 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 20:56:02 volumio volumio[5590]: info: Initializing connection to go-librespot Websocket Feb 17 20:56:02 volumio volumio[5590]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 17 20:56:02 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 20:56:02 volumio go-librespot[5933]: go-librespot daemon starting... Feb 17 20:56:02 volumio go-librespot[5934]: time="2026-02-17T20:56:02+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 20:56:02 volumio go-librespot[5934]: time="2026-02-17T20:56:02+07:00" level=debug msg="app state loaded" Feb 17 20:56:02 volumio go-librespot[5934]: time="2026-02-17T20:56:02+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 20:56:03 volumio volumio[5590]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 17 20:56:03 volumio volumio[5590]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 17 20:56:03 volumio volumio[5590]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 17 20:56:03 volumio volumio[5590]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 17 20:56:03 volumio volumio[5590]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 17 20:56:03 volumio volumio[5590]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 17 20:56:03 volumio volumio[5590]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 17 20:56:03 volumio volumio[5590]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 17 20:56:03 volumio volumio[5590]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 17 20:56:03 volumio volumio[5590]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 17 20:56:03 volumio volumio[5590]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 17 20:56:03 volumio volumio[5590]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 17 20:56:03 volumio volumio[5590]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 17 20:56:03 volumio volumio[5590]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 17 20:56:03 volumio volumio[5590]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 17 20:56:03 volumio volumio[5590]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 17 20:56:03 volumio volumio[5590]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 17 20:56:03 volumio volumio[5590]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 17 20:56:03 volumio volumio[5590]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 17 20:56:03 volumio volumio[5590]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 17 20:56:03 volumio volumio[5590]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 17 20:56:03 volumio volumio[5590]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 17 20:56:03 volumio volumio[5590]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 17 20:56:03 volumio volumio[5590]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 17 20:56:03 volumio volumio[5590]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 17 20:56:03 volumio volumio[5590]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 17 20:56:03 volumio volumio[5590]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 17 20:56:03 volumio volumio[5590]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 17 20:56:03 volumio volumio[5590]: info: Adding plugin bluetooth to MyMusic Plugins Feb 17 20:56:03 volumio volumio[5590]: info: Adding plugin multiroom to MyMusic Plugins Feb 17 20:56:03 volumio volumio[5590]: info: Adding plugin metavolumio to MyMusic Plugins Feb 17 20:56:03 volumio volumio[5590]: info: Adding plugin cd_controller to MyMusic Plugins Feb 17 20:56:03 volumio volumio[5590]: info: Adding plugin qobuzconnect to MyMusic Plugins Feb 17 20:56:03 volumio volumio[5590]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 17 20:56:03 volumio volumio[5590]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 17 20:56:03 volumio volumio[5590]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 17 20:56:03 volumio go-librespot[5934]: time="2026-02-17T20:56: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-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 17 20:56:03 volumio go-librespot[5934]: time="2026-02-17T20:56:03+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 17 20:56:03 volumio go-librespot[5934]: time="2026-02-17T20:56:03+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 17 20:56:03 volumio go-librespot[5934]: time="2026-02-17T20:56:03+07:00" level=info msg="zeroconf server listening on port 36539" Feb 17 20:56:03 volumio go-librespot[5934]: time="2026-02-17T20:56:03+07:00" level=debug msg="obtained new client token: AADiYL2YkR9erOXdq23W9DMkOuulJsHdPG6u6Kc53WcA5Mh8jgCTZBU8oeKoQAxewYBGDo57auEeMzS2TzUgykPz6i58+j9KLGC7grkggKntYCeTMdv+Lta3TJdNgfrg2Tw4Un5gSBvqfdBzVCUuumv39LfsXV8k5E+41RMVhMf08pKsHbUI1jXtwgT6Qai9RMRe4+uGgL4Bco53ftNBy4RMRdne+esLoimWWp45sXL7OVMZLnVryg26NQ==" Feb 17 20:56:03 volumio go-librespot[5934]: time="2026-02-17T20:56:03+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 17 20:56:03 volumio go-librespot[5934]: time="2026-02-17T20:56:03+07:00" level=debug msg="completed keyexchange" Feb 17 20:56:03 volumio go-librespot[5934]: time="2026-02-17T20:56:03+07:00" level=debug msg="completed challenge" Feb 17 20:56:03 volumio go-librespot[5934]: time="2026-02-17T20:56: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 17 20:56:03 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 20:56:03 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 20:56:05 volumio volumio[5590]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 17 20:56:05 volumio volumio[5590]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 17 20:56:05 volumio volumio[5590]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 20:56:05 volumio volumio[5590]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 20:56:05 volumio volumio[5590]: info: Starting MyVolumio Remote Streaming Endpoints Feb 17 20:56:05 volumio volumio[5590]: info: MyVolumio login type: Token Feb 17 20:56:05 volumio volumio[5590]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 17 20:56:05 volumio volumio[5590]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 17 20:56:06 volumio volumio[5590]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 17 20:56:06 volumio volumio[5590]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 17 20:56:06 volumio volumio[5590]: info: Streaming services startup Feb 17 20:56:06 volumio volumio[5590]: info: Starting Streaming Daemon Feb 17 20:56:06 volumio sudo[5957]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 17 20:56:06 volumio sudo[5957]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 20:56:06 volumio volumio[5590]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 17 20:56:07 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Feb 17 20:56:07 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 20:56:07 volumio sudo[5957]: pam_unix(sudo:session): session closed for user root Feb 17 20:56:07 volumio volumio[5590]: info: Initializing connection to go-librespot Websocket Feb 17 20:56:07 volumio volumio[5590]: error: Cannot start Volumio Streaming Daemon Feb 17 20:56:07 volumio volumio[5590]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 17 20:56:07 volumio volumio[5590]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 17 20:56:07 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 20:56:07 volumio go-librespot[5966]: go-librespot daemon starting... Feb 17 20:56:07 volumio volumio[5590]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 17 20:56:07 volumio go-librespot[5967]: time="2026-02-17T20:56:07+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 20:56:07 volumio go-librespot[5967]: time="2026-02-17T20:56:07+07:00" level=debug msg="app state loaded" Feb 17 20:56:07 volumio go-librespot[5967]: time="2026-02-17T20:56:07+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 20:56:07 volumio go-librespot[5967]: time="2026-02-17T20:56: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 17 20:56:07 volumio go-librespot[5967]: time="2026-02-17T20:56: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 17 20:56:07 volumio go-librespot[5967]: time="2026-02-17T20:56: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 17 20:56:07 volumio go-librespot[5967]: time="2026-02-17T20:56:07+07:00" level=info msg="zeroconf server listening on port 45633" Feb 17 20:56:07 volumio go-librespot[5967]: time="2026-02-17T20:56:07+07:00" level=debug msg="obtained new client token: AADf0MRTrtm2zFptuvYUPTyKdSa66JOCNRD3/NIb4fDcZFNbSaaWqI+vQ4m2tQN52NCYcnhE/mi0tpS0wiVZE9fob64n3c7LaqMj0/mP8jCNd84/S83NHIG/xqtjrBAawjpQVamIodqir8AY9VGd+E5qCe4xOHfR7aIgaAXA8XgfO7u5O2ntIqCEJQ6zvdCZPDsTJDpljx0hWtKt9wZVkbF4fkfmNpwaghdMtj1dUwXinRsUPkAZMiMnhA==" Feb 17 20:56:07 volumio go-librespot[5967]: time="2026-02-17T20:56:07+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 17 20:56:08 volumio go-librespot[5967]: time="2026-02-17T20:56:08+07:00" level=debug msg="completed keyexchange" Feb 17 20:56:08 volumio go-librespot[5967]: time="2026-02-17T20:56:08+07:00" level=debug msg="completed challenge" Feb 17 20:56:08 volumio volumio[5590]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Feb 17 20:56:08 volumio go-librespot[5967]: time="2026-02-17T20:56: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 17 20:56:08 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 20:56:08 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 20:56:09 volumio volumio[5590]: info: MyVolumio token set successfully Feb 17 20:56:09 volumio volumio[5590]: info: MYVOLUMIO: Adding device Feb 17 20:56:09 volumio volumio[5590]: info: MYVOLUMIO: Evaluating Server Feb 17 20:56:09 volumio volumio[5590]: info: MyVolumio status changed Feb 17 20:56:09 volumio volumio[5590]: info: Streaming services startup Feb 17 20:56:09 volumio volumio[5590]: info: Starting Streaming Daemon Feb 17 20:56:09 volumio volumio[5590]: info: Removing browser output: myVolumio user plan is not superstar Feb 17 20:56:09 volumio volumio[5590]: info: Removing audio output: Feb 17 20:56:09 volumio volumio[5590]: info: Stoppping Tunnel 1 Feb 17 20:56:09 volumio sudo[5995]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 17 20:56:09 volumio sudo[5995]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 20:56:09 volumio sudo[5995]: pam_unix(sudo:session): session closed for user root Feb 17 20:56:09 volumio volumio[5590]: error: Cannot start Volumio Streaming Daemon Feb 17 20:56:09 volumio volumio[5590]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 17 20:56:09 volumio volumio[5590]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 17 20:56:09 volumio sudo[5998]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Feb 17 20:56:09 volumio sudo[5998]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 20:56:09 volumio volumio[5590]: info: Setting Geolocation for MyVolumio to as1 Feb 17 20:56:09 volumio volumio[5590]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 20:56:09 volumio volumio[5590]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 20:56:09 volumio volumio[5590]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 20:56:09 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 17 20:56:09 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 17 20:56:09 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 17 20:56:09 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 17 20:56:09 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 17 20:56:09 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 17 20:56:09 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 17 20:56:09 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 17 20:56:09 volumio sudo[5998]: pam_unix(sudo:session): session closed for user root Feb 17 20:56:09 volumio volumio[5590]: info: Remote SSH Stopped Feb 17 20:56:10 volumio volumio[5590]: info: Initializing connection to go-librespot Websocket Feb 17 20:56:10 volumio volumio[5590]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 17 20:56:10 volumio volumio[5590]: info: Updating MyVolumio device info Feb 17 20:56:10 volumio volumio[5590]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 20:56:10 volumio volumio[5590]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 20:56:10 volumio volumio[5590]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 20:56:10 volumio volumio[5590]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Feb 17 20:56:11 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Feb 17 20:56:11 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 20:56:11 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 20:56:11 volumio go-librespot[6000]: go-librespot daemon starting... Feb 17 20:56:11 volumio go-librespot[6001]: time="2026-02-17T20:56:11+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 20:56:11 volumio go-librespot[6001]: time="2026-02-17T20:56:11+07:00" level=debug msg="app state loaded" Feb 17 20:56:11 volumio go-librespot[6001]: time="2026-02-17T20:56:11+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 20:56:11 volumio volumio[5590]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Feb 17 20:56:11 volumio go-librespot[6001]: time="2026-02-17T20:56:11+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 17 20:56:11 volumio go-librespot[6001]: time="2026-02-17T20:56:11+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 17 20:56:11 volumio go-librespot[6001]: time="2026-02-17T20:56:11+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 17 20:56:11 volumio go-librespot[6001]: time="2026-02-17T20:56:11+07:00" level=info msg="zeroconf server listening on port 40679" Feb 17 20:56:12 volumio go-librespot[6001]: time="2026-02-17T20:56:12+07:00" level=debug msg="obtained new client token: AAA0nl5bvFUJcpicZO7nR15HZxAW/PWwCIf5Xi9WQvYQLR+c/3f/z5dh7f3oj+bzZmzfzkl9lRXm5fL6d3YtFUhm/V9SExFvn4CY/Z5/77KI3Rv60UQPVWLtQLzV+F2ym8mEvseepaR4YAPr0XBxrGrbw7K59Yel1MLxO6Al4EI/kLTDxwWci2flhjXaoQZLwJPEaiMK5agEepXyWdDMWbJ+y9xM1xtVjRLEGdw99P79fcJOVQfaB7w=" Feb 17 20:56:12 volumio go-librespot[6001]: time="2026-02-17T20:56:12+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 17 20:56:12 volumio go-librespot[6001]: time="2026-02-17T20:56:12+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 17 20:56:12 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 20:56:12 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 20:56:13 volumio volumio[5590]: info: Initializing connection to go-librespot Websocket Feb 17 20:56:13 volumio volumio[5590]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 17 20:56:14 volumio volumio[5590]: info: MYVOLUMIO: Adding device Feb 17 20:56:14 volumio volumio[5590]: info: MYVOLUMIO: Evaluating Server Feb 17 20:56:15 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Feb 17 20:56:15 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 20:56:15 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 20:56:15 volumio go-librespot[6038]: go-librespot daemon starting... Feb 17 20:56:15 volumio go-librespot[6042]: time="2026-02-17T20:56:15+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 20:56:15 volumio go-librespot[6042]: time="2026-02-17T20:56:15+07:00" level=debug msg="app state loaded" Feb 17 20:56:15 volumio go-librespot[6042]: time="2026-02-17T20:56:15+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 20:56:15 volumio volumio[5590]: info: Setting Geolocation for MyVolumio to as1 Feb 17 20:56:15 volumio volumio[5590]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 20:56:15 volumio volumio[5590]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 20:56:15 volumio volumio[5590]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 20:56:16 volumio go-librespot[6042]: time="2026-02-17T20:56: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 17 20:56:16 volumio go-librespot[6042]: time="2026-02-17T20:56: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 17 20:56:16 volumio go-librespot[6042]: time="2026-02-17T20:56: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 17 20:56:16 volumio go-librespot[6042]: time="2026-02-17T20:56:16+07:00" level=info msg="zeroconf server listening on port 43117" Feb 17 20:56:16 volumio volumio[5590]: info: Initializing connection to go-librespot Websocket Feb 17 20:56:16 volumio go-librespot[6042]: time="2026-02-17T20:56:16+07:00" level=debug msg="new websocket client" Feb 17 20:56:16 volumio volumio[5590]: info: Connection to go-librespot Websocket established Feb 17 20:56:16 volumio go-librespot[6042]: time="2026-02-17T20:56:16+07:00" level=debug msg="obtained new client token: AAB44V+5932uBbM7xEp0xSvoqRNueIghkwU8MqVu0zWDfTC0P93N4OelvFUB3s3z/faJLQAwfrlUzdDvTe03wp/kHMf5bs/B3+9Jh0wZweXU36Cre9WRS6S+KXibXjA6fit/LUPjj0P8wzuF1WgW19rmJxE5IDksqrArxSCRKXN35Xp60XJPPkw6XpTnifZxNTsEL8auMFTJKe9JbXfMqzYN8uFp+pU3OzrtgN7KmJTYoCpzAU4xrwCHMw==" Feb 17 20:56:16 volumio go-librespot[6042]: time="2026-02-17T20:56:16+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 17 20:56:16 volumio go-librespot[6042]: time="2026-02-17T20:56:16+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 17 20:56:16 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 20:56:16 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 17 20:56:16 volumio volumio[5590]: info: Connection to go-librespot Websocket closed Feb 17 20:56:16 volumio volumio[5590]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Feb 17 20:56:16 volumio volumio[5590]: info: Updating MyVolumio device info Feb 17 20:56:16 volumio volumio[5590]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 20:56:16 volumio volumio[5590]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 20:56:16 volumio volumio[5590]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 20:56:17 volumio volumio[5590]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Feb 17 20:56:18 volumio volumio[5590]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 17 20:56:18 volumio volumio[5590]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 17 20:56:18 volumio volumio[5590]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Feb 17 20:56:18 volumio volumio-remote-updater[25144]: Test mode disabled Feb 17 20:56:18 volumio volumio-remote-updater[25144]: Alpha mode disabled Feb 17 20:56:18 volumio volumio-remote-updater[25144]: Alpha legacy test mode disabled Feb 17 20:56:18 volumio volumio[5590]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled Feb 17 20:56:18 volumio volumio[5590]: info: Update Ready: {"changeLogLink":"http://volumio.org","description":"

FIXES

\n
    \n
  • Fix for CPU utilization spike
    • \n
  • Fix for triggerhappy input permission
    • \n
\n

NEW ADDITIONS

\n
    \n
  • Add BLE onboarding plugin
    • \n
  • Enable vc4-kms-v3d for all compatible RPi models
    • \n
  • Update Tidal SDK
    • \n
\n","title":"Update v4.096","updateavailable":true} Feb 17 20:56:18 volumio volumio[5590]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Feb 17 20:56:19 volumio volumio[5590]: info: Getting Spotify volume Feb 17 20:56:19 volumio volumio[5590]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 17 20:56:19 volumio volumio[5590]: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 17 20:56:19 volumio volumio[5590]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Feb 17 20:56:19 volumio volumio[5590]: errno: -111, Feb 17 20:56:19 volumio volumio[5590]: code: 'ECONNREFUSED', Feb 17 20:56:19 volumio volumio[5590]: syscall: 'connect', Feb 17 20:56:19 volumio volumio[5590]: address: '127.0.0.1', Feb 17 20:56:19 volumio volumio[5590]: port: 9879, Feb 17 20:56:19 volumio volumio[5590]: response: undefined Feb 17 20:56:19 volumio volumio[5590]: } Feb 17 20:56:19 volumio volumio[5590]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 17 20:56:19 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Feb 17 20:56:19 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 17 20:56:19 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 17 20:56:19 volumio go-librespot[6066]: go-librespot daemon starting... Feb 17 20:56:19 volumio go-librespot[6067]: time="2026-02-17T20:56:19+07:00" level=info msg="running go-librespot 0.4.0" Feb 17 20:56:19 volumio go-librespot[6067]: time="2026-02-17T20:56:19+07:00" level=debug msg="app state loaded" Feb 17 20:56:19 volumio go-librespot[6067]: time="2026-02-17T20:56:19+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 17 20:56:20 volumio go-librespot[6067]: time="2026-02-17T20:56:20+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 17 20:56:20 volumio go-librespot[6067]: time="2026-02-17T20:56:20+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 17 20:56:20 volumio go-librespot[6067]: time="2026-02-17T20:56:20+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 17 20:56:20 volumio go-librespot[6067]: time="2026-02-17T20:56:20+07:00" level=info msg="zeroconf server listening on port 38185" Feb 17 20:56:20 volumio go-librespot[6067]: time="2026-02-17T20:56:20+07:00" level=debug msg="obtained new client token: AABrivfeFRqktyr0xak18kqj+6OBDUGsPe1mC+SXh8fOYKALLem8JwjeweC/TirgUHRPnZOIMqUtdrPqBOfJLw9x+YA1p1DyF19I3fIdA1PEuiP1jRAaFK4IUGGqo954Be9s9CDIaSc/Y67BQF/QZ96mT/DVwOPWhUZQt/PrT/qBNleik7PqWA82Zykml/BNA+fvQEMvdCsGgZOusomjD94eF9Zi4p0gFFmcfgHn9xi2P8KkzWZmsEzvZA==" Feb 17 20:56:20 volumio sudo[6077]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-17 20:55' Feb 17 20:56:20 volumio sudo[6077]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 17 20:56:20 volumio go-librespot[6067]: time="2026-02-17T20:56:20+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 17 20:56:20 volumio go-librespot[6067]: time="2026-02-17T20:56:20+07:00" level=debug msg="completed keyexchange" Feb 17 20:56:20 volumio go-librespot[6067]: time="2026-02-17T20:56:20+07:00" level=debug msg="completed challenge" Feb 17 20:56:21 volumio go-librespot[6067]: time="2026-02-17T20:56:21+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 17 20:56:21 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 17 20:56:21 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. 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"