Feb 07 09:29:00 volumio sudo[15332]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 07 09:29:00 volumio volumio[15174]: info: Volumio Network Manager: Network status updated: 1 Feb 07 09:29:00 volumio sudo[15332]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 09:29:00 volumio sudo[15334]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 07 09:29:00 volumio sudo[15334]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 09:29:00 volumio sudo[15332]: pam_unix(sudo:session): session closed for user root Feb 07 09:29:00 volumio sudo[15334]: pam_unix(sudo:session): session closed for user root Feb 07 09:29:00 volumio volumio[15174]: info: VolumeController:: Volume=100 Mute =false Feb 07 09:29:00 volumio volumio[15174]: info: CoreStateMachine::pushState Feb 07 09:29:00 volumio volumio[15174]: info: CorePlayQueue::getTrack 0 Feb 07 09:29:00 volumio volumio[15174]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 07 09:29:00 volumio volumio[15174]: info: CoreCommandRouter::volumioPushState Feb 07 09:29:00 volumio volumio[15174]: info: CoreStateMachine::updateTrackBlock Feb 07 09:29:00 volumio volumio[15174]: info: CorePlayQueue::getTrackBlock Feb 07 09:29:00 volumio volumio[15174]: info: CoreCommandRouter::volumioRetrievevolume Feb 07 09:29:00 volumio volumio-remote-updater[643]: [2026-02-07 09:29:00] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1770431338 101 Feb 07 09:29:00 volumio volumio[15174]: 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 07 09:29:00 volumio volumio[15174]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 09:29:00 volumio volumio[15174]: info: Reloading queue from file Feb 07 09:29:00 volumio volumio[15174]: info: CoreStateMachine::setRepeat null single undefined Feb 07 09:29:00 volumio volumio[15174]: info: CoreStateMachine::pushState Feb 07 09:29:00 volumio volumio[15174]: info: CorePlayQueue::getTrack 0 Feb 07 09:29:00 volumio volumio[15174]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 07 09:29:00 volumio volumio[15174]: info: CoreCommandRouter::volumioPushState Feb 07 09:29:00 volumio volumio[15174]: info: CoreStateMachine::setRandom null Feb 07 09:29:00 volumio volumio[15174]: info: CoreStateMachine::pushState Feb 07 09:29:00 volumio volumio[15174]: info: CorePlayQueue::getTrack 0 Feb 07 09:29:00 volumio volumio[15174]: info: CoreCommandRouter::volumioPushState Feb 07 09:29:00 volumio volumio[15174]: info: Setting Device type: Raspberry PI Feb 07 09:29:00 volumio volumio[15174]: info: Completed loading Core Plugins Feb 07 09:29:00 volumio volumio[15174]: info: Preparing to generate the ALSA configuration file Feb 07 09:29:00 volumio volumio[15174]: info: VolumeController:: Volume=100 Mute =false Feb 07 09:29:00 volumio volumio[15174]: info: CoreStateMachine::pushState Feb 07 09:29:00 volumio volumio[15174]: info: CorePlayQueue::getTrack 0 Feb 07 09:29:00 volumio volumio[15174]: info: CoreCommandRouter::volumioPushState Feb 07 09:29:00 volumio volumio[15174]: info: Asound.conf file unchanged, so no further update is needed Feb 07 09:29:00 volumio volumio[15174]: info: Output device has changed, restarting MPD Feb 07 09:29:01 volumio volumio[15174]: info: Output device has changed, restarting Shairport Sync Feb 07 09:29:01 volumio volumio[15174]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 09:29:01 volumio volumio[15174]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 09:29:01 volumio sudo[15347]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 07 09:29:01 volumio sudo[15347]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 09:29:01 volumio sudo[15349]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 07 09:29:01 volumio sudo[15349]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 09:29:01 volumio sudo[15349]: pam_unix(sudo:session): session closed for user root Feb 07 09:29:01 volumio sudo[15351]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 07 09:29:01 volumio sudo[15351]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 09:29:01 volumio volumio[15174]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 07 09:29:01 volumio volumio[15174]: info: ___________ START PLUGINS ___________ Feb 07 09:29:01 volumio volumio[15174]: info: ControllerMpd::onStart: Initializing MPD Feb 07 09:29:01 volumio volumio[15174]: info: Creating MPD Configuration file Feb 07 09:29:01 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 07 09:29:01 volumio sudo[15347]: pam_unix(sudo:session): session closed for user root Feb 07 09:29:01 volumio sudo[15360]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 07 09:29:01 volumio sudo[15360]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 09:29:01 volumio volumio[15174]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 07 09:29:01 volumio volumio[15174]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 07 09:29:01 volumio sudo[15360]: pam_unix(sudo:session): session closed for user root Feb 07 09:29:01 volumio volumio[15174]: info: [1770431341365] CoreMusicLibrary::Adding element Media Servers Feb 07 09:29:01 volumio volumio[15174]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 07 09:29:01 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 07 09:29:01 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 07 09:29:01 volumio systemd[1]: mpd.service: Consumed 7.205s CPU time. Feb 07 09:29:01 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 07 09:29:01 volumio volumio[15174]: info: UPNP Browser: Client initialized successfully Feb 07 09:29:01 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 07 09:29:01 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 07 09:29:01 volumio sudo[15362]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 07 09:29:01 volumio sudo[15362]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 09:29:01 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 07 09:29:01 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 07 09:29:01 volumio volumio[15174]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 09:29:01 volumio volumio[15174]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 09:29:01 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 18. Feb 07 09:29:01 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 07 09:29:01 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 07 09:29:01 volumio go-librespot[15371]: go-librespot daemon starting... Feb 07 09:29:01 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 07 09:29:01 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 07 09:29:01 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 07 09:29:01 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 07 09:29:01 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 07 09:29:01 volumio volumio[15174]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 07 09:29:01 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 07 09:29:01 volumio volumio[15174]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 09:29:01 volumio go-librespot[15372]: time="2026-02-07T09:29:01+07:00" level=info msg="running go-librespot 0.4.0" Feb 07 09:29:01 volumio go-librespot[15372]: time="2026-02-07T09:29:01+07:00" level=debug msg="app state loaded" Feb 07 09:29:01 volumio volumio[15174]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 09:29:01 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 07 09:29:01 volumio go-librespot[15372]: time="2026-02-07T09:29:01+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 07 09:29:01 volumio volumio[15174]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 07 09:29:01 volumio volumio[15174]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 07 09:29:01 volumio volumio[15174]: info: [1770431341801] CoreMusicLibrary::Adding element Last_100 Feb 07 09:29:01 volumio volumio[15174]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 07 09:29:01 volumio volumio[15174]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 07 09:29:01 volumio volumio[15174]: info: [1770431341830] CoreMusicLibrary::Adding element Webradio Feb 07 09:29:01 volumio volumio[15174]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 07 09:29:01 volumio volumio[15174]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 07 09:29:01 volumio volumio[15174]: info: Initializing BBC Radios Feb 07 09:29:02 volumio volumio[15174]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 07 09:29:02 volumio volumio[15174]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 09:29:02 volumio volumio[15174]: info: Creating Spotify config file Feb 07 09:29:02 volumio volumio[15174]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 09:29:02 volumio sudo[15379]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 07 09:29:02 volumio sudo[15379]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 07 09:29:02 volumio sudo[15379]: pam_unix(sudo:session): session closed for user root Feb 07 09:29:02 volumio go-librespot[15372]: time="2026-02-07T09:29:02+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 07 09:29:02 volumio go-librespot[15372]: time="2026-02-07T09:29:02+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 07 09:29:02 volumio go-librespot[15372]: time="2026-02-07T09:29:02+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 07 09:29:02 volumio go-librespot[15372]: time="2026-02-07T09:29:02+07:00" level=info msg="zeroconf server listening on port 40793" Feb 07 09:29:02 volumio go-librespot[15372]: time="2026-02-07T09:29:02+07:00" level=debug msg="obtained new client token: AABwCcPkbfMfPpe/1ZEv/aT8GQ0U4sX5TUH/7piXaIUTstvkVZ2L5iy3NEji92JKnDcz3/rCfzvRMEhRAyEcMUW7epQOFIg6EWgYd0Zuh6DxyhB90MrT4MlMHkeaclAD1YHb1mi4zyxPPH/mLXZiw/iGmk4n5T4OlIjpDexWmhvnul/oP5USZNCYtPjDiCepWXWiUoDHi9h5nCYUs1Qb3M4VJC1wAiRTnqBY4yRpxdC5pTY3Fpoj5iPjzw==" Feb 07 09:29:02 volumio go-librespot[15372]: time="2026-02-07T09:29:02+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 07 09:29:02 volumio go-librespot[15372]: time="2026-02-07T09:29:02+07:00" level=debug msg="completed keyexchange" Feb 07 09:29:02 volumio go-librespot[15372]: time="2026-02-07T09:29:02+07:00" level=debug msg="completed challenge" Feb 07 09:29:03 volumio volumio[15295]: Starting albumart workers Feb 07 09:29:03 volumio go-librespot[15372]: time="2026-02-07T09:29: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 07 09:29:03 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 07 09:29:03 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 07 09:29:03 volumio volumio[15174]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 07 09:29:03 volumio volumio[15174]: info: [1770431343354] CoreMusicLibrary::Adding element YouTube Music Feb 07 09:29:03 volumio volumio[15174]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 07 09:29:03 volumio volumio[15174]: Cannot find translation for source YouTube Music Feb 07 09:29:03 volumio volumio[15174]: info: Volumio Calling Home Feb 07 09:29:03 volumio volumio[15297]: Starting albumart workers Feb 07 09:29:03 volumio sudo[15401]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Feb 07 09:29:03 volumio sudo[15401]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 09:29:03 volumio sudo[15401]: pam_unix(sudo:session): session closed for user root Feb 07 09:29:03 volumio volumio[15296]: Starting albumart workers Feb 07 09:29:04 volumio volumio[15174]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Feb 07 09:29:04 volumio volumio[15174]: info: Discovery: Found device Volumio Feb 07 09:29:04 volumio volumio[15174]: info: CoreCommandRouter::volumioGetState Feb 07 09:29:04 volumio volumio[15174]: info: CorePlayQueue::getTrack 0 Feb 07 09:29:04 volumio volumio[15174]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Feb 07 09:29:04 volumio volumio[15174]: info: Discovery: Found device Volumio Feb 07 09:29:04 volumio volumio[15174]: info: CoreCommandRouter::volumioGetState Feb 07 09:29:04 volumio volumio[15174]: info: CorePlayQueue::getTrack 0 Feb 07 09:29:04 volumio volumio[15174]: info: MPD Permissions set Feb 07 09:29:04 volumio volumio[15174]: info: MPD Permissions set Feb 07 09:29:04 volumio volumio[15174]: info: Upmpdcli Daemon Started Feb 07 09:29:04 volumio volumio[15174]: info: Spotify config file written Feb 07 09:29:04 volumio sudo[15407]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 07 09:29:04 volumio sudo[15407]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 09:29:04 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 07 09:29:04 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 07 09:29:04 volumio go-librespot[15409]: go-librespot daemon starting... Feb 07 09:29:04 volumio sudo[15407]: pam_unix(sudo:session): session closed for user root Feb 07 09:29:04 volumio go-librespot[15410]: time="2026-02-07T09:29:04+07:00" level=info msg="running go-librespot 0.4.0" Feb 07 09:29:04 volumio go-librespot[15410]: time="2026-02-07T09:29:04+07:00" level=debug msg="app state loaded" Feb 07 09:29:04 volumio go-librespot[15410]: time="2026-02-07T09:29:04+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 07 09:29:04 volumio volumio[15174]: 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 07 09:29:04 volumio volumio[15174]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 09:29:04 volumio volumio[15174]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 09:29:04 volumio volumio[15174]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 09:29:04 volumio volumio[15174]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 09:29:04 volumio volumio[15174]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 09:29:04 volumio volumio[15174]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 09:29:04 volumio volumio[15174]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 09:29:04 volumio volumio[15174]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 09:29:04 volumio volumio[15174]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 09:29:04 volumio volumio[15174]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 09:29:04 volumio volumio[15174]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 09:29:04 volumio volumio[15174]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 09:29:04 volumio volumio[15174]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 09:29:04 volumio volumio[15174]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 09:29:04 volumio volumio[15174]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 09:29:04 volumio volumio[15174]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 09:29:04 volumio volumio[15174]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 09:29:04 volumio volumio[15174]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 09:29:05 volumio volumio[15174]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 09:29:05 volumio volumio[15174]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 09:29:05 volumio volumio[15174]: info: No need to fix Spotify hosts Feb 07 09:29:05 volumio go-librespot[15410]: time="2026-02-07T09:29: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 07 09:29:05 volumio go-librespot[15410]: time="2026-02-07T09:29:05+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 07 09:29:05 volumio go-librespot[15410]: time="2026-02-07T09:29:05+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 07 09:29:05 volumio go-librespot[15410]: time="2026-02-07T09:29:05+07:00" level=info msg="zeroconf server listening on port 42463" Feb 07 09:29:05 volumio volumio[15174]: info: Volumio called home Feb 07 09:29:05 volumio go-librespot[15410]: time="2026-02-07T09:29:05+07:00" level=debug msg="obtained new client token: AACC5ODfUmgi9hxtmd7MzCVXLzNSZ5SEyEy05RDmJZH4zHfj8hWqJoe8vOlKahMC9nD/i6sqcZwighlV9+e6ZYfJPE+r3qXM6ujjw+uzB/tHr52mqviOOCaRSb8sfnLFXQdgfKmn2teIWbE3++x+erSK7H77dVbvuK42rCZnhClUoD3izV76zc9HoP604vycfmnJFEM6YTquHGFHrPbtydUZ6tXbZQqH0i4OkBlB2Vx6anTiZJduPQEU8Q==" Feb 07 09:29:05 volumio go-librespot[15410]: time="2026-02-07T09:29:05+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 07 09:29:05 volumio go-librespot[15410]: time="2026-02-07T09:29:05+07:00" level=debug msg="completed keyexchange" Feb 07 09:29:05 volumio go-librespot[15410]: time="2026-02-07T09:29:05+07:00" level=debug msg="completed challenge" Feb 07 09:29:06 volumio go-librespot[15410]: time="2026-02-07T09:29: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 07 09:29:06 volumio volumio[15174]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 07 09:29:06 volumio volumio[15174]: SPOTIFY: BQA_W9H160I5vXuMQmRg1YEWkrGsvQFS3qE62C7tyRxbECtY3uw8Eg9wjf0h-QZCVznlRHFDO3g-zA9hLnT3ay2kcNCYrl8MULIS1f6MLpEClEJHMpJYVhERB3Qvo4U9xjQkvvQXHSkLuNjRQOiRguis_5Jl56ZDLhQUhegscf_6ueLW3_Pq3NrFReG-fneOKzV9ok7mEDzZ94tUbujG75lJgaoPiW-ex0CRbe6AbIjeoNOEQw7wM5NcALBWyI8UfGzGHTZRuohIUe7CB_gGdnGkRkt5V_g2QLIqKb8ZCjAyowZ0HvSGlXrP Feb 07 09:29:06 volumio volumio[15174]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 07 09:29:06 volumio volumio[15174]: info: New Spotify access token = BQA_W9H160I5vXuMQmRg1YEWkrGsvQFS3qE62C7tyRxbECtY3uw8Eg9wjf0h-QZCVznlRHFDO3g-zA9hLnT3ay2kcNCYrl8MULIS1f6MLpEClEJHMpJYVhERB3Qvo4U9xjQkvvQXHSkLuNjRQOiRguis_5Jl56ZDLhQUhegscf_6ueLW3_Pq3NrFReG-fneOKzV9ok7mEDzZ94tUbujG75lJgaoPiW-ex0CRbe6AbIjeoNOEQw7wM5NcALBWyI8UfGzGHTZRuohIUe7CB_gGdnGkRkt5V_g2QLIqKb8ZCjAyowZ0HvSGlXrP Feb 07 09:29:06 volumio volumio[15174]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 07 09:29:06 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 07 09:29:06 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 07 09:29:06 volumio volumio[15174]: info: Starting Shairport Sync Feb 07 09:29:06 volumio volumio[15174]: info: Starting Shairport Sync Feb 07 09:29:06 volumio volumio[15174]: info: Starting Shairport Sync Feb 07 09:29:06 volumio sudo[15447]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 07 09:29:06 volumio sudo[15447]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 09:29:06 volumio sudo[15449]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 07 09:29:06 volumio sudo[15449]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 09:29:06 volumio sudo[15451]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 07 09:29:06 volumio sudo[15451]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 09:29:06 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 07 09:29:06 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 07 09:29:06 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 07 09:29:06 volumio systemd[1]: shairport-sync.service: Consumed 2.301s CPU time. Feb 07 09:29:06 volumio volumio[15174]: info: CoreCommandRouter::volumioGetState Feb 07 09:29:06 volumio volumio[15174]: info: CorePlayQueue::getTrack 0 Feb 07 09:29:06 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 07 09:29:06 volumio sudo[15449]: pam_unix(sudo:session): session closed for user root Feb 07 09:29:06 volumio sudo[15447]: pam_unix(sudo:session): session closed for user root Feb 07 09:29:06 volumio sudo[15451]: pam_unix(sudo:session): session closed for user root Feb 07 09:29:06 volumio volumio[15174]: info: Shairport-Sync Started Feb 07 09:29:06 volumio volumio[15174]: Error adding Membership: Error: addMembership EINVAL Feb 07 09:29:06 volumio volumio[15174]: info: Shairport-Sync Started Feb 07 09:29:06 volumio volumio[15174]: info: Shairport-Sync Started Feb 07 09:29:06 volumio volumio[15174]: 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 07 09:29:06 volumio volumio[15174]: info: Spotify Successfully logged in Feb 07 09:29:06 volumio volumio[15174]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 07 09:29:06 volumio volumio[15174]: info: [1770431346865] CoreMusicLibrary::Adding element Spotify Feb 07 09:29:06 volumio volumio[15174]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 07 09:29:06 volumio volumio[15174]: Cannot find translation for source YouTube Music Feb 07 09:29:06 volumio volumio[15174]: Cannot find translation for source Spotify Feb 07 09:29:07 volumio volumio[15174]: info: [yt-cast-receiver] DIAL server listening on port 8098 Feb 07 09:29:07 volumio volumio[15174]: info: CoreCommandRouter::volumioRetrievevolume Feb 07 09:29:08 volumio volumio[15174]: info: VolumeController:: Volume=100 Mute =false Feb 07 09:29:08 volumio volumio[15174]: info: CoreCommandRouter::volumioGetState Feb 07 09:29:08 volumio volumio[15174]: info: CorePlayQueue::getTrack 0 Feb 07 09:29:08 volumio volumio[15174]: info: CoreStateMachine::pushState Feb 07 09:29:08 volumio volumio[15174]: info: CorePlayQueue::getTrack 0 Feb 07 09:29:08 volumio volumio[15174]: info: CoreCommandRouter::volumioPushState Feb 07 09:29:08 volumio volumio[15174]: info: go-librespot daemon successfully initialized Feb 07 09:29:09 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 19. Feb 07 09:29:09 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 07 09:29:09 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 07 09:29:09 volumio go-librespot[15486]: go-librespot daemon starting... Feb 07 09:29:09 volumio go-librespot[15487]: time="2026-02-07T09:29:09+07:00" level=info msg="running go-librespot 0.4.0" Feb 07 09:29:09 volumio go-librespot[15487]: time="2026-02-07T09:29:09+07:00" level=debug msg="app state loaded" Feb 07 09:29:09 volumio go-librespot[15487]: time="2026-02-07T09:29:09+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 07 09:29:09 volumio mpd[15399]: 2026-02-07T09:29:09 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 07 09:29:09 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 07 09:29:09 volumio sudo[15362]: pam_unix(sudo:session): session closed for user root Feb 07 09:29:09 volumio sudo[15351]: pam_unix(sudo:session): session closed for user root Feb 07 09:29:09 volumio volumio[15174]: error: MPD error: The expression evaluated to a falsy value: Feb 07 09:29:09 volumio volumio[15174]: assert.ok(self.idling) Feb 07 09:29:09 volumio volumio[15174]: error: The expression evaluated to a falsy value: Feb 07 09:29:09 volumio volumio[15174]: assert.ok(self.idling) Feb 07 09:29:09 volumio volumio[15174]: error: updateQueue error: null Feb 07 09:29:09 volumio volumio[15174]: info: MPD running with PID15399 Feb 07 09:29:09 volumio volumio[15174]: ,establishing connection Feb 07 09:29:09 volumio go-librespot[15487]: time="2026-02-07T09:29:09+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 07 09:29:09 volumio go-librespot[15487]: time="2026-02-07T09:29:09+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 07 09:29:09 volumio go-librespot[15487]: time="2026-02-07T09:29:09+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 07 09:29:09 volumio go-librespot[15487]: time="2026-02-07T09:29:09+07:00" level=info msg="zeroconf server listening on port 33293" Feb 07 09:29:09 volumio volumio[15174]: info: Completed starting Core Plugins Feb 07 09:29:09 volumio volumio[15174]: info: ------------------------------------------- Feb 07 09:29:09 volumio volumio[15174]: info: ----- MyVolumio plugins startup ---- Feb 07 09:29:09 volumio volumio[15174]: info: ------------------------------------------- Feb 07 09:29:09 volumio volumio[15174]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 07 09:29:09 volumio volumio[15174]: error: updateQueue error: null Feb 07 09:29:09 volumio go-librespot[15487]: time="2026-02-07T09:29:09+07:00" level=debug msg="obtained new client token: AAB2/KxdRjfy2mK0x0TjAkBdbPhshZwVOmLPoz7yKHxMzSC9429WcXwKTzo1QB1m+DEQRRc8i+mFdtvaCbpM1Ktg8zQOdrp+HQf5JH40hMw4na2USS/xHeXmN7KdLDmHK0H7+vQ3jG5YWleQ3YicHAv/lbpjrGF8z8IShlQ+fhjujVc/R+t4HjQ0t3ByUBcw/SDZ9/+CIfXZGg6x+L2ZF7EO2dnfyqs/jGaftA6qaMOAih3i4/PSwhq/8w==" Feb 07 09:29:09 volumio go-librespot[15487]: time="2026-02-07T09:29:09+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 07 09:29:10 volumio go-librespot[15487]: time="2026-02-07T09:29:10+07:00" level=debug msg="completed keyexchange" Feb 07 09:29:10 volumio go-librespot[15487]: time="2026-02-07T09:29:10+07:00" level=debug msg="completed challenge" Feb 07 09:29:10 volumio go-librespot[15487]: time="2026-02-07T09:29: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 07 09:29:10 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 07 09:29:10 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 07 09:29:11 volumio volumio[15174]: info: Initializing connection to go-librespot Websocket Feb 07 09:29:11 volumio volumio[15174]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 07 09:29:13 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 20. Feb 07 09:29:13 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 07 09:29:13 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 07 09:29:13 volumio go-librespot[15500]: go-librespot daemon starting... Feb 07 09:29:13 volumio go-librespot[15501]: time="2026-02-07T09:29:13+07:00" level=info msg="running go-librespot 0.4.0" Feb 07 09:29:13 volumio go-librespot[15501]: time="2026-02-07T09:29:13+07:00" level=debug msg="app state loaded" Feb 07 09:29:13 volumio go-librespot[15501]: time="2026-02-07T09:29:13+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 07 09:29:13 volumio go-librespot[15501]: time="2026-02-07T09:29:13+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 07 09:29:13 volumio go-librespot[15501]: time="2026-02-07T09:29:13+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 07 09:29:13 volumio go-librespot[15501]: time="2026-02-07T09:29:13+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 07 09:29:13 volumio go-librespot[15501]: time="2026-02-07T09:29:13+07:00" level=info msg="zeroconf server listening on port 42199" Feb 07 09:29:14 volumio go-librespot[15501]: time="2026-02-07T09:29:14+07:00" level=debug msg="obtained new client token: AAD01uo66D8YyMYxhHBxGcP2e2zo2WOWEcRnrSBsKMXg2NdBTHgwuVDL8YRE2oHeOYXkjXSLoL6tfDMMySJX5EwXrBvwnCvrz7OvWdhKzUSeXHg0MXpf9eW7ZPLbLthCFgr+mybzjQ8OLWJ5+Q/hCDguNLnGm9WKM/cotiMIJyTOBo5ipDhEW9Zfmg3luqY5GWkgNtABXzSQ7HtiUu2/p8tioT3ipnZJEj6DjN/RNC0AqH37umoEWeI=" Feb 07 09:29:14 volumio go-librespot[15501]: time="2026-02-07T09:29:14+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 07 09:29:14 volumio go-librespot[15501]: time="2026-02-07T09:29:14+07:00" level=debug msg="completed keyexchange" Feb 07 09:29:14 volumio go-librespot[15501]: time="2026-02-07T09:29:14+07:00" level=debug msg="completed challenge" Feb 07 09:29:14 volumio go-librespot[15501]: time="2026-02-07T09:29: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 07 09:29:14 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 07 09:29:14 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 07 09:29:14 volumio volumio[15174]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 07 09:29:14 volumio volumio[15174]: info: Initializing connection to go-librespot Websocket Feb 07 09:29:14 volumio volumio[15174]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 07 09:29:17 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 21. Feb 07 09:29:17 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 07 09:29:17 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 07 09:29:17 volumio go-librespot[15508]: go-librespot daemon starting... Feb 07 09:29:17 volumio go-librespot[15509]: time="2026-02-07T09:29:17+07:00" level=info msg="running go-librespot 0.4.0" Feb 07 09:29:17 volumio go-librespot[15509]: time="2026-02-07T09:29:17+07:00" level=debug msg="app state loaded" Feb 07 09:29:17 volumio go-librespot[15509]: time="2026-02-07T09:29:17+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 07 09:29:17 volumio volumio[15174]: info: Initializing connection to go-librespot Websocket Feb 07 09:29:17 volumio go-librespot[15509]: time="2026-02-07T09:29:17+07:00" level=debug msg="new websocket client" Feb 07 09:29:17 volumio volumio[15174]: info: Connection to go-librespot Websocket established Feb 07 09:29:18 volumio go-librespot[15509]: time="2026-02-07T09:29: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 07 09:29:18 volumio go-librespot[15509]: time="2026-02-07T09:29: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 07 09:29:18 volumio go-librespot[15509]: time="2026-02-07T09:29: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 07 09:29:18 volumio go-librespot[15509]: time="2026-02-07T09:29:18+07:00" level=info msg="zeroconf server listening on port 34695" Feb 07 09:29:18 volumio go-librespot[15509]: time="2026-02-07T09:29:18+07:00" level=debug msg="obtained new client token: AADhOds2ztXW+uF5kFxyAp5aKqhrwx3KX8GFrXu+dffBcXN2agZWHCcn2Fl5xxnxkK+zjd8FOaNqI2vrwtikkz0JZNNVPfd2AkIDnOYjdRGo0QMEuIY6rrqdq6fmUhi/o0gvIPQzcDS5syGTPk6zCMGYcB716Nr67YG4Bxw4BqxDwWGswqEc2jd1ORs5yWyAtKRqAb6HfeOYic23KREvUMAjzsfXb99WNX/MY2QPEt4BJTFrABJEnspXZA==" Feb 07 09:29:18 volumio volumio[15174]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 07 09:29:18 volumio volumio[15174]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 07 09:29:18 volumio volumio[15174]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 07 09:29:18 volumio volumio[15174]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 07 09:29:18 volumio volumio[15174]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 07 09:29:18 volumio volumio[15174]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 07 09:29:18 volumio volumio[15174]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 07 09:29:18 volumio volumio[15174]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 07 09:29:18 volumio volumio[15174]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 07 09:29:18 volumio volumio[15174]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 07 09:29:18 volumio volumio[15174]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 07 09:29:18 volumio volumio[15174]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 07 09:29:18 volumio volumio[15174]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 07 09:29:18 volumio volumio[15174]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 07 09:29:18 volumio volumio[15174]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 07 09:29:18 volumio volumio[15174]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 07 09:29:18 volumio volumio[15174]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 07 09:29:18 volumio volumio[15174]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 07 09:29:18 volumio volumio[15174]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 07 09:29:18 volumio volumio[15174]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 07 09:29:18 volumio volumio[15174]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 07 09:29:18 volumio volumio[15174]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 07 09:29:18 volumio volumio[15174]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 07 09:29:18 volumio volumio[15174]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 07 09:29:18 volumio volumio[15174]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 07 09:29:18 volumio volumio[15174]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 07 09:29:18 volumio volumio[15174]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 07 09:29:18 volumio volumio[15174]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 07 09:29:18 volumio volumio[15174]: info: Adding plugin bluetooth to MyMusic Plugins Feb 07 09:29:18 volumio volumio[15174]: info: Adding plugin multiroom to MyMusic Plugins Feb 07 09:29:18 volumio volumio[15174]: info: Adding plugin metavolumio to MyMusic Plugins Feb 07 09:29:18 volumio go-librespot[15509]: time="2026-02-07T09:29:18+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 07 09:29:18 volumio volumio[15174]: info: Adding plugin cd_controller to MyMusic Plugins Feb 07 09:29:18 volumio volumio[15174]: info: Adding plugin qobuzconnect to MyMusic Plugins Feb 07 09:29:18 volumio volumio[15174]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 07 09:29:18 volumio volumio[15174]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 07 09:29:18 volumio volumio[15174]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 07 09:29:18 volumio go-librespot[15509]: time="2026-02-07T09:29:18+07:00" level=debug msg="completed keyexchange" Feb 07 09:29:18 volumio go-librespot[15509]: time="2026-02-07T09:29:18+07:00" level=debug msg="completed challenge" Feb 07 09:29:18 volumio go-librespot[15509]: time="2026-02-07T09:29:18+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 07 09:29:18 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 07 09:29:18 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 07 09:29:20 volumio volumio[15174]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 07 09:29:20 volumio volumio[15174]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 07 09:29:20 volumio volumio[15174]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 09:29:20 volumio volumio[15174]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 09:29:20 volumio volumio[15174]: info: Starting MyVolumio Remote Streaming Endpoints Feb 07 09:29:20 volumio volumio[15174]: info: MyVolumio login type: Token Feb 07 09:29:20 volumio volumio[15174]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 07 09:29:20 volumio volumio[15174]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 07 09:29:21 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 22. Feb 07 09:29:21 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 07 09:29:21 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 07 09:29:21 volumio go-librespot[15532]: go-librespot daemon starting... Feb 07 09:29:21 volumio go-librespot[15533]: time="2026-02-07T09:29:21+07:00" level=info msg="running go-librespot 0.4.0" Feb 07 09:29:21 volumio go-librespot[15533]: time="2026-02-07T09:29:21+07:00" level=debug msg="app state loaded" Feb 07 09:29:21 volumio go-librespot[15533]: time="2026-02-07T09:29:21+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 07 09:29:22 volumio volumio[15174]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 07 09:29:22 volumio volumio[15174]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 07 09:29:22 volumio volumio[15174]: info: Streaming services startup Feb 07 09:29:22 volumio volumio[15174]: info: Starting Streaming Daemon Feb 07 09:29:22 volumio sudo[15541]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 07 09:29:22 volumio sudo[15541]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 09:29:22 volumio volumio[15174]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 07 09:29:22 volumio sudo[15541]: pam_unix(sudo:session): session closed for user root Feb 07 09:29:22 volumio volumio[15174]: info: Getting Spotify volume Feb 07 09:29:22 volumio volumio[15174]: info: Connection to go-librespot Websocket closed Feb 07 09:29:22 volumio volumio[15174]: error: Cannot start Volumio Streaming Daemon Feb 07 09:29:22 volumio volumio[15174]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 07 09:29:22 volumio volumio[15174]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 07 09:29:22 volumio volumio[15174]: 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 07 09:29:22 volumio go-librespot[15533]: time="2026-02-07T09:29:22+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 07 09:29:22 volumio go-librespot[15533]: time="2026-02-07T09:29:22+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 07 09:29:22 volumio go-librespot[15533]: time="2026-02-07T09:29:22+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 07 09:29:22 volumio go-librespot[15533]: time="2026-02-07T09:29:22+07:00" level=info msg="zeroconf server listening on port 41375" Feb 07 09:29:22 volumio volumio[15174]: info: CoreCommandRouter::volumioGetState Feb 07 09:29:22 volumio volumio[15174]: info: CorePlayQueue::getTrack 0 Feb 07 09:29:22 volumio volumio[15174]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Feb 07 09:29:22 volumio volumio[15174]: SPOTIFY: SPOTIFY VOLUME undefined Feb 07 09:29:22 volumio volumio[15174]: SPOTIFY: VOLUMIO VOLUME 100 Feb 07 09:29:22 volumio volumio[15174]: info: Aligning Spotify Volume to Volumio Volume Feb 07 09:29:22 volumio volumio[15174]: info: CoreCommandRouter::volumioGetState Feb 07 09:29:22 volumio volumio[15174]: info: CorePlayQueue::getTrack 0 Feb 07 09:29:22 volumio volumio[15174]: info: Setting Spotify Volume from Volumio: 100 Feb 07 09:29:22 volumio go-librespot[15533]: time="2026-02-07T09:29:22+07:00" level=debug msg="obtained new client token: AADvry3TTRZ9+ZJbLxKAu4LSjhNzy+qaDjGsw9BdaVpySaZwFo3LYNaPulTysCWU5tIAKY8Ho2algnwfPmzWJJL3RoJXsz/N7P5usnBiM1VqJV4KeJjxCx+4MfmRsTEQdb6h6TRf0iFI2UYQ0cbsSrX1tYWJRtiH5m7ocLt2Lcy5ZMFC63fgaOzy0+uFBqVWCgaZ9R44hnvRwtMfYZCTdQSJSpKmG4u1KMDsdLqsQhliTK4bpqLu63uPig==" Feb 07 09:29:22 volumio go-librespot[15533]: time="2026-02-07T09:29:22+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 07 09:29:22 volumio go-librespot[15533]: time="2026-02-07T09:29:22+07:00" level=debug msg="completed keyexchange" Feb 07 09:29:22 volumio go-librespot[15533]: time="2026-02-07T09:29:22+07:00" level=debug msg="completed challenge" Feb 07 09:29:23 volumio go-librespot[15533]: time="2026-02-07T09:29: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 07 09:29:23 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 07 09:29:23 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 07 09:29:23 volumio volumio[15174]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 07 09:29:23 volumio volumio[15174]: Error: socket hang up Feb 07 09:29:23 volumio volumio[15174]: at connResetException (node:internal/errors:720:14) Feb 07 09:29:23 volumio volumio[15174]: at Socket.socketOnEnd (node:_http_client:519:23) Feb 07 09:29:23 volumio volumio[15174]: at Socket.emit (node:events:526:35) Feb 07 09:29:23 volumio volumio[15174]: at endReadableNT (node:internal/streams/readable:1376:12) Feb 07 09:29:23 volumio volumio[15174]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Feb 07 09:29:23 volumio volumio[15174]: code: 'ECONNRESET', Feb 07 09:29:23 volumio volumio[15174]: response: undefined Feb 07 09:29:23 volumio volumio[15174]: } Feb 07 09:29:23 volumio volumio[15174]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 07 09:29:24 volumio sudo[15562]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-07 09:28' Feb 07 09:29:24 volumio sudo[15562]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 09:29:24 volumio sudo[15562]: pam_unix(sudo:session): session closed for user root Feb 07 09:29:26 volumio volumio-remote-updater[643]: [2026-02-07 09:29:26] [error] handle_read_frame error: asio.system:104 (Connection reset by peer) Feb 07 09:29:26 volumio volumio-remote-updater[643]: [2026-02-07 09:29:26] [disconnect] Disconnect close local:[1006,Connection reset by peer] remote:[1006] Feb 07 09:29:26 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Feb 07 09:29:26 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 23. Feb 07 09:29:26 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 07 09:29:26 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 07 09:29:26 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Feb 07 09:29:26 volumio go-librespot[15570]: go-librespot daemon starting... Feb 07 09:29:26 volumio systemd[1]: volumio.service: Consumed 55.630s CPU time. Feb 07 09:29:26 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 07 09:29:26 volumio go-librespot[15571]: time="2026-02-07T09:29:26+07:00" level=info msg="running go-librespot 0.4.0" Feb 07 09:29:26 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 07 09:29:26 volumio go-librespot[15571]: time="2026-02-07T09:29:26+07:00" level=debug msg="app state loaded" Feb 07 09:29:26 volumio go-librespot[15571]: time="2026-02-07T09:29:26+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 07 09:29:26 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 5578. Feb 07 09:29:26 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 07 09:29:26 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Feb 07 09:29:26 volumio systemd[1]: volumio.service: Consumed 55.630s CPU time. Feb 07 09:29:26 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Feb 07 09:29:26 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 07 09:29:26 volumio go-librespot[15571]: time="2026-02-07T09:29:26+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 07 09:29:26 volumio go-librespot[15571]: time="2026-02-07T09:29:26+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 07 09:29:26 volumio go-librespot[15571]: time="2026-02-07T09:29:26+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 07 09:29:26 volumio go-librespot[15571]: time="2026-02-07T09:29:26+07:00" level=info msg="zeroconf server listening on port 42787" Feb 07 09:29:27 volumio go-librespot[15571]: time="2026-02-07T09:29:27+07:00" level=debug msg="obtained new client token: AAA+ghOd5JVww7gvsFailT5d/zWQkvXQfi2ocVHMct/7iB1BCHUeB//BKC0ffcutXcePtPXVCshXLhHiyxsNzPx0RR90zaFudNWiDMuFvZmZ1aUiFxkwuP/PiJes1FPLVi/JE5jCFI6+7LBNsTRXvWI6pa/3oCVGI3fTz9YLqt2uclIXUzDYUkdS6s13V21OT7ns2SuxKXj6t6g2jJitbRQNCOHGHcZd/v99KVJRwgOwgrkvCbbgd5A=" Feb 07 09:29:27 volumio go-librespot[15571]: time="2026-02-07T09:29:27+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 07 09:29:27 volumio go-librespot[15571]: time="2026-02-07T09:29:27+07:00" level=debug msg="completed keyexchange" Feb 07 09:29:27 volumio go-librespot[15571]: time="2026-02-07T09:29:27+07:00" level=debug msg="completed challenge" Feb 07 09:29:27 volumio go-librespot[15571]: time="2026-02-07T09:29:27+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 07 09:29:27 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 07 09:29:27 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 07 09:29:30 volumio volumio[15584]: info: ------------------------------------------- Feb 07 09:29:30 volumio volumio[15584]: info: ----- Volumio3 ---- Feb 07 09:29:30 volumio volumio[15584]: info: ------------------------------------------- Feb 07 09:29:30 volumio volumio[15584]: info: ----- System startup ---- Feb 07 09:29:30 volumio volumio[15584]: info: ------------------------------------------- Feb 07 09:29:30 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 24. Feb 07 09:29:30 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 07 09:29:30 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 07 09:29:30 volumio go-librespot[15606]: go-librespot daemon starting... Feb 07 09:29:30 volumio go-librespot[15607]: time="2026-02-07T09:29:30+07:00" level=info msg="running go-librespot 0.4.0" Feb 07 09:29:30 volumio go-librespot[15607]: time="2026-02-07T09:29:30+07:00" level=debug msg="app state loaded" Feb 07 09:29:30 volumio go-librespot[15607]: time="2026-02-07T09:29:30+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 07 09:29:31 volumio go-librespot[15607]: time="2026-02-07T09:29: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-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 07 09:29:31 volumio go-librespot[15607]: time="2026-02-07T09:29:31+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 07 09:29:31 volumio go-librespot[15607]: time="2026-02-07T09:29:31+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 07 09:29:31 volumio go-librespot[15607]: time="2026-02-07T09:29:31+07:00" level=info msg="zeroconf server listening on port 44157" Feb 07 09:29:31 volumio volumio-remote-updater[643]: [2026-02-07 09:29:31] [connect] Successful connection Feb 07 09:29:31 volumio go-librespot[15607]: time="2026-02-07T09:29:31+07:00" level=debug msg="obtained new client token: AABaRHuhQ8RRR/wXDeB2BJ+D9lcPaY+sz2rkRRIgTljF2spx+ejJgAx+ZYQHdSfmwS6EPhTGOHIYrZRivNC2D7ewaYH3dja67K7X0LWQPVn/PD+WVj9GSVHONmfos7zuC5Mk8wppHvsFKq3LbB44VFofsCKZk6UycohL5Tl0r39uQWcvhdE/vOQc71INV1Odb9+T0oL22HHRxY9YmTPEGkXE0yFb0brCeK3kB7xN0ZHwTspBD8j6j1Ht1g==" Feb 07 09:29:31 volumio volumio[15584]: info: MYVOLUMIO Environment detected Feb 07 09:29:31 volumio go-librespot[15607]: time="2026-02-07T09:29:31+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 07 09:29:31 volumio volumio[15584]: info: Plugin folders cleanup Feb 07 09:29:31 volumio volumio[15584]: info: Scanning into folder /volumio/app/plugins/ Feb 07 09:29:31 volumio volumio[15584]: info: Scanning category audio_interface Feb 07 09:29:31 volumio volumio[15584]: info: Scanning category miscellanea Feb 07 09:29:31 volumio volumio[15584]: info: Scanning category music_service Feb 07 09:29:31 volumio volumio[15584]: info: Scanning category plugins.json Feb 07 09:29:31 volumio volumio[15584]: info: Scanning category system_controller Feb 07 09:29:31 volumio volumio[15584]: info: Scanning category user_interface Feb 07 09:29:31 volumio volumio[15584]: info: Scanning into folder /data/plugins/ Feb 07 09:29:31 volumio volumio[15584]: info: Scanning category music_service Feb 07 09:29:31 volumio volumio[15584]: info: Plugin folders cleanup completed Feb 07 09:29:31 volumio volumio[15584]: info: ------------------------------------------- Feb 07 09:29:31 volumio volumio[15584]: info: ----- Core plugins startup ---- Feb 07 09:29:31 volumio volumio[15584]: info: ------------------------------------------- Feb 07 09:29:31 volumio volumio[15584]: info: Loading plugins from folder /volumio/app/plugins/ Feb 07 09:29:31 volumio volumio[15584]: info: Adding plugin upnp to MyMusic Plugins Feb 07 09:29:31 volumio volumio[15584]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 07 09:29:31 volumio volumio[15584]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 07 09:29:31 volumio volumio[15584]: info: Loading plugins from folder /data/plugins/ Feb 07 09:29:31 volumio go-librespot[15607]: time="2026-02-07T09:29:31+07:00" level=debug msg="completed keyexchange" Feb 07 09:29:31 volumio go-librespot[15607]: time="2026-02-07T09:29:31+07:00" level=debug msg="completed challenge" Feb 07 09:29:31 volumio volumio[15584]: info: Loading plugin "system"... Feb 07 09:29:31 volumio go-librespot[15607]: time="2026-02-07T09:29:31+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 07 09:29:31 volumio volumio[15584]: info: Loading plugin "appearance"... Feb 07 09:29:31 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 07 09:29:31 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 07 09:29:33 volumio volumio[15584]: info: Loading plugin "network"... Feb 07 09:29:33 volumio volumio[15584]: info: Refreshing Cached IP Addresses Feb 07 09:29:33 volumio sudo[15622]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 07 09:29:33 volumio sudo[15622]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 09:29:33 volumio volumio[15584]: info: Loading plugin "services"... Feb 07 09:29:33 volumio sudo[15624]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 07 09:29:33 volumio sudo[15624]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 09:29:33 volumio sudo[15622]: pam_unix(sudo:session): session closed for user root Feb 07 09:29:33 volumio volumio[15584]: info: Loading plugin "alsa_controller"... Feb 07 09:29:33 volumio sudo[15624]: pam_unix(sudo:session): session closed for user root Feb 07 09:29:33 volumio sudo[15636]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 07 09:29:33 volumio sudo[15636]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 09:29:34 volumio volumio[15584]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 07 09:29:34 volumio volumio[15584]: info: Loading plugin "wizard"... Feb 07 09:29:34 volumio volumio[15584]: info: Loading plugin "networkfs"... Feb 07 09:29:34 volumio volumio[15584]: info: Starting Udev Watcher for removable devices Feb 07 09:29:34 volumio volumio[15584]: info: Ignoring mount for partition: boot Feb 07 09:29:34 volumio volumio[15584]: info: Ignoring mount for partition: volumio Feb 07 09:29:34 volumio volumio[15584]: info: Ignoring mount for partition: volumio_data Feb 07 09:29:34 volumio volumio[15584]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 07 09:29:34 volumio volumio[15584]: info: Loading plugin "volumio_command_line_client"... Feb 07 09:29:34 volumio volumio[15584]: info: Loading plugin "upnp"... Feb 07 09:29:34 volumio volumio[15584]: info: [1770431374167] Starting Upmpd Daemon Feb 07 09:29:34 volumio volumio[15584]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 07 09:29:34 volumio volumio[15584]: info: Loading plugin "my_music"... Feb 07 09:29:34 volumio volumio[15584]: info: Loading plugin "mpd"... Feb 07 09:29:34 volumio volumio[15584]: info: Loading plugin "upnp_browser"... Feb 07 09:29:35 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 25. Feb 07 09:29:35 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 07 09:29:35 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 07 09:29:35 volumio go-librespot[15655]: go-librespot daemon starting... Feb 07 09:29:35 volumio go-librespot[15656]: time="2026-02-07T09:29:35+07:00" level=info msg="running go-librespot 0.4.0" Feb 07 09:29:35 volumio go-librespot[15656]: time="2026-02-07T09:29:35+07:00" level=debug msg="app state loaded" Feb 07 09:29:35 volumio go-librespot[15656]: time="2026-02-07T09:29:35+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 07 09:29:35 volumio go-librespot[15656]: time="2026-02-07T09:29: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-gew4.spotify.com:80]" Feb 07 09:29:35 volumio go-librespot[15656]: time="2026-02-07T09:29:35+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 07 09:29:35 volumio go-librespot[15656]: time="2026-02-07T09:29:35+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 07 09:29:35 volumio go-librespot[15656]: time="2026-02-07T09:29:35+07:00" level=info msg="zeroconf server listening on port 34855" Feb 07 09:29:35 volumio go-librespot[15656]: time="2026-02-07T09:29:35+07:00" level=debug msg="obtained new client token: AADA62aGvoTBL7En6CpZ4rID19y4XRbQDBCZpT+j+WyfGSwQHmsnFc/dBJzXzI7zBEM5IAcOuM5e2tdUw/YvkH3qTWSDmvEqH6fveKV68tn83icbgWrWUDrwoODH2dwhTHOFeLECDFjpsedpl7uAJtji0fI/IX33/mZ8KVMYuTzAugLhw752dLRz8WMJr31iSgRYTtCLgwlSqMBAyVJikbVPkI3D0WOCh+tyO89RSu/ZmdbeUf8p65rW8w==" Feb 07 09:29:36 volumio go-librespot[15656]: time="2026-02-07T09:29:36+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 07 09:29:36 volumio go-librespot[15656]: time="2026-02-07T09:29:36+07:00" level=debug msg="completed keyexchange" Feb 07 09:29:36 volumio go-librespot[15656]: time="2026-02-07T09:29:36+07:00" level=debug msg="completed challenge" Feb 07 09:29:36 volumio go-librespot[15656]: time="2026-02-07T09:29: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 07 09:29:36 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 07 09:29:36 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 07 09:29:36 volumio sudo[15636]: pam_unix(sudo:session): session closed for user root Feb 07 09:29:37 volumio volumio[15584]: info: Starting UPNP Browser Feb 07 09:29:37 volumio volumio[15584]: info: Loading plugin "alarm-clock"... Feb 07 09:29:38 volumio volumio[15584]: info: Loading plugin "airplay_emulation"... Feb 07 09:29:38 volumio volumio[15584]: info: Starting Shairport Sync Feb 07 09:29:38 volumio volumio[15584]: info: Loading plugin "last_100"... Feb 07 09:29:38 volumio volumio[15584]: info: Loading plugin "webradio"... Feb 07 09:29:38 volumio volumio[15584]: info: Loading plugin "i2s_dacs"... Feb 07 09:29:38 volumio volumio[15584]: info: Loading plugin "volumiodiscovery"... Feb 07 09:29:38 volumio volumio[15584]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 07 09:29:38 volumio node[15584]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 07 09:29:38 volumio volumio[15584]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 07 09:29:38 volumio node[15584]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 07 09:29:38 volumio volumio[15584]: *** WARNING *** For more information see Feb 07 09:29:38 volumio node[15584]: *** WARNING *** For more information see Feb 07 09:29:38 volumio volumio[15584]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 07 09:29:38 volumio node[15584]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 07 09:29:38 volumio volumio[15584]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 07 09:29:38 volumio node[15584]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 07 09:29:38 volumio volumio[15584]: *** WARNING *** For more information see Feb 07 09:29:38 volumio node[15584]: *** WARNING *** For more information see Feb 07 09:29:38 volumio volumio[15584]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 07 09:29:38 volumio volumio[15584]: info: Discovery: Started advertising with name: Volumio Feb 07 09:29:38 volumio volumio[15584]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 07 09:29:38 volumio volumio[15584]: info: Loading plugin "spop"... Feb 07 09:29:39 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 26. Feb 07 09:29:39 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 07 09:29:39 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 07 09:29:39 volumio go-librespot[15666]: go-librespot daemon starting... Feb 07 09:29:39 volumio go-librespot[15667]: time="2026-02-07T09:29:39+07:00" level=info msg="running go-librespot 0.4.0" Feb 07 09:29:39 volumio go-librespot[15667]: time="2026-02-07T09:29:39+07:00" level=debug msg="app state loaded" Feb 07 09:29:39 volumio go-librespot[15667]: time="2026-02-07T09:29:39+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 07 09:29:39 volumio go-librespot[15667]: time="2026-02-07T09:29:39+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 07 09:29:39 volumio go-librespot[15667]: time="2026-02-07T09:29:39+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 07 09:29:39 volumio go-librespot[15667]: time="2026-02-07T09:29:39+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 07 09:29:40 volumio go-librespot[15667]: time="2026-02-07T09:29:40+07:00" level=info msg="zeroconf server listening on port 39489" Feb 07 09:29:40 volumio go-librespot[15667]: time="2026-02-07T09:29:40+07:00" level=debug msg="obtained new client token: AAAVVpDV8RjsONCJ4suZnIxyEK0e2mXNiwRxtytyRpBUfO/8nHSCn8A3cNaWyLvnxeuBhBGTafGDfOcbVk3A2ViFVtWiFDlAUq7X0HYmgu9+DLW3b6eiccAX11CrgKKH2vJ9keQEIPjq+wHinawDlP0SBwYPJGbnBJ0Pfn6XzzRt0EjapBERx0X+5qPVguEQNPZtkhNLq/9M7qjKOlI0C+WrUBZb5o8yoTzrgfLncTjlonU/huwRRNw=" Feb 07 09:29:40 volumio go-librespot[15667]: time="2026-02-07T09:29:40+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 07 09:29:40 volumio volumio[15584]: info: Loading plugin "ytcr"... Feb 07 09:29:40 volumio go-librespot[15667]: time="2026-02-07T09:29:40+07:00" level=debug msg="completed keyexchange" Feb 07 09:29:40 volumio go-librespot[15667]: time="2026-02-07T09:29:40+07:00" level=debug msg="completed challenge" Feb 07 09:29:40 volumio go-librespot[15667]: time="2026-02-07T09:29: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 07 09:29:40 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 07 09:29:40 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 07 09:29:43 volumio volumio[15584]: info: Loading plugin "ytmusic"... Feb 07 09:29:43 volumio volumio-remote-updater[643]: [2026-02-07 09:29:43] [connect] Successful connection Feb 07 09:29:43 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 27. Feb 07 09:29:43 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 07 09:29:43 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 07 09:29:43 volumio go-librespot[15674]: go-librespot daemon starting... Feb 07 09:29:43 volumio go-librespot[15675]: time="2026-02-07T09:29:43+07:00" level=info msg="running go-librespot 0.4.0" Feb 07 09:29:43 volumio go-librespot[15675]: time="2026-02-07T09:29:43+07:00" level=debug msg="app state loaded" Feb 07 09:29:43 volumio go-librespot[15675]: time="2026-02-07T09:29:43+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 07 09:29:44 volumio volumio[15584]: info: Loading plugin "outputs"... Feb 07 09:29:44 volumio volumio[15584]: info: Loading plugin "albumart"... Feb 07 09:29:44 volumio volumio[15584]: info: Plugin example_plugin is not enabled Feb 07 09:29:44 volumio volumio[15584]: info: Loading plugin "inputs"... Feb 07 09:29:44 volumio volumio[15584]: info: Loading plugin "updater_comm"... Feb 07 09:29:44 volumio go-librespot[15675]: time="2026-02-07T09:29: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-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 07 09:29:44 volumio go-librespot[15675]: time="2026-02-07T09:29:44+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 07 09:29:44 volumio go-librespot[15675]: time="2026-02-07T09:29:44+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 07 09:29:44 volumio go-librespot[15675]: time="2026-02-07T09:29:44+07:00" level=info msg="zeroconf server listening on port 36197" Feb 07 09:29:44 volumio volumio[15584]: info: Plugin mpdemulation is not enabled Feb 07 09:29:44 volumio volumio[15584]: info: Loading plugin "rest_api"... Feb 07 09:29:44 volumio volumio[15584]: info: Loading plugin "websocket"... Feb 07 09:29:44 volumio volumio[15584]: info: Starting Socket.io Server version 1.7.4 Feb 07 09:29:44 volumio volumio[15584]: info: Loading plugin "RoonBridge"... Feb 07 09:29:44 volumio go-librespot[15675]: time="2026-02-07T09:29:44+07:00" level=debug msg="obtained new client token: AAD6oyjjMTDi2EU+pPXLuj+9R5Kw1Ynh5LZ63eW4HNzcBoPiVSE21iHSMNcvBqKgUN8qMmkVAdeZXP29BNGhkwcHxcmdGC/j/KMiB2ukTOQK63HIlyD6hvZS5ZFTSMHRlV1c9+wirJLts2CV3RV9dWBQJJabiKKfxjAG0gBDGGw4x9JnIW80bni0HUKsbpt2C06SC55/beJ4mHRrZlYU7rTmbA+RSGN4LUpalfp0xCIfFxeKPkohpWOAuw==" Feb 07 09:29:44 volumio go-librespot[15675]: time="2026-02-07T09:29:44+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 07 09:29:45 volumio go-librespot[15675]: time="2026-02-07T09:29:44+07:00" level=debug msg="completed keyexchange" Feb 07 09:29:45 volumio go-librespot[15675]: time="2026-02-07T09:29:45+07:00" level=debug msg="completed challenge" Feb 07 09:29:45 volumio go-librespot[15675]: time="2026-02-07T09:29: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 07 09:29:45 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 07 09:29:45 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 07 09:29:45 volumio volumio[15584]: info: Applying required configuration parameters for plugin RoonBridge Feb 07 09:29:45 volumio volumio[15584]: info: Loading i18n strings for locale en Feb 07 09:29:45 volumio volumio[15584]: Updating browse sources language Feb 07 09:29:45 volumio volumio[15584]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 07 09:29:45 volumio volumio[15695]: Forking 3 albumart workers Feb 07 09:29:45 volumio volumio[15584]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 07 09:29:45 volumio volumio[15584]: info: CoreCommandRouter::initPlayerControls Feb 07 09:29:45 volumio volumio[15584]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 09:29:45 volumio volumio[15584]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 09:29:45 volumio volumio[15584]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 09:29:45 volumio volumio[15584]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 09:29:45 volumio volumio[15584]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 09:29:45 volumio volumio[15584]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 09:29:45 volumio volumio[15584]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 09:29:45 volumio volumio[15584]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 09:29:45 volumio volumio[15584]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 07 09:29:45 volumio volumio[15584]: Express server listening on port 3000 Feb 07 09:29:45 volumio volumio[15584]: [Metrics] WebUI: 16s 206.57ms Feb 07 09:29:45 volumio volumio[15584]: info: CoreStateMachine::resetVolumioState Feb 07 09:29:45 volumio volumio[15584]: info: CoreStateMachine::getcurrentVolume Feb 07 09:29:45 volumio volumio[15584]: info: CoreCommandRouter::volumioRetrievevolume Feb 07 09:29:45 volumio sudo[15740]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 07 09:29:45 volumio sudo[15740]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 09:29:45 volumio sudo[15738]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 07 09:29:45 volumio sudo[15738]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 09:29:45 volumio sudo[15740]: pam_unix(sudo:session): session closed for user root Feb 07 09:29:45 volumio sudo[15738]: pam_unix(sudo:session): session closed for user root Feb 07 09:29:45 volumio volumio[15584]: info: Volumio Network Manager: Network status updated: 1 Feb 07 09:29:46 volumio volumio[15584]: info: VolumeController:: Volume=100 Mute =false Feb 07 09:29:46 volumio volumio[15584]: info: CoreStateMachine::pushState Feb 07 09:29:46 volumio volumio[15584]: info: CorePlayQueue::getTrack 0 Feb 07 09:29:46 volumio volumio[15584]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 07 09:29:46 volumio volumio[15584]: info: CoreCommandRouter::volumioPushState Feb 07 09:29:46 volumio volumio[15584]: info: CoreStateMachine::updateTrackBlock Feb 07 09:29:46 volumio volumio[15584]: info: CorePlayQueue::getTrackBlock Feb 07 09:29:46 volumio volumio[15584]: info: CoreCommandRouter::volumioRetrievevolume Feb 07 09:29:46 volumio volumio-remote-updater[643]: [2026-02-07 09:29:46] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1770431383 101 Feb 07 09:29:46 volumio volumio[15584]: 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 07 09:29:46 volumio volumio[15584]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 09:29:46 volumio volumio[15584]: info: Reloading queue from file Feb 07 09:29:46 volumio volumio[15584]: info: CoreStateMachine::setRepeat null single undefined Feb 07 09:29:46 volumio volumio[15584]: info: CoreStateMachine::pushState Feb 07 09:29:46 volumio volumio[15584]: info: CorePlayQueue::getTrack 0 Feb 07 09:29:46 volumio volumio[15584]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 07 09:29:46 volumio volumio[15584]: info: CoreCommandRouter::volumioPushState Feb 07 09:29:46 volumio volumio[15584]: info: CoreStateMachine::setRandom null Feb 07 09:29:46 volumio volumio[15584]: info: CoreStateMachine::pushState Feb 07 09:29:46 volumio volumio[15584]: info: CorePlayQueue::getTrack 0 Feb 07 09:29:46 volumio volumio[15584]: info: CoreCommandRouter::volumioPushState Feb 07 09:29:46 volumio volumio[15584]: info: Setting Device type: Raspberry PI Feb 07 09:29:46 volumio volumio[15584]: info: Completed loading Core Plugins Feb 07 09:29:46 volumio volumio[15584]: info: Preparing to generate the ALSA configuration file Feb 07 09:29:46 volumio volumio[15584]: info: VolumeController:: Volume=100 Mute =false Feb 07 09:29:46 volumio volumio[15584]: info: CoreStateMachine::pushState Feb 07 09:29:46 volumio volumio[15584]: info: CorePlayQueue::getTrack 0 Feb 07 09:29:46 volumio volumio[15584]: info: CoreCommandRouter::volumioPushState Feb 07 09:29:46 volumio volumio[15584]: info: Asound.conf file unchanged, so no further update is needed Feb 07 09:29:46 volumio volumio[15584]: info: Output device has changed, restarting MPD Feb 07 09:29:46 volumio volumio[15584]: info: Output device has changed, restarting Shairport Sync Feb 07 09:29:46 volumio volumio[15584]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 09:29:46 volumio volumio[15584]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 09:29:46 volumio sudo[15757]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 07 09:29:46 volumio sudo[15757]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 09:29:46 volumio sudo[15759]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 07 09:29:46 volumio sudo[15761]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 07 09:29:46 volumio sudo[15759]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 09:29:46 volumio sudo[15761]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 09:29:46 volumio sudo[15759]: pam_unix(sudo:session): session closed for user root Feb 07 09:29:46 volumio volumio[15584]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 07 09:29:46 volumio volumio[15584]: info: ___________ START PLUGINS ___________ Feb 07 09:29:46 volumio sudo[15757]: pam_unix(sudo:session): session closed for user root Feb 07 09:29:46 volumio volumio[15584]: info: ControllerMpd::onStart: Initializing MPD Feb 07 09:29:46 volumio volumio[15584]: info: Creating MPD Configuration file Feb 07 09:29:46 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 07 09:29:46 volumio volumio[15584]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 07 09:29:46 volumio volumio[15584]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 07 09:29:46 volumio volumio[15584]: info: [1770431386896] CoreMusicLibrary::Adding element Media Servers Feb 07 09:29:46 volumio volumio[15584]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 07 09:29:46 volumio sudo[15772]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 07 09:29:46 volumio sudo[15772]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 09:29:46 volumio sudo[15770]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 07 09:29:46 volumio volumio[15584]: info: UPNP Browser: Client initialized successfully Feb 07 09:29:47 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 07 09:29:47 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 07 09:29:47 volumio systemd[1]: mpd.service: Consumed 7.196s CPU time. Feb 07 09:29:47 volumio sudo[15770]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 09:29:47 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 07 09:29:47 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 07 09:29:47 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 07 09:29:47 volumio sudo[15770]: pam_unix(sudo:session): session closed for user root Feb 07 09:29:47 volumio volumio[15584]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 09:29:47 volumio volumio[15584]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 09:29:47 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 07 09:29:47 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 07 09:29:47 volumio volumio[15584]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 07 09:29:47 volumio volumio[15584]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 09:29:47 volumio volumio[15584]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 09:29:47 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 07 09:29:47 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 07 09:29:47 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 07 09:29:47 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 07 09:29:47 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 07 09:29:47 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 07 09:29:47 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 07 09:29:47 volumio volumio[15584]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 07 09:29:47 volumio volumio[15584]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 07 09:29:47 volumio volumio[15584]: info: [1770431387311] CoreMusicLibrary::Adding element Last_100 Feb 07 09:29:47 volumio volumio[15584]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 07 09:29:47 volumio volumio[15584]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 07 09:29:47 volumio volumio[15584]: info: [1770431387332] CoreMusicLibrary::Adding element Webradio Feb 07 09:29:47 volumio volumio[15584]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 07 09:29:47 volumio volumio[15584]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 07 09:29:47 volumio volumio[15584]: info: Initializing BBC Radios Feb 07 09:29:47 volumio volumio[15584]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 07 09:29:47 volumio volumio[15584]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 09:29:47 volumio volumio[15584]: info: Creating Spotify config file Feb 07 09:29:47 volumio volumio[15584]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 09:29:47 volumio sudo[15786]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 07 09:29:47 volumio sudo[15786]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 07 09:29:47 volumio sudo[15786]: pam_unix(sudo:session): session closed for user root Feb 07 09:29:48 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 28. Feb 07 09:29:48 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 07 09:29:48 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 07 09:29:48 volumio go-librespot[15802]: go-librespot daemon starting... Feb 07 09:29:48 volumio go-librespot[15803]: time="2026-02-07T09:29:48+07:00" level=info msg="running go-librespot 0.4.0" Feb 07 09:29:48 volumio volumio[15707]: Starting albumart workers Feb 07 09:29:48 volumio volumio[15584]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 07 09:29:48 volumio volumio[15584]: info: [1770431388763] CoreMusicLibrary::Adding element YouTube Music Feb 07 09:29:48 volumio volumio[15584]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 07 09:29:48 volumio volumio[15584]: Cannot find translation for source YouTube Music Feb 07 09:29:48 volumio volumio[15584]: info: Volumio Calling Home Feb 07 09:29:48 volumio volumio[15706]: Starting albumart workers Feb 07 09:29:49 volumio sudo[15810]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Feb 07 09:29:49 volumio sudo[15810]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 09:29:49 volumio sudo[15810]: pam_unix(sudo:session): session closed for user root Feb 07 09:29:49 volumio go-librespot[15803]: time="2026-02-07T09:29:49+07:00" level=info msg="zeroconf server listening on port 43031" Feb 07 09:29:49 volumio volumio[15708]: Starting albumart workers Feb 07 09:29:49 volumio volumio[15584]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Feb 07 09:29:49 volumio volumio[15584]: info: Discovery: Found device Volumio Feb 07 09:29:49 volumio volumio[15584]: info: CoreCommandRouter::volumioGetState Feb 07 09:29:49 volumio volumio[15584]: info: CorePlayQueue::getTrack 0 Feb 07 09:29:49 volumio volumio[15584]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Feb 07 09:29:49 volumio volumio[15584]: info: Discovery: Found device Volumio Feb 07 09:29:49 volumio volumio[15584]: info: CoreCommandRouter::volumioGetState Feb 07 09:29:49 volumio volumio[15584]: info: CorePlayQueue::getTrack 0 Feb 07 09:29:49 volumio volumio[15584]: info: MPD Permissions set Feb 07 09:29:49 volumio volumio[15584]: info: MPD Permissions set Feb 07 09:29:49 volumio volumio[15584]: info: Upmpdcli Daemon Started Feb 07 09:29:49 volumio volumio[15584]: info: Volumio called home Feb 07 09:29:49 volumio volumio[15584]: info: Spotify config file written Feb 07 09:29:49 volumio sudo[15818]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 07 09:29:49 volumio sudo[15818]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 09:29:49 volumio volumio[15584]: 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 07 09:29:49 volumio volumio[15584]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 09:29:49 volumio volumio[15584]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 09:29:49 volumio volumio[15584]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 09:29:49 volumio volumio[15584]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 09:29:49 volumio volumio[15584]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 09:29:49 volumio volumio[15584]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 09:29:49 volumio volumio[15584]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 09:29:49 volumio volumio[15584]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 09:29:49 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Feb 07 09:29:50 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Feb 07 09:29:50 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 07 09:29:50 volumio volumio[15584]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 09:29:50 volumio volumio[15584]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 09:29:50 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 07 09:29:50 volumio volumio[15584]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 09:29:50 volumio volumio[15584]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 09:29:50 volumio volumio[15584]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 09:29:50 volumio go-librespot[15821]: go-librespot daemon starting... Feb 07 09:29:50 volumio sudo[15818]: pam_unix(sudo:session): session closed for user root Feb 07 09:29:50 volumio volumio[15584]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 09:29:50 volumio volumio[15584]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 09:29:50 volumio volumio[15584]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 09:29:50 volumio volumio[15584]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 09:29:50 volumio volumio[15584]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 09:29:50 volumio go-librespot[15826]: time="2026-02-07T09:29:50+07:00" level=info msg="running go-librespot 0.4.0" Feb 07 09:29:50 volumio go-librespot[15826]: time="2026-02-07T09:29:50+07:00" level=debug msg="app state loaded" Feb 07 09:29:50 volumio go-librespot[15826]: time="2026-02-07T09:29:50+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 07 09:29:50 volumio volumio[15584]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 09:29:50 volumio volumio[15584]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 09:29:50 volumio volumio[15584]: info: No need to fix Spotify hosts Feb 07 09:29:50 volumio go-librespot[15826]: time="2026-02-07T09:29: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 07 09:29:50 volumio go-librespot[15826]: time="2026-02-07T09:29: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 07 09:29:50 volumio go-librespot[15826]: time="2026-02-07T09:29: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 07 09:29:50 volumio go-librespot[15826]: time="2026-02-07T09:29:50+07:00" level=info msg="zeroconf server listening on port 35221" Feb 07 09:29:51 volumio go-librespot[15826]: time="2026-02-07T09:29:51+07:00" level=debug msg="obtained new client token: AADviCU7Zvp2hGvmVDepR28DfFMpmwIpQK4uMv4dl/H5ECLqteN/sfloQbK19989jEnG2+6rb6/zuhgAe30vqhpTC9Kyj2tblzLylhgOTiwQRJZRNtNd8nbfw8XpUu3qLJNQ9KnlH90VtZ3adLq6jTGiQ3fOrqqDLEXcuddVw5j5KbeafFUfRfHKkSYl2QS/x9s5jro6pYTkTV6xESNz4rCQcbqKwzRst4SOJ8wyfWNjZtxw7094yy8=" Feb 07 09:29:51 volumio go-librespot[15826]: time="2026-02-07T09:29:51+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 07 09:29:51 volumio go-librespot[15826]: time="2026-02-07T09:29:51+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Feb 07 09:29:51 volumio go-librespot[15826]: time="2026-02-07T09:29:51+07:00" level=debug msg="completed keyexchange" Feb 07 09:29:51 volumio go-librespot[15826]: time="2026-02-07T09:29:51+07:00" level=debug msg="completed challenge" Feb 07 09:29:51 volumio volumio[15584]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 07 09:29:51 volumio volumio[15584]: SPOTIFY: BQA6Vns9_tx2vxCLt6Vb-X1buHxll6RPGEx9IfFZnHXqDIQMWPYKGkBzlYVUnekpyPtaued-i4hq5CjXHbWY7VBMsCe5JTqLXa2hkNarpVsgHRoBLYxJVdKP0iS6eplGpQjQ78UtoOPUdUHjRtdx49yey0xI9DzI5atgobRZ7_nErXogzMj0GKkCgWFNpYZbtzvo_2nJzuHypWWlu0EPLhhJaIG5tdqZD01AZfYCM47ykJl89Cc79rond3bM63dg8GdjcFlwr_Mep_RrJ-XbLZBNS4poC0zFyiAtBqIwx8IysWeS6b4iJx8N Feb 07 09:29:51 volumio volumio[15584]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 07 09:29:51 volumio go-librespot[15826]: time="2026-02-07T09:29: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 07 09:29:51 volumio volumio[15584]: info: New Spotify access token = BQA6Vns9_tx2vxCLt6Vb-X1buHxll6RPGEx9IfFZnHXqDIQMWPYKGkBzlYVUnekpyPtaued-i4hq5CjXHbWY7VBMsCe5JTqLXa2hkNarpVsgHRoBLYxJVdKP0iS6eplGpQjQ78UtoOPUdUHjRtdx49yey0xI9DzI5atgobRZ7_nErXogzMj0GKkCgWFNpYZbtzvo_2nJzuHypWWlu0EPLhhJaIG5tdqZD01AZfYCM47ykJl89Cc79rond3bM63dg8GdjcFlwr_Mep_RrJ-XbLZBNS4poC0zFyiAtBqIwx8IysWeS6b4iJx8N Feb 07 09:29:51 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 07 09:29:51 volumio volumio[15584]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 07 09:29:51 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 07 09:29:51 volumio volumio[15584]: info: Starting Shairport Sync Feb 07 09:29:51 volumio volumio[15584]: info: Starting Shairport Sync Feb 07 09:29:51 volumio volumio[15584]: info: Starting Shairport Sync Feb 07 09:29:51 volumio sudo[15859]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 07 09:29:51 volumio sudo[15859]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 09:29:51 volumio sudo[15861]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 07 09:29:51 volumio sudo[15861]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 09:29:51 volumio sudo[15863]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 07 09:29:51 volumio sudo[15863]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 09:29:51 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 07 09:29:51 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 07 09:29:51 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 07 09:29:51 volumio systemd[1]: shairport-sync.service: Consumed 2.375s CPU time. Feb 07 09:29:52 volumio volumio[15584]: info: CoreCommandRouter::volumioGetState Feb 07 09:29:52 volumio volumio[15584]: info: CorePlayQueue::getTrack 0 Feb 07 09:29:52 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 07 09:29:52 volumio sudo[15859]: pam_unix(sudo:session): session closed for user root Feb 07 09:29:52 volumio volumio[15584]: info: Shairport-Sync Started Feb 07 09:29:52 volumio volumio[15584]: Error adding Membership: Error: addMembership EINVAL Feb 07 09:29:52 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 07 09:29:52 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 07 09:29:52 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 07 09:29:52 volumio volumio[15584]: 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 07 09:29:52 volumio volumio[15584]: info: Spotify Successfully logged in Feb 07 09:29:52 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 07 09:29:52 volumio volumio[15584]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 07 09:29:52 volumio volumio[15584]: info: [1770431392325] CoreMusicLibrary::Adding element Spotify Feb 07 09:29:52 volumio volumio[15584]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 07 09:29:52 volumio volumio[15584]: Cannot find translation for source YouTube Music Feb 07 09:29:52 volumio sudo[15863]: pam_unix(sudo:session): session closed for user root Feb 07 09:29:52 volumio sudo[15861]: pam_unix(sudo:session): session closed for user root Feb 07 09:29:52 volumio volumio[15584]: Cannot find translation for source Spotify Feb 07 09:29:52 volumio volumio[15584]: info: Shairport-Sync Started Feb 07 09:29:52 volumio volumio[15584]: info: Shairport-Sync Started Feb 07 09:29:52 volumio volumio[15584]: info: [yt-cast-receiver] DIAL server listening on port 8098 Feb 07 09:29:52 volumio volumio[15584]: info: CoreCommandRouter::volumioRetrievevolume Feb 07 09:29:53 volumio volumio[15584]: info: VolumeController:: Volume=100 Mute =false Feb 07 09:29:53 volumio volumio[15584]: info: CoreCommandRouter::volumioGetState Feb 07 09:29:53 volumio volumio[15584]: info: CorePlayQueue::getTrack 0 Feb 07 09:29:53 volumio volumio[15584]: info: CoreStateMachine::pushState Feb 07 09:29:53 volumio volumio[15584]: info: CorePlayQueue::getTrack 0 Feb 07 09:29:53 volumio volumio[15584]: info: CoreCommandRouter::volumioPushState Feb 07 09:29:54 volumio volumio[15584]: info: go-librespot daemon successfully initialized Feb 07 09:29:54 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Feb 07 09:29:54 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 07 09:29:54 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 07 09:29:54 volumio go-librespot[15908]: go-librespot daemon starting... Feb 07 09:29:54 volumio mpd[15801]: 2026-02-07T09:29:54 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 07 09:29:54 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 07 09:29:54 volumio sudo[15772]: pam_unix(sudo:session): session closed for user root Feb 07 09:29:54 volumio sudo[15761]: pam_unix(sudo:session): session closed for user root Feb 07 09:29:54 volumio go-librespot[15909]: time="2026-02-07T09:29:54+07:00" level=info msg="running go-librespot 0.4.0" Feb 07 09:29:54 volumio go-librespot[15909]: time="2026-02-07T09:29:54+07:00" level=debug msg="app state loaded" Feb 07 09:29:54 volumio go-librespot[15909]: time="2026-02-07T09:29:54+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 07 09:29:55 volumio volumio[15584]: error: MPD error: The expression evaluated to a falsy value: Feb 07 09:29:55 volumio volumio[15584]: assert.ok(self.idling) Feb 07 09:29:55 volumio volumio[15584]: error: The expression evaluated to a falsy value: Feb 07 09:29:55 volumio volumio[15584]: assert.ok(self.idling) Feb 07 09:29:55 volumio volumio[15584]: info: MPD running with PID15801 Feb 07 09:29:55 volumio volumio[15584]: ,establishing connection Feb 07 09:29:55 volumio volumio[15584]: error: updateQueue error: null Feb 07 09:29:55 volumio volumio[15584]: info: Completed starting Core Plugins Feb 07 09:29:55 volumio volumio[15584]: info: ------------------------------------------- Feb 07 09:29:55 volumio volumio[15584]: info: ----- MyVolumio plugins startup ---- Feb 07 09:29:55 volumio volumio[15584]: info: ------------------------------------------- Feb 07 09:29:55 volumio volumio[15584]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 07 09:29:55 volumio volumio[15584]: error: updateQueue error: null Feb 07 09:29:55 volumio go-librespot[15909]: time="2026-02-07T09:29:55+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 07 09:29:55 volumio go-librespot[15909]: time="2026-02-07T09:29:55+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 07 09:29:55 volumio go-librespot[15909]: time="2026-02-07T09:29:55+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 07 09:29:55 volumio go-librespot[15909]: time="2026-02-07T09:29:55+07:00" level=info msg="zeroconf server listening on port 43255" Feb 07 09:29:55 volumio go-librespot[15909]: time="2026-02-07T09:29:55+07:00" level=debug msg="obtained new client token: AACoyRC+VdJB33Rg1t5PHHwsNLf/qTIxJENpdsxhn/xota+DmxznqADtiZYXviYD7wJjxaZvp/AwKBuA0oD3S40byfhTpR5JV7vGSObsx7k6XIk5MVhUA8DefNTB2RGbbShqpmOlqWR/K9sQ/Z2Zj8Q4+6qJjwKIuWhG1aDegOBMR4Oabd9sMAlzEYvvtMPY1L4KxlkDOYMnNxA8YcS+1ojAaajiCW/iAXMWI2AWIS6H2zZbbG1rrfpHlQ==" Feb 07 09:29:55 volumio go-librespot[15909]: time="2026-02-07T09:29:55+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 07 09:29:55 volumio go-librespot[15909]: time="2026-02-07T09:29:55+07:00" level=debug msg="completed keyexchange" Feb 07 09:29:55 volumio go-librespot[15909]: time="2026-02-07T09:29:55+07:00" level=debug msg="completed challenge" Feb 07 09:29:56 volumio go-librespot[15909]: time="2026-02-07T09:29:56+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 07 09:29:56 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 07 09:29:56 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 07 09:29:57 volumio volumio[15584]: info: Initializing connection to go-librespot Websocket Feb 07 09:29:57 volumio volumio[15584]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 07 09:29:59 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Feb 07 09:29:59 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 07 09:29:59 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 07 09:29:59 volumio go-librespot[15921]: go-librespot daemon starting... Feb 07 09:29:59 volumio go-librespot[15922]: time="2026-02-07T09:29:59+07:00" level=info msg="running go-librespot 0.4.0" Feb 07 09:29:59 volumio go-librespot[15922]: time="2026-02-07T09:29:59+07:00" level=debug msg="app state loaded" Feb 07 09:29:59 volumio go-librespot[15922]: time="2026-02-07T09:29:59+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 07 09:29:59 volumio go-librespot[15922]: time="2026-02-07T09:29: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-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 07 09:29:59 volumio go-librespot[15922]: time="2026-02-07T09:29:59+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 07 09:29:59 volumio go-librespot[15922]: time="2026-02-07T09:29:59+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 07 09:29:59 volumio go-librespot[15922]: time="2026-02-07T09:29:59+07:00" level=info msg="zeroconf server listening on port 46019" Feb 07 09:30:00 volumio volumio[15584]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 07 09:30:00 volumio go-librespot[15922]: time="2026-02-07T09:30:00+07:00" level=debug msg="obtained new client token: AAD5ahJmpEzEOkfs6GOG8VU4v6iGyqjAyu6Yz0tX0TwrdfFGNHHV9OftAgCatWi/p5YDSGgz96zd0rkZz28XbeQAjsbgXcoh7HYdbRa7v7p3tEYLsE54GbAuHqJ0IGzS68/aufNHeNB9X7s8BB5SYRtnqQpCy3RYNeMun5uz/cm9XM9FJ5PUHMxSHyR9d5z8u+0xJiVhCmv1T2iIT0zgQNA4B/Dg1k6fY52BjJoiLJxCFd+FbwbHJdo=" Feb 07 09:30:00 volumio go-librespot[15922]: time="2026-02-07T09:30:00+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 07 09:30:00 volumio go-librespot[15922]: time="2026-02-07T09:30:00+07:00" level=debug msg="completed keyexchange" Feb 07 09:30:00 volumio go-librespot[15922]: time="2026-02-07T09:30:00+07:00" level=debug msg="completed challenge" Feb 07 09:30:00 volumio go-librespot[15922]: time="2026-02-07T09:30:00+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 07 09:30:00 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 07 09:30:00 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 07 09:30:00 volumio volumio[15584]: info: Initializing connection to go-librespot Websocket Feb 07 09:30:00 volumio volumio[15584]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 07 09:30:03 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Feb 07 09:30:03 volumio volumio[15584]: info: Initializing connection to go-librespot Websocket Feb 07 09:30:03 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 07 09:30:03 volumio volumio[15584]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 07 09:30:03 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 07 09:30:03 volumio go-librespot[15931]: go-librespot daemon starting... Feb 07 09:30:03 volumio go-librespot[15932]: time="2026-02-07T09:30:03+07:00" level=info msg="running go-librespot 0.4.0" Feb 07 09:30:03 volumio go-librespot[15932]: time="2026-02-07T09:30:03+07:00" level=debug msg="app state loaded" Feb 07 09:30:03 volumio go-librespot[15932]: time="2026-02-07T09:30:03+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 07 09:30:03 volumio volumio[15584]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 07 09:30:03 volumio volumio[15584]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 07 09:30:03 volumio volumio[15584]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 07 09:30:03 volumio volumio[15584]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 07 09:30:03 volumio volumio[15584]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 07 09:30:03 volumio volumio[15584]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 07 09:30:03 volumio volumio[15584]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 07 09:30:03 volumio volumio[15584]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 07 09:30:03 volumio volumio[15584]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 07 09:30:03 volumio volumio[15584]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 07 09:30:03 volumio volumio[15584]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 07 09:30:03 volumio volumio[15584]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 07 09:30:03 volumio volumio[15584]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 07 09:30:03 volumio volumio[15584]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 07 09:30:03 volumio volumio[15584]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 07 09:30:03 volumio volumio[15584]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 07 09:30:04 volumio volumio[15584]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 07 09:30:04 volumio volumio[15584]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 07 09:30:04 volumio volumio[15584]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 07 09:30:04 volumio volumio[15584]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 07 09:30:04 volumio volumio[15584]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 07 09:30:04 volumio volumio[15584]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 07 09:30:04 volumio volumio[15584]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 07 09:30:04 volumio volumio[15584]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 07 09:30:04 volumio volumio[15584]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 07 09:30:04 volumio volumio[15584]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 07 09:30:04 volumio volumio[15584]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 07 09:30:04 volumio volumio[15584]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 07 09:30:04 volumio volumio[15584]: info: Adding plugin bluetooth to MyMusic Plugins Feb 07 09:30:04 volumio volumio[15584]: info: Adding plugin multiroom to MyMusic Plugins Feb 07 09:30:04 volumio volumio[15584]: info: Adding plugin metavolumio to MyMusic Plugins Feb 07 09:30:04 volumio volumio[15584]: info: Adding plugin cd_controller to MyMusic Plugins Feb 07 09:30:04 volumio volumio[15584]: info: Adding plugin qobuzconnect to MyMusic Plugins Feb 07 09:30:04 volumio volumio[15584]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 07 09:30:04 volumio volumio[15584]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 07 09:30:04 volumio volumio[15584]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 07 09:30:04 volumio go-librespot[15932]: time="2026-02-07T09:30:04+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 07 09:30:04 volumio go-librespot[15932]: time="2026-02-07T09:30:04+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 07 09:30:04 volumio go-librespot[15932]: time="2026-02-07T09:30:04+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 07 09:30:04 volumio go-librespot[15932]: time="2026-02-07T09:30:04+07:00" level=info msg="zeroconf server listening on port 46685" Feb 07 09:30:04 volumio go-librespot[15932]: time="2026-02-07T09:30:04+07:00" level=debug msg="obtained new client token: AACZM2vUVQQ4V3H1iCifVT2vVT8nbNHfnO9VCQv3/wl5FZipI4EB9R9kKkS7HzZirX7zGcdWSj6TMzLYJHM54sf4tdvVyGCd9SmuIbIf6SSdBxRG1CjY487i/ta2/XTVkjB5vOuzTXoTzBwBQMtZxGK4mdTo955zk+Ry78jfG0OS2gSMQJCo2O/ut1uqzn6mUZnTOnFdpAm6Q2hv+0jgozuhSV3VaadkFTIdNGQfkzzIv6C6GTcQ2L6+mA==" Feb 07 09:30:04 volumio go-librespot[15932]: time="2026-02-07T09:30:04+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 07 09:30:04 volumio go-librespot[15932]: time="2026-02-07T09:30:04+07:00" level=debug msg="completed keyexchange" Feb 07 09:30:04 volumio go-librespot[15932]: time="2026-02-07T09:30:04+07:00" level=debug msg="completed challenge" Feb 07 09:30:04 volumio go-librespot[15932]: time="2026-02-07T09:30:04+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 07 09:30:04 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 07 09:30:04 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 07 09:30:05 volumio volumio[15584]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 07 09:30:05 volumio volumio[15584]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 07 09:30:05 volumio volumio[15584]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 09:30:05 volumio volumio[15584]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 09:30:05 volumio volumio[15584]: info: Starting MyVolumio Remote Streaming Endpoints Feb 07 09:30:05 volumio volumio[15584]: info: MyVolumio login type: Token Feb 07 09:30:05 volumio volumio[15584]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 07 09:30:05 volumio volumio[15584]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 07 09:30:07 volumio volumio[15584]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 07 09:30:07 volumio volumio[15584]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 07 09:30:07 volumio volumio[15584]: info: Streaming services startup Feb 07 09:30:07 volumio volumio[15584]: info: Starting Streaming Daemon Feb 07 09:30:07 volumio sudo[15954]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 07 09:30:07 volumio sudo[15954]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 09:30:07 volumio volumio[15584]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 07 09:30:07 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Feb 07 09:30:07 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 07 09:30:07 volumio volumio[15584]: info: Initializing connection to go-librespot Websocket Feb 07 09:30:07 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 07 09:30:07 volumio go-librespot[15960]: go-librespot daemon starting... Feb 07 09:30:07 volumio sudo[15954]: pam_unix(sudo:session): session closed for user root Feb 07 09:30:07 volumio volumio[15584]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 07 09:30:07 volumio volumio[15584]: error: Cannot start Volumio Streaming Daemon Feb 07 09:30:07 volumio volumio[15584]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 07 09:30:07 volumio volumio[15584]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 07 09:30:07 volumio go-librespot[15961]: time="2026-02-07T09:30:07+07:00" level=info msg="running go-librespot 0.4.0" Feb 07 09:30:07 volumio go-librespot[15961]: time="2026-02-07T09:30:07+07:00" level=debug msg="app state loaded" Feb 07 09:30:07 volumio go-librespot[15961]: time="2026-02-07T09:30:07+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 07 09:30:08 volumio go-librespot[15961]: time="2026-02-07T09:30:08+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 07 09:30:08 volumio go-librespot[15961]: time="2026-02-07T09:30:08+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 07 09:30:08 volumio go-librespot[15961]: time="2026-02-07T09:30:08+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 07 09:30:08 volumio go-librespot[15961]: time="2026-02-07T09:30:08+07:00" level=info msg="zeroconf server listening on port 39531" Feb 07 09:30:08 volumio go-librespot[15961]: time="2026-02-07T09:30:08+07:00" level=debug msg="obtained new client token: AADqMLXGMkD8LkvySIYdIfmvt7FZ0aWN0+uNd0rWUJJ+3vQ6k9zdbIZLa0A8e3HeiGMfMocWbm3S+L6o5qchAD0CMzsRwlI63KR/Wb01pPcoiRbW9ggocaXGOvqw56xydUK5TQMCgL0X0mnBdZwL43s0CP4N/shNZAoqJlqPs9t4h6DPU0tuxS4S7aylr1KVPHypuef7uHzMBF9CbkU0Aq+WcOOeaIj+DYlUMTR563s3qBCd+cv9vqsItg==" Feb 07 09:30:08 volumio go-librespot[15961]: time="2026-02-07T09:30:08+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 07 09:30:08 volumio volumio[15584]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Feb 07 09:30:08 volumio go-librespot[15961]: time="2026-02-07T09:30:08+07:00" level=debug msg="completed keyexchange" Feb 07 09:30:08 volumio go-librespot[15961]: time="2026-02-07T09:30:08+07:00" level=debug msg="completed challenge" Feb 07 09:30:08 volumio go-librespot[15961]: time="2026-02-07T09:30: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 07 09:30:08 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 07 09:30:08 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 07 09:30:09 volumio volumio[15584]: info: MyVolumio token set successfully Feb 07 09:30:09 volumio volumio[15584]: info: MYVOLUMIO: Adding device Feb 07 09:30:09 volumio volumio[15584]: info: MYVOLUMIO: Evaluating Server Feb 07 09:30:10 volumio volumio[15584]: info: MyVolumio status changed Feb 07 09:30:10 volumio volumio[15584]: info: Streaming services startup Feb 07 09:30:10 volumio volumio[15584]: info: Starting Streaming Daemon Feb 07 09:30:10 volumio volumio[15584]: info: Removing browser output: myVolumio user plan is not superstar Feb 07 09:30:10 volumio volumio[15584]: info: Removing audio output: Feb 07 09:30:10 volumio volumio[15584]: info: Stoppping Tunnel 1 Feb 07 09:30:10 volumio sudo[15990]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 07 09:30:10 volumio sudo[15990]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 09:30:10 volumio sudo[15993]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Feb 07 09:30:10 volumio sudo[15993]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 09:30:10 volumio sudo[15990]: pam_unix(sudo:session): session closed for user root Feb 07 09:30:10 volumio volumio[15584]: error: Cannot start Volumio Streaming Daemon Feb 07 09:30:10 volumio volumio[15584]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 07 09:30:10 volumio volumio[15584]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 07 09:30:10 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 07 09:30:10 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 07 09:30:10 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 07 09:30:10 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 07 09:30:10 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 07 09:30:10 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 07 09:30:10 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 07 09:30:10 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 07 09:30:10 volumio sudo[15993]: pam_unix(sudo:session): session closed for user root Feb 07 09:30:10 volumio volumio[15584]: info: Remote SSH Stopped Feb 07 09:30:10 volumio volumio[15584]: info: Initializing connection to go-librespot Websocket Feb 07 09:30:10 volumio volumio[15584]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 07 09:30:12 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Feb 07 09:30:12 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 07 09:30:12 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 07 09:30:12 volumio go-librespot[15996]: go-librespot daemon starting... Feb 07 09:30:12 volumio go-librespot[15997]: time="2026-02-07T09:30:12+07:00" level=info msg="running go-librespot 0.4.0" Feb 07 09:30:12 volumio go-librespot[15997]: time="2026-02-07T09:30:12+07:00" level=debug msg="app state loaded" Feb 07 09:30:12 volumio go-librespot[15997]: time="2026-02-07T09:30:12+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 07 09:30:12 volumio volumio[15584]: info: Setting Geolocation for MyVolumio to as1 Feb 07 09:30:12 volumio volumio[15584]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 09:30:12 volumio volumio[15584]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 09:30:12 volumio volumio[15584]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 09:30:12 volumio volumio[15584]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Feb 07 09:30:12 volumio go-librespot[15997]: time="2026-02-07T09:30:12+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 07 09:30:12 volumio go-librespot[15997]: time="2026-02-07T09:30:12+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 07 09:30:12 volumio go-librespot[15997]: time="2026-02-07T09:30:12+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 07 09:30:12 volumio go-librespot[15997]: time="2026-02-07T09:30:12+07:00" level=info msg="zeroconf server listening on port 35051" Feb 07 09:30:12 volumio go-librespot[15997]: time="2026-02-07T09:30:12+07:00" level=debug msg="obtained new client token: AABRb2iCbY3TD/HSiAsDJ1eGQExgxxn6c3xv/vFzL1u9fedKqhXeQAu/4/3zLJO19E/1pXBoWUU3mFEzuiV6cizWRjPeqFRSG8IYmmm+5vj70wh+ZPtGPhzF89yd9QK5LDKsFwS5EREpgV5LN9DzIA4oBwVYvDk7MBMjGllAt9Zc8wePsrMGEVh/FCsK2Y91imAE3LIvVLwn6eS5hKS4FPTOF1CopKFgzJNMLH5XLFlMHaGQE80PWNd1uA==" Feb 07 09:30:12 volumio go-librespot[15997]: time="2026-02-07T09:30:12+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 07 09:30:13 volumio go-librespot[15997]: time="2026-02-07T09:30:13+07:00" level=debug msg="completed keyexchange" Feb 07 09:30:13 volumio go-librespot[15997]: time="2026-02-07T09:30:13+07:00" level=debug msg="completed challenge" Feb 07 09:30:13 volumio go-librespot[15997]: time="2026-02-07T09:30:13+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 07 09:30:13 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 07 09:30:13 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 07 09:30:13 volumio volumio[15584]: info: Updating MyVolumio device info Feb 07 09:30:13 volumio volumio[15584]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 09:30:13 volumio volumio[15584]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 09:30:13 volumio volumio[15584]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 09:30:13 volumio volumio[15584]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Feb 07 09:30:13 volumio volumio[15584]: info: Initializing connection to go-librespot Websocket Feb 07 09:30:13 volumio volumio[15584]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 07 09:30:16 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Feb 07 09:30:16 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 07 09:30:16 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 07 09:30:16 volumio go-librespot[16018]: go-librespot daemon starting... Feb 07 09:30:16 volumio go-librespot[16019]: time="2026-02-07T09:30:16+07:00" level=info msg="running go-librespot 0.4.0" Feb 07 09:30:16 volumio go-librespot[16019]: time="2026-02-07T09:30:16+07:00" level=debug msg="app state loaded" Feb 07 09:30:16 volumio go-librespot[16019]: time="2026-02-07T09:30:16+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 07 09:30:16 volumio volumio[15584]: info: MYVOLUMIO: Adding device Feb 07 09:30:16 volumio volumio[15584]: info: MYVOLUMIO: Evaluating Server Feb 07 09:30:16 volumio go-librespot[16019]: time="2026-02-07T09:30: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-gew4.spotify.com:80]" Feb 07 09:30:16 volumio go-librespot[16019]: time="2026-02-07T09:30:16+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 07 09:30:16 volumio go-librespot[16019]: time="2026-02-07T09:30:16+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 07 09:30:16 volumio go-librespot[16019]: time="2026-02-07T09:30:16+07:00" level=info msg="zeroconf server listening on port 40377" Feb 07 09:30:17 volumio volumio[15584]: info: Initializing connection to go-librespot Websocket Feb 07 09:30:17 volumio go-librespot[16019]: time="2026-02-07T09:30:17+07:00" level=debug msg="obtained new client token: AABxYOSxebn2AX/bt5tvyxmkFb8vaqm1isCcJEVNQ3ynR7rKllrsq5QwDgGp6r3Vm2P9ULd5aHadCEvbDj96lea5b+94LN9xqYU6RGlszXEUl2eFB0kaKtu7M5WQP4sHtuSwTF1sopHE6hPf1g56HopjZYv3iAxJ5AEcZBZOYWlbUYzKG2cCIS7ZDRPjVr1BrdjrNiA6fXMFDT1Le40LxzDRDuPlsoFGD2wqdANkTHQTE8XIzZMh85Q=" Feb 07 09:30:17 volumio go-librespot[16019]: time="2026-02-07T09:30:17+07:00" level=debug msg="new websocket client" Feb 07 09:30:17 volumio volumio[15584]: info: Connection to go-librespot Websocket established Feb 07 09:30:17 volumio go-librespot[16019]: time="2026-02-07T09:30:17+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 07 09:30:17 volumio volumio[15584]: info: Setting Geolocation for MyVolumio to as1 Feb 07 09:30:17 volumio volumio[15584]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 09:30:17 volumio volumio[15584]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 09:30:17 volumio volumio[15584]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 09:30:17 volumio go-librespot[16019]: time="2026-02-07T09:30:17+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 07 09:30:17 volumio go-librespot[16019]: time="2026-02-07T09:30:17+07:00" level=debug msg="connected to ap-gae2.spotify.com:80" Feb 07 09:30:17 volumio go-librespot[16019]: time="2026-02-07T09:30:17+07:00" level=debug msg="completed keyexchange" Feb 07 09:30:17 volumio go-librespot[16019]: time="2026-02-07T09:30:17+07:00" level=debug msg="completed challenge" Feb 07 09:30:17 volumio go-librespot[16019]: time="2026-02-07T09:30:17+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 07 09:30:17 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 07 09:30:17 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 07 09:30:17 volumio volumio[15584]: info: Connection to go-librespot Websocket closed Feb 07 09:30:17 volumio volumio[15584]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Feb 07 09:30:18 volumio volumio[15584]: info: Updating MyVolumio device info Feb 07 09:30:18 volumio volumio[15584]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 09:30:18 volumio volumio[15584]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 09:30:18 volumio volumio[15584]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 09:30:18 volumio volumio[15584]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Feb 07 09:30:18 volumio volumio[15584]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 07 09:30:18 volumio volumio[15584]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 09:30:18 volumio volumio[15584]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Feb 07 09:30:19 volumio volumio-remote-updater[643]: Test mode disabled Feb 07 09:30:19 volumio volumio-remote-updater[643]: Alpha mode disabled Feb 07 09:30:19 volumio volumio-remote-updater[643]: Alpha legacy test mode disabled Feb 07 09:30:19 volumio volumio[15584]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled Feb 07 09:30:19 volumio volumio[15584]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Feb 07 09:30:19 volumio volumio[15584]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Feb 07 09:30:20 volumio volumio[15584]: info: Getting Spotify volume Feb 07 09:30:20 volumio volumio[15584]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 07 09:30:20 volumio volumio[15584]: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 07 09:30:20 volumio volumio[15584]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Feb 07 09:30:20 volumio volumio[15584]: errno: -111, Feb 07 09:30:20 volumio volumio[15584]: code: 'ECONNREFUSED', Feb 07 09:30:20 volumio volumio[15584]: syscall: 'connect', Feb 07 09:30:20 volumio volumio[15584]: address: '127.0.0.1', Feb 07 09:30:20 volumio volumio[15584]: port: 9879, Feb 07 09:30:20 volumio volumio[15584]: response: undefined Feb 07 09:30:20 volumio volumio[15584]: } Feb 07 09:30:20 volumio volumio[15584]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 07 09:30:20 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Feb 07 09:30:20 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 07 09:30:20 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 07 09:30:20 volumio go-librespot[16062]: go-librespot daemon starting... Feb 07 09:30:20 volumio go-librespot[16063]: time="2026-02-07T09:30:20+07:00" level=info msg="running go-librespot 0.4.0" Feb 07 09:30:20 volumio go-librespot[16063]: time="2026-02-07T09:30:20+07:00" level=debug msg="app state loaded" Feb 07 09:30:20 volumio go-librespot[16063]: time="2026-02-07T09:30:20+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 07 09:30:21 volumio go-librespot[16063]: time="2026-02-07T09:30:21+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 07 09:30:21 volumio go-librespot[16063]: time="2026-02-07T09:30:21+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 07 09:30:21 volumio go-librespot[16063]: time="2026-02-07T09:30:21+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 07 09:30:21 volumio go-librespot[16063]: time="2026-02-07T09:30:21+07:00" level=info msg="zeroconf server listening on port 46161" Feb 07 09:30:21 volumio go-librespot[16063]: time="2026-02-07T09:30:21+07:00" level=debug msg="obtained new client token: AACBP7+sdmeUr8ouU0aFNAnm7yUty5H6gdxbD3E9JF5cy3gPJzce14uXntZ9XAjbLBFT71vTfIrcVIm/oxRNJx3MLglfq3lSD1aJ09HVTgp6FOqadAxGB3qYm/mDlGtLCeEgQs6UxTHM6NDH+WdGIAmZDMpUzCQFwZqWt8O1zuHjedu4NSki3CvB2FpSVdZhb8wciY1i0vmPZ7jv07siqUK74d4Ug7xcJAeAtktIpruYHLPvslV0ifhOjA==" Feb 07 09:30:21 volumio sudo[16072]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-07 09:29' Feb 07 09:30:21 volumio sudo[16072]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 09:30:21 volumio go-librespot[16063]: time="2026-02-07T09:30:21+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 07 09:30:21 volumio go-librespot[16063]: time="2026-02-07T09:30:21+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Feb 07 09:30:21 volumio go-librespot[16063]: time="2026-02-07T09:30:21+07:00" level=debug msg="completed keyexchange" Feb 07 09:30:21 volumio go-librespot[16063]: time="2026-02-07T09:30:21+07:00" level=debug msg="completed challenge" Feb 07 09:30:21 volumio go-librespot[16063]: time="2026-02-07T09:30: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 07 09:30:21 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 07 09:30: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"