Feb 18 23:37:00 volumio volumio[7553]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Feb 18 23:37:00 volumio volumio[7553]: info: Discovery: Found device Volumio Feb 18 23:37:00 volumio volumio[7553]: info: CoreCommandRouter::volumioGetState Feb 18 23:37:00 volumio volumio[7553]: info: CorePlayQueue::getTrack 0 Feb 18 23:37:00 volumio volumio[7553]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Feb 18 23:37:00 volumio volumio[7553]: info: Discovery: Found device Volumio Feb 18 23:37:00 volumio volumio[7553]: info: CoreCommandRouter::volumioGetState Feb 18 23:37:00 volumio volumio[7553]: info: CorePlayQueue::getTrack 0 Feb 18 23:37:00 volumio volumio[7553]: info: MPD Permissions set Feb 18 23:37:00 volumio volumio[7553]: info: MPD Permissions set Feb 18 23:37:00 volumio volumio[7553]: info: Upmpdcli Daemon Started Feb 18 23:37:00 volumio go-librespot[7786]: time="2026-02-18T23:37:00+07:00" level=info msg="zeroconf server listening on port 43917" Feb 18 23:37:00 volumio volumio[7553]: info: Volumio called home Feb 18 23:37:00 volumio volumio[7553]: info: Spotify config file written Feb 18 23:37:00 volumio volumio[7553]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Feb 18 23:37:00 volumio sudo[7801]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 18 23:37:00 volumio sudo[7801]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 23:37:00 volumio volumio[7553]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 23:37:00 volumio volumio[7553]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 23:37:00 volumio volumio[7553]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 23:37:00 volumio volumio[7553]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 23:37:00 volumio volumio[7553]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 23:37:00 volumio volumio[7553]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 23:37:00 volumio volumio[7553]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 23:37:00 volumio volumio[7553]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 23:37:00 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Feb 18 23:37:00 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Feb 18 23:37:00 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 23:37:00 volumio volumio[7553]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 23:37:00 volumio volumio[7553]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 23:37:00 volumio volumio[7553]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 23:37:00 volumio volumio[7553]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 23:37:00 volumio volumio[7553]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 23:37:00 volumio volumio[7553]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 23:37:00 volumio volumio[7553]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 23:37:00 volumio volumio[7553]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 23:37:00 volumio volumio[7553]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 23:37:00 volumio volumio[7553]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 23:37:00 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 23:37:00 volumio go-librespot[7808]: go-librespot daemon starting... Feb 18 23:37:00 volumio sudo[7801]: pam_unix(sudo:session): session closed for user root Feb 18 23:37:00 volumio volumio[7553]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 23:37:00 volumio volumio[7553]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 23:37:00 volumio go-librespot[7813]: time="2026-02-18T23:37:00+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 23:37:00 volumio go-librespot[7813]: time="2026-02-18T23:37:00+07:00" level=debug msg="app state loaded" Feb 18 23:37:00 volumio go-librespot[7813]: time="2026-02-18T23:37:00+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 23:37:00 volumio volumio[7553]: info: No need to fix Spotify hosts Feb 18 23:37:01 volumio go-librespot[7813]: time="2026-02-18T23:37:01+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 23:37:01 volumio go-librespot[7813]: time="2026-02-18T23:37:01+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 18 23:37:01 volumio go-librespot[7813]: time="2026-02-18T23:37:01+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 18 23:37:01 volumio go-librespot[7813]: time="2026-02-18T23:37:01+07:00" level=info msg="zeroconf server listening on port 36593" Feb 18 23:37:01 volumio volumio[7553]: info: Starting Shairport Sync Feb 18 23:37:01 volumio volumio[7553]: info: Starting Shairport Sync Feb 18 23:37:01 volumio volumio[7553]: info: Starting Shairport Sync Feb 18 23:37:01 volumio go-librespot[7813]: time="2026-02-18T23:37:01+07:00" level=debug msg="obtained new client token: AAAghC/fsuvUvW3wPYRcDvm5i/LNXpqX4fjrm1Kya7GmSBdDAi6RVXW+dMpCjH3DDlTkxjAnmzYZkZFp1HGZrxa5zT7s2XrVDE1X48E272g3IOvb17IBO8tKGSGuDpuS8HqxntqTvwRunZw+ZD94yVko8kE4ghxTomElyDcExooP/6lwCC4W2EN4Ycpmm6e+bZcOLfJnYaqvwZzBVUyiWPOxCMURfyNZFhIw9DygsjFUpwLZVv+b+wJFRA==" Feb 18 23:37:01 volumio sudo[7836]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 18 23:37:01 volumio sudo[7836]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 23:37:01 volumio sudo[7838]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 18 23:37:01 volumio sudo[7838]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 23:37:01 volumio sudo[7840]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 18 23:37:01 volumio sudo[7840]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 23:37:01 volumio go-librespot[7813]: time="2026-02-18T23:37:01+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 23:37:01 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 18 23:37:01 volumio go-librespot[7813]: time="2026-02-18T23:37:01+07:00" level=debug msg="completed keyexchange" Feb 18 23:37:01 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 18 23:37:01 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 18 23:37:01 volumio systemd[1]: shairport-sync.service: Consumed 2.206s CPU time. Feb 18 23:37:01 volumio go-librespot[7813]: time="2026-02-18T23:37:01+07:00" level=debug msg="completed challenge" Feb 18 23:37:02 volumio go-librespot[7813]: time="2026-02-18T23:37:02+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 18 23:37:02 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 18 23:37:02 volumio sudo[7840]: pam_unix(sudo:session): session closed for user root Feb 18 23:37:02 volumio sudo[7836]: pam_unix(sudo:session): session closed for user root Feb 18 23:37:02 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 23:37:02 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 23:37:02 volumio volumio[7553]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 18 23:37:02 volumio volumio[7553]: SPOTIFY: BQADmd1f_MIgZrMycSTxRMVGoIWYypEQakgYvNM64K6Y2kCDniLZQEGArtQSs9y8VE3HjKJbqadrV7TR3ryovegYeN-OU7KffmrFemldtLHPkvqEpITocwmq6CKhUkoFrIoxfDhsJkK-oWWVhgs6J-Ftu3KfbX6f6OqpNxqQ_1PjU1ohArApTMje9MsVYUT1GIiZACzzn0YzmCDFOzVXv7PRtF1pOL_BP83h7Gw6FLrVR_2OIPn92WAi0nWd0jZzgkz75qVk2nLXaW0EXngeZehZdO7gEv8SKibUb0DNsrUjGoj7HehHLrfN Feb 18 23:37:02 volumio volumio[7553]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 18 23:37:02 volumio volumio[7553]: info: New Spotify access token = BQADmd1f_MIgZrMycSTxRMVGoIWYypEQakgYvNM64K6Y2kCDniLZQEGArtQSs9y8VE3HjKJbqadrV7TR3ryovegYeN-OU7KffmrFemldtLHPkvqEpITocwmq6CKhUkoFrIoxfDhsJkK-oWWVhgs6J-Ftu3KfbX6f6OqpNxqQ_1PjU1ohArApTMje9MsVYUT1GIiZACzzn0YzmCDFOzVXv7PRtF1pOL_BP83h7Gw6FLrVR_2OIPn92WAi0nWd0jZzgkz75qVk2nLXaW0EXngeZehZdO7gEv8SKibUb0DNsrUjGoj7HehHLrfN Feb 18 23:37:02 volumio volumio[7553]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 18 23:37:02 volumio sudo[7838]: pam_unix(sudo:session): session closed for user root Feb 18 23:37:02 volumio volumio[7553]: info: CoreCommandRouter::volumioGetState Feb 18 23:37:02 volumio volumio[7553]: info: CorePlayQueue::getTrack 0 Feb 18 23:37:02 volumio volumio[7553]: info: Shairport-Sync Started Feb 18 23:37:02 volumio volumio[7553]: Error adding Membership: Error: addMembership EINVAL Feb 18 23:37:02 volumio volumio[7553]: info: Shairport-Sync Started Feb 18 23:37:02 volumio volumio[7553]: info: Shairport-Sync Started Feb 18 23:37:02 volumio volumio[7553]: SPOTIFY: User informations: {"country":"PK","display_name":"215mmgea6kss3jxeqsqdquvji","email":"linh.ngotran@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/215mmgea6kss3jxeqsqdquvji"},"followers":{"href":null,"total":1},"href":"https://api.spotify.com/v1/users/215mmgea6kss3jxeqsqdquvji","id":"215mmgea6kss3jxeqsqdquvji","images":[],"product":"premium","type":"user","uri":"spotify:user:215mmgea6kss3jxeqsqdquvji"} Feb 18 23:37:02 volumio volumio[7553]: info: Spotify Successfully logged in Feb 18 23:37:02 volumio volumio[7553]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 23:37:02 volumio volumio[7553]: info: [1771432622623] CoreMusicLibrary::Adding element Spotify Feb 18 23:37:02 volumio volumio[7553]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 23:37:02 volumio volumio[7553]: Cannot find translation for source YouTube Music Feb 18 23:37:02 volumio volumio[7553]: Cannot find translation for source Spotify Feb 18 23:37:03 volumio volumio[7553]: info: [yt-cast-receiver] DIAL server listening on port 8098 Feb 18 23:37:03 volumio volumio[7553]: info: CoreCommandRouter::volumioRetrievevolume Feb 18 23:37:03 volumio volumio[7553]: info: VolumeController:: Volume=100 Mute =false Feb 18 23:37:03 volumio volumio[7553]: info: CoreCommandRouter::volumioGetState Feb 18 23:37:03 volumio volumio[7553]: info: CorePlayQueue::getTrack 0 Feb 18 23:37:03 volumio volumio[7553]: info: CoreStateMachine::pushState Feb 18 23:37:03 volumio volumio[7553]: info: CorePlayQueue::getTrack 0 Feb 18 23:37:03 volumio volumio[7553]: info: CoreCommandRouter::volumioPushState Feb 18 23:37:04 volumio volumio[7553]: info: go-librespot daemon successfully initialized Feb 18 23:37:04 volumio mpd[7778]: 2026-02-18T23:37:04 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 18 23:37:04 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 18 23:37:04 volumio sudo[7751]: pam_unix(sudo:session): session closed for user root Feb 18 23:37:04 volumio sudo[7744]: pam_unix(sudo:session): session closed for user root Feb 18 23:37:04 volumio volumio[7553]: error: MPD error: The expression evaluated to a falsy value: Feb 18 23:37:04 volumio volumio[7553]: assert.ok(self.idling) Feb 18 23:37:04 volumio volumio[7553]: error: The expression evaluated to a falsy value: Feb 18 23:37:04 volumio volumio[7553]: assert.ok(self.idling) Feb 18 23:37:04 volumio volumio[7553]: info: MPD running with PID7778 Feb 18 23:37:04 volumio volumio[7553]: ,establishing connection Feb 18 23:37:04 volumio volumio[7553]: error: updateQueue error: null Feb 18 23:37:05 volumio volumio[7553]: info: Completed starting Core Plugins Feb 18 23:37:05 volumio volumio[7553]: info: ------------------------------------------- Feb 18 23:37:05 volumio volumio[7553]: info: ----- MyVolumio plugins startup ---- Feb 18 23:37:05 volumio volumio[7553]: info: ------------------------------------------- Feb 18 23:37:05 volumio volumio[7553]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 18 23:37:05 volumio volumio[7553]: error: updateQueue error: null Feb 18 23:37:05 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Feb 18 23:37:05 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 23:37:05 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 23:37:05 volumio go-librespot[7883]: go-librespot daemon starting... Feb 18 23:37:05 volumio go-librespot[7884]: time="2026-02-18T23:37:05+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 23:37:05 volumio go-librespot[7884]: time="2026-02-18T23:37:05+07:00" level=debug msg="app state loaded" Feb 18 23:37:05 volumio go-librespot[7884]: time="2026-02-18T23:37:05+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 23:37:05 volumio go-librespot[7884]: time="2026-02-18T23:37:05+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 23:37:05 volumio go-librespot[7884]: time="2026-02-18T23:37:05+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 18 23:37:05 volumio go-librespot[7884]: time="2026-02-18T23:37:05+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 18 23:37:05 volumio go-librespot[7884]: time="2026-02-18T23:37:05+07:00" level=info msg="zeroconf server listening on port 45151" Feb 18 23:37:06 volumio go-librespot[7884]: time="2026-02-18T23:37:06+07:00" level=debug msg="obtained new client token: AADSLoKAwICeLX9rihsvRlfZzgDBqyacUGs6Idgg9d2mgO2aRZQDhqU2y8LFg7GU71BW+lhRigwuTmJO7myyybuQ2r7UpYULLoNmxOrBND8La0VBDw8YlSNDlgjhGK17iGObJZQqM5O00mgwcVaQfHfuPYWnOIxL6updoR6tca+DhbQ/mS8WjmyGt1wk1CIiyy0MYjbAUO/CYyrcOEI83D95EiFc+PPcua7pgabN1IN16ZScaUhNfa4=" Feb 18 23:37:06 volumio go-librespot[7884]: time="2026-02-18T23:37:06+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 23:37:06 volumio go-librespot[7884]: time="2026-02-18T23:37:06+07:00" level=debug msg="completed keyexchange" Feb 18 23:37:06 volumio go-librespot[7884]: time="2026-02-18T23:37:06+07:00" level=debug msg="completed challenge" Feb 18 23:37:06 volumio go-librespot[7884]: time="2026-02-18T23:37:06+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 18 23:37:06 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 23:37:06 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 23:37:07 volumio volumio[7553]: info: Initializing connection to go-librespot Websocket Feb 18 23:37:07 volumio volumio[7553]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 18 23:37:09 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Feb 18 23:37:09 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 23:37:09 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 23:37:09 volumio go-librespot[7892]: go-librespot daemon starting... Feb 18 23:37:09 volumio go-librespot[7893]: time="2026-02-18T23:37:09+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 23:37:09 volumio go-librespot[7893]: time="2026-02-18T23:37:09+07:00" level=debug msg="app state loaded" Feb 18 23:37:09 volumio go-librespot[7893]: time="2026-02-18T23:37:09+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 23:37:09 volumio volumio[7553]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 18 23:37:10 volumio go-librespot[7893]: time="2026-02-18T23:37:10+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 23:37:10 volumio go-librespot[7893]: time="2026-02-18T23:37:10+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 18 23:37:10 volumio go-librespot[7893]: time="2026-02-18T23:37:10+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 18 23:37:10 volumio go-librespot[7893]: time="2026-02-18T23:37:10+07:00" level=info msg="zeroconf server listening on port 32991" Feb 18 23:37:10 volumio go-librespot[7893]: time="2026-02-18T23:37:10+07:00" level=debug msg="obtained new client token: AAAdMsLzFGITm7JzruXB74drzg7RNwCctzEIPJOFin1axKxpFrNOrwX7SfvOHw5saaAqvgSbBUsL1+eDgJl8kQYfIrel0RabzV7AoYZXeNs2jHLHLThiSQEXWtmgTMb7QKTsXxycU/fDMzcSoSNkyn9qp7dzS8HmiNjuMP3veNL4Ey5sMrLW/1jySnG4E5UzEe8mIAWm266uZhUnrxK6fGZW6Jtt+6GacVDallZjl0fxo/UCqcZ/9yKRXg==" Feb 18 23:37:10 volumio go-librespot[7893]: time="2026-02-18T23:37:10+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 23:37:10 volumio go-librespot[7893]: time="2026-02-18T23:37:10+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 18 23:37:10 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 23:37:10 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 23:37:10 volumio volumio[7553]: info: Initializing connection to go-librespot Websocket Feb 18 23:37:10 volumio volumio[7553]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 18 23:37:13 volumio volumio[7553]: info: Initializing connection to go-librespot Websocket Feb 18 23:37:13 volumio volumio[7553]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 18 23:37:13 volumio volumio[7553]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 18 23:37:13 volumio volumio[7553]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 18 23:37:13 volumio volumio[7553]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 18 23:37:13 volumio volumio[7553]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 18 23:37:13 volumio volumio[7553]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 18 23:37:13 volumio volumio[7553]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 18 23:37:13 volumio volumio[7553]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 18 23:37:13 volumio volumio[7553]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 18 23:37:13 volumio volumio[7553]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 18 23:37:13 volumio volumio[7553]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 18 23:37:13 volumio volumio[7553]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 18 23:37:13 volumio volumio[7553]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 18 23:37:13 volumio volumio[7553]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 18 23:37:13 volumio volumio[7553]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 18 23:37:13 volumio volumio[7553]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 18 23:37:13 volumio volumio[7553]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 18 23:37:13 volumio volumio[7553]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 18 23:37:13 volumio volumio[7553]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 18 23:37:13 volumio volumio[7553]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 18 23:37:13 volumio volumio[7553]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 18 23:37:13 volumio volumio[7553]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 18 23:37:13 volumio volumio[7553]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 18 23:37:13 volumio volumio[7553]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 18 23:37:13 volumio volumio[7553]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 18 23:37:13 volumio volumio[7553]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 18 23:37:13 volumio volumio[7553]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 18 23:37:13 volumio volumio[7553]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 18 23:37:13 volumio volumio[7553]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 18 23:37:13 volumio volumio[7553]: info: Adding plugin bluetooth to MyMusic Plugins Feb 18 23:37:13 volumio volumio[7553]: info: Adding plugin multiroom to MyMusic Plugins Feb 18 23:37:13 volumio volumio[7553]: info: Adding plugin metavolumio to MyMusic Plugins Feb 18 23:37:13 volumio volumio[7553]: info: Adding plugin cd_controller to MyMusic Plugins Feb 18 23:37:13 volumio volumio[7553]: info: Adding plugin qobuzconnect to MyMusic Plugins Feb 18 23:37:13 volumio volumio[7553]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 18 23:37:13 volumio volumio[7553]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 18 23:37:13 volumio volumio[7553]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 18 23:37:13 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Feb 18 23:37:13 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 23:37:13 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 23:37:13 volumio go-librespot[7900]: go-librespot daemon starting... Feb 18 23:37:13 volumio go-librespot[7901]: time="2026-02-18T23:37:13+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 23:37:13 volumio go-librespot[7901]: time="2026-02-18T23:37:13+07:00" level=debug msg="app state loaded" Feb 18 23:37:13 volumio go-librespot[7901]: time="2026-02-18T23:37:13+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 23:37:14 volumio go-librespot[7901]: time="2026-02-18T23:37:14+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 23:37:14 volumio go-librespot[7901]: time="2026-02-18T23:37:14+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 18 23:37:14 volumio go-librespot[7901]: time="2026-02-18T23:37:14+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 18 23:37:14 volumio go-librespot[7901]: time="2026-02-18T23:37:14+07:00" level=info msg="zeroconf server listening on port 38943" Feb 18 23:37:14 volumio go-librespot[7901]: time="2026-02-18T23:37:14+07:00" level=debug msg="obtained new client token: AAA5jcvgOvZFWoVCduO6FxBhFjAZS/RbsyU38BnjXkrIlPeaF3wOlZoAll9an5kM/Nqm9dGVgduyrZWkCbFKNel9WUQc0SIJlet+5ZaGm1BdLGhX6G3SIPDwgQzzIH9QXwLh52/rn9kiDm16H63cR8XHscLSPD0+GkfSIrRH5NS+WXsRIT/YcxnaskDMvC99KwMlxMUmVBev3qfJDkX0x9uO2+hEVTimg7FUMVcM3ftiB7vwXFKzJcZ+jw==" Feb 18 23:37:14 volumio go-librespot[7901]: time="2026-02-18T23:37:14+07:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:4070, retrying with a different AP" error="dial tcp 104.199.241.202:4070: connect: connection refused" Feb 18 23:37:14 volumio go-librespot[7901]: time="2026-02-18T23:37:14+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Feb 18 23:37:15 volumio go-librespot[7901]: time="2026-02-18T23:37:15+07:00" level=debug msg="completed keyexchange" Feb 18 23:37:15 volumio go-librespot[7901]: time="2026-02-18T23:37:15+07:00" level=debug msg="completed challenge" Feb 18 23:37:15 volumio go-librespot[7901]: time="2026-02-18T23:37:15+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 18 23:37:15 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 23:37:15 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 23:37:15 volumio volumio[7553]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 18 23:37:15 volumio volumio[7553]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 18 23:37:15 volumio volumio[7553]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 23:37:15 volumio volumio[7553]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 23:37:15 volumio volumio[7553]: info: Starting MyVolumio Remote Streaming Endpoints Feb 18 23:37:15 volumio volumio[7553]: info: MyVolumio login type: Token Feb 18 23:37:15 volumio volumio[7553]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 18 23:37:15 volumio volumio[7553]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 18 23:37:17 volumio volumio[7553]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 18 23:37:17 volumio volumio[7553]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 18 23:37:17 volumio volumio[7553]: info: Streaming services startup Feb 18 23:37:17 volumio volumio[7553]: info: Starting Streaming Daemon Feb 18 23:37:17 volumio sudo[7923]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 18 23:37:17 volumio sudo[7923]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 23:37:17 volumio volumio[7553]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 18 23:37:17 volumio sudo[7923]: pam_unix(sudo:session): session closed for user root Feb 18 23:37:17 volumio volumio[7553]: info: Initializing connection to go-librespot Websocket Feb 18 23:37:17 volumio volumio[7553]: error: Cannot start Volumio Streaming Daemon Feb 18 23:37:17 volumio volumio[7553]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 18 23:37:17 volumio volumio[7553]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 18 23:37:17 volumio volumio[7553]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 18 23:37:18 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Feb 18 23:37:18 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 23:37:18 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 23:37:18 volumio go-librespot[7929]: go-librespot daemon starting... Feb 18 23:37:18 volumio go-librespot[7930]: time="2026-02-18T23:37:18+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 23:37:18 volumio go-librespot[7930]: time="2026-02-18T23:37:18+07:00" level=debug msg="app state loaded" Feb 18 23:37:18 volumio go-librespot[7930]: time="2026-02-18T23:37:18+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 23:37:18 volumio volumio[7553]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Feb 18 23:37:18 volumio go-librespot[7930]: time="2026-02-18T23:37: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 23:37:18 volumio go-librespot[7930]: time="2026-02-18T23:37:18+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 18 23:37:18 volumio go-librespot[7930]: time="2026-02-18T23:37:18+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 18 23:37:18 volumio go-librespot[7930]: time="2026-02-18T23:37:18+07:00" level=info msg="zeroconf server listening on port 45619" Feb 18 23:37:19 volumio go-librespot[7930]: time="2026-02-18T23:37:19+07:00" level=debug msg="obtained new client token: AAD5ewEqlcDcQxmmDD1RrPmbW2P/du5DZ1rjt6p0802gdMlT2VqZCsLHtWyQYi+zkvdKlapr9Gzrr3RXX95u8+lvBBQrUSiRVycWhdL0WMU2a3yJQq1EL8r8AvVGlklUK4ZaW3bYWbtNzRK7ANNBY52OUKPK6IkI77q/ZSZbEMfEwDhxRdnr6n1eigSXJkv0OTtmehVw5PGg+5tB40iOXoGrqxS2Hkl5NNpuqjqR6ksMP2reCCMGPI0=" Feb 18 23:37:19 volumio go-librespot[7930]: time="2026-02-18T23:37:19+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 23:37:19 volumio go-librespot[7930]: time="2026-02-18T23:37:19+07:00" level=debug msg="completed keyexchange" Feb 18 23:37:19 volumio go-librespot[7930]: time="2026-02-18T23:37:19+07:00" level=debug msg="completed challenge" Feb 18 23:37:19 volumio go-librespot[7930]: time="2026-02-18T23:37:19+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 18 23:37:19 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 23:37:19 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 23:37:19 volumio volumio[7553]: info: MyVolumio token set successfully Feb 18 23:37:19 volumio volumio[7553]: info: MYVOLUMIO: Adding device Feb 18 23:37:19 volumio volumio[7553]: info: MYVOLUMIO: Evaluating Server Feb 18 23:37:20 volumio volumio[7553]: info: MyVolumio status changed Feb 18 23:37:20 volumio volumio[7553]: info: Streaming services startup Feb 18 23:37:20 volumio volumio[7553]: info: Starting Streaming Daemon Feb 18 23:37:20 volumio volumio[7553]: info: Removing browser output: myVolumio user plan is not superstar Feb 18 23:37:20 volumio volumio[7553]: info: Removing audio output: Feb 18 23:37:20 volumio volumio[7553]: info: Stoppping Tunnel 1 Feb 18 23:37:20 volumio sudo[7958]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 18 23:37:20 volumio sudo[7958]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 23:37:20 volumio sudo[7958]: pam_unix(sudo:session): session closed for user root Feb 18 23:37:20 volumio sudo[7961]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Feb 18 23:37:20 volumio sudo[7961]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 23:37:20 volumio volumio[7553]: error: Cannot start Volumio Streaming Daemon Feb 18 23:37:20 volumio volumio[7553]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 18 23:37:20 volumio volumio[7553]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 18 23:37:20 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 18 23:37:20 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 18 23:37:20 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 18 23:37:20 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 18 23:37:20 volumio volumio[7553]: info: Setting Geolocation for MyVolumio to as1 Feb 18 23:37:20 volumio volumio[7553]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 23:37:20 volumio volumio[7553]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 23:37:20 volumio volumio[7553]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 23:37:20 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 18 23:37:20 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 18 23:37:20 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 18 23:37:20 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 18 23:37:20 volumio sudo[7961]: pam_unix(sudo:session): session closed for user root Feb 18 23:37:20 volumio volumio[7553]: info: Remote SSH Stopped Feb 18 23:37:20 volumio volumio[7553]: info: Initializing connection to go-librespot Websocket Feb 18 23:37:20 volumio volumio[7553]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 18 23:37:20 volumio volumio[7553]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Feb 18 23:37:21 volumio volumio[7553]: info: Updating MyVolumio device info Feb 18 23:37:21 volumio volumio[7553]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 23:37:21 volumio volumio[7553]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 23:37:21 volumio volumio[7553]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 23:37:21 volumio volumio[7553]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Feb 18 23:37:22 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Feb 18 23:37:22 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 23:37:22 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 23:37:22 volumio go-librespot[7963]: go-librespot daemon starting... Feb 18 23:37:22 volumio go-librespot[7964]: time="2026-02-18T23:37:22+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 23:37:22 volumio go-librespot[7964]: time="2026-02-18T23:37:22+07:00" level=debug msg="app state loaded" Feb 18 23:37:22 volumio go-librespot[7964]: time="2026-02-18T23:37:22+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 23:37:23 volumio go-librespot[7964]: time="2026-02-18T23:37:23+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 23:37:23 volumio go-librespot[7964]: time="2026-02-18T23:37:23+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 18 23:37:23 volumio go-librespot[7964]: time="2026-02-18T23:37:23+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 18 23:37:23 volumio go-librespot[7964]: time="2026-02-18T23:37:23+07:00" level=info msg="zeroconf server listening on port 38019" Feb 18 23:37:23 volumio go-librespot[7964]: time="2026-02-18T23:37:23+07:00" level=debug msg="obtained new client token: AACQZ0Q+KXdJvgZqNbt0rmq/au3qhhoqFhp4cEYi5UHgUY3oIrbDeY2/3hpDX0j4F2oqoYRyIKVQ9dv7IILdCv1rtOs77Y2X/XjR1K59oPmg9V2b3Bn1hlKbyPaleft3Y/eWSUslrFoKFbWbAyilRs6DahKs5GUrWZIYd1LWFD7rfMx0iPfNrA8lKqvcYTU2cJQPwTXlHWuawfJFXZG7bPeAr6HB2u1J84cNkGvC0c3rgUygJNCsNcgVJQ==" Feb 18 23:37:23 volumio go-librespot[7964]: time="2026-02-18T23:37:23+07:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:4070, retrying with a different AP" error="dial tcp 104.199.241.202:4070: connect: connection refused" Feb 18 23:37:23 volumio go-librespot[7964]: time="2026-02-18T23:37:23+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 18 23:37:23 volumio go-librespot[7964]: time="2026-02-18T23:37:23+07:00" level=debug msg="connected to ap-gae2.spotify.com:80" Feb 18 23:37:23 volumio volumio[7553]: info: Initializing connection to go-librespot Websocket Feb 18 23:37:23 volumio go-librespot[7964]: time="2026-02-18T23:37:23+07:00" level=debug msg="new websocket client" Feb 18 23:37:23 volumio volumio[7553]: info: Connection to go-librespot Websocket established Feb 18 23:37:23 volumio go-librespot[7964]: time="2026-02-18T23:37:23+07:00" level=debug msg="completed keyexchange" Feb 18 23:37:23 volumio go-librespot[7964]: time="2026-02-18T23:37:23+07:00" level=debug msg="completed challenge" Feb 18 23:37:23 volumio go-librespot[7964]: time="2026-02-18T23:37:23+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 18 23:37:23 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 23:37:23 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 23:37:23 volumio volumio[7553]: info: Connection to go-librespot Websocket closed Feb 18 23:37:24 volumio volumio[7553]: info: MYVOLUMIO: Adding device Feb 18 23:37:24 volumio volumio[7553]: info: MYVOLUMIO: Evaluating Server Feb 18 23:37:25 volumio volumio[7553]: info: Setting Geolocation for MyVolumio to as1 Feb 18 23:37:25 volumio volumio[7553]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 23:37:25 volumio volumio[7553]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 23:37:25 volumio volumio[7553]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 23:37:26 volumio volumio[7553]: info: Updating MyVolumio device info Feb 18 23:37:26 volumio volumio[7553]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 23:37:26 volumio volumio[7553]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 23:37:26 volumio volumio[7553]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 23:37:26 volumio volumio[7553]: info: Getting Spotify volume Feb 18 23:37:26 volumio volumio[7553]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 18 23:37:26 volumio volumio[7553]: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 18 23:37:26 volumio volumio[7553]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Feb 18 23:37:26 volumio volumio[7553]: errno: -111, Feb 18 23:37:26 volumio volumio[7553]: code: 'ECONNREFUSED', Feb 18 23:37:26 volumio volumio[7553]: syscall: 'connect', Feb 18 23:37:26 volumio volumio[7553]: address: '127.0.0.1', Feb 18 23:37:26 volumio volumio[7553]: port: 9879, Feb 18 23:37:26 volumio volumio[7553]: response: undefined Feb 18 23:37:26 volumio volumio[7553]: } Feb 18 23:37:26 volumio volumio[7553]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 18 23:37:27 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Feb 18 23:37:27 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 23:37:27 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 23:37:27 volumio go-librespot[8015]: go-librespot daemon starting... Feb 18 23:37:27 volumio go-librespot[8016]: time="2026-02-18T23:37:27+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 23:37:27 volumio go-librespot[8016]: time="2026-02-18T23:37:27+07:00" level=debug msg="app state loaded" Feb 18 23:37:27 volumio go-librespot[8016]: time="2026-02-18T23:37:27+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 23:37:27 volumio go-librespot[8016]: time="2026-02-18T23:37:27+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 23:37:27 volumio go-librespot[8016]: time="2026-02-18T23:37:27+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 18 23:37:27 volumio go-librespot[8016]: time="2026-02-18T23:37:27+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 18 23:37:27 volumio go-librespot[8016]: time="2026-02-18T23:37:27+07:00" level=info msg="zeroconf server listening on port 45899" Feb 18 23:37:27 volumio go-librespot[8016]: time="2026-02-18T23:37:27+07:00" level=debug msg="obtained new client token: AAC95EcPon2XbVQ/dkmDMHQfQZFAW6295or5YEO99mzz3E4+C7qDoZVL1jpKXZSPbDWkvBu2erZXUlEQl9BYMiFX4nbWBGXOrlmkKsu9leoEk+owWFQYOekgLOqFOQ63XVBTafParny3nj7AuQYfg8nGDL4OCs0DjaIDnNXqvRd0yEfG+qc7KdQUcjDG3xRxkVc8LpjzYZhvp48As7Cor5UO/TzuhEPtbXfXXNi1qh2nq8AQVXonQOWGVg==" Feb 18 23:37:27 volumio go-librespot[8016]: time="2026-02-18T23:37:27+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 23:37:28 volumio go-librespot[8016]: time="2026-02-18T23:37:28+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 18 23:37:28 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 23:37:28 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 23:37:28 volumio sudo[8026]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-18 23:36' Feb 18 23:37:28 volumio sudo[8026]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 23:37:28 volumio sudo[8026]: pam_unix(sudo:session): session closed for user root Feb 18 23:37:28 volumio volumio-remote-updater[25144]: [2026-02-18 23:37:28] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Feb 18 23:37:28 volumio volumio-remote-updater[25144]: [2026-02-18 23:37:28] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Feb 18 23:37:28 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Feb 18 23:37:28 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Feb 18 23:37:28 volumio systemd[1]: volumio.service: Consumed 58.773s CPU time. Feb 18 23:37:28 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 18 23:37:28 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 18 23:37:28 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 22603. Feb 18 23:37:28 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 18 23:37:28 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Feb 18 23:37:28 volumio systemd[1]: volumio.service: Consumed 58.773s CPU time. Feb 18 23:37:28 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Feb 18 23:37:28 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 18 23:37:31 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Feb 18 23:37:31 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 23:37:31 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 23:37:31 volumio go-librespot[8056]: go-librespot daemon starting... Feb 18 23:37:31 volumio go-librespot[8057]: time="2026-02-18T23:37:31+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 23:37:31 volumio go-librespot[8057]: time="2026-02-18T23:37:31+07:00" level=debug msg="app state loaded" Feb 18 23:37:31 volumio go-librespot[8057]: time="2026-02-18T23:37:31+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 23:37:31 volumio go-librespot[8057]: time="2026-02-18T23:37: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-gew4.spotify.com:80]" Feb 18 23:37:31 volumio go-librespot[8057]: time="2026-02-18T23:37:31+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 18 23:37:31 volumio go-librespot[8057]: time="2026-02-18T23:37:31+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 18 23:37:31 volumio go-librespot[8057]: time="2026-02-18T23:37:31+07:00" level=info msg="zeroconf server listening on port 37971" Feb 18 23:37:32 volumio go-librespot[8057]: time="2026-02-18T23:37:32+07:00" level=debug msg="obtained new client token: AADHPHZMMc7pnReb1oxt/Iz8WixkWI8U1Nr85DBb4aRXP+aOuOJ+GlCND/GhkgYn5GpK3Pv7vRcG1Kvyi9Vz1m49U+0LjsdSqWQCFBI+OqYqoGi3m5DH9EGXfEmLPl0M0x/3uHltQMvYD0NMKnGG5n9JsyLujtoYXQr9hr4+ZIxAtRB2nEiURZpQnbg/drnY5od3fl87PQArsfaCTCetb9fxbuNpFCnkCxe6wduAir8bAlR/WMPuYbwZdw==" Feb 18 23:37:32 volumio go-librespot[8057]: time="2026-02-18T23:37:32+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 23:37:32 volumio go-librespot[8057]: time="2026-02-18T23:37:32+07:00" level=debug msg="completed keyexchange" Feb 18 23:37:32 volumio go-librespot[8057]: time="2026-02-18T23:37:32+07:00" level=debug msg="completed challenge" Feb 18 23:37:32 volumio go-librespot[8057]: time="2026-02-18T23:37:32+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 18 23:37:32 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 23:37:32 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 23:37:32 volumio volumio[8041]: info: ------------------------------------------- Feb 18 23:37:32 volumio volumio[8041]: info: ----- Volumio3 ---- Feb 18 23:37:32 volumio volumio[8041]: info: ------------------------------------------- Feb 18 23:37:32 volumio volumio[8041]: info: ----- System startup ---- Feb 18 23:37:32 volumio volumio[8041]: info: ------------------------------------------- Feb 18 23:37:33 volumio volumio-remote-updater[25144]: [2026-02-18 23:37:33] [connect] Successful connection Feb 18 23:37:33 volumio volumio[8041]: info: MYVOLUMIO Environment detected Feb 18 23:37:34 volumio volumio[8041]: info: Plugin folders cleanup Feb 18 23:37:34 volumio volumio[8041]: info: Scanning into folder /volumio/app/plugins/ Feb 18 23:37:34 volumio volumio[8041]: info: Scanning category audio_interface Feb 18 23:37:34 volumio volumio[8041]: info: Scanning category miscellanea Feb 18 23:37:34 volumio volumio[8041]: info: Scanning category music_service Feb 18 23:37:34 volumio volumio[8041]: info: Scanning category plugins.json Feb 18 23:37:34 volumio volumio[8041]: info: Scanning category system_controller Feb 18 23:37:34 volumio volumio[8041]: info: Scanning category user_interface Feb 18 23:37:34 volumio volumio[8041]: info: Scanning into folder /data/plugins/ Feb 18 23:37:34 volumio volumio[8041]: info: Scanning category music_service Feb 18 23:37:34 volumio volumio[8041]: info: Plugin folders cleanup completed Feb 18 23:37:34 volumio volumio[8041]: info: ------------------------------------------- Feb 18 23:37:34 volumio volumio[8041]: info: ----- Core plugins startup ---- Feb 18 23:37:34 volumio volumio[8041]: info: ------------------------------------------- Feb 18 23:37:34 volumio volumio[8041]: info: Loading plugins from folder /volumio/app/plugins/ Feb 18 23:37:34 volumio volumio[8041]: info: Adding plugin upnp to MyMusic Plugins Feb 18 23:37:34 volumio volumio[8041]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 18 23:37:34 volumio volumio[8041]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 18 23:37:34 volumio volumio[8041]: info: Loading plugins from folder /data/plugins/ Feb 18 23:37:34 volumio volumio[8041]: info: Loading plugin "system"... Feb 18 23:37:34 volumio volumio[8041]: info: Loading plugin "appearance"... Feb 18 23:37:35 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Feb 18 23:37:35 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 23:37:35 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 23:37:35 volumio go-librespot[8076]: go-librespot daemon starting... Feb 18 23:37:35 volumio go-librespot[8077]: time="2026-02-18T23:37:35+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 23:37:35 volumio go-librespot[8077]: time="2026-02-18T23:37:35+07:00" level=debug msg="app state loaded" Feb 18 23:37:35 volumio go-librespot[8077]: time="2026-02-18T23:37:35+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 23:37:35 volumio go-librespot[8077]: time="2026-02-18T23:37: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 18 23:37:35 volumio go-librespot[8077]: time="2026-02-18T23:37: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 18 23:37:35 volumio go-librespot[8077]: time="2026-02-18T23:37: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 18 23:37:35 volumio go-librespot[8077]: time="2026-02-18T23:37:35+07:00" level=info msg="zeroconf server listening on port 40889" Feb 18 23:37:36 volumio volumio[8041]: info: Loading plugin "network"... Feb 18 23:37:36 volumio volumio[8041]: info: Refreshing Cached IP Addresses Feb 18 23:37:36 volumio sudo[8085]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 18 23:37:36 volumio sudo[8085]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 23:37:36 volumio go-librespot[8077]: time="2026-02-18T23:37:36+07:00" level=debug msg="obtained new client token: AAArj5mPuCKTtZrsvl9cJwK0z7usUVsITI7+UatyIkAbsRvpzVGs5vVicETSIkWCei7+hrrMkhX+kFMo55xa7pvzNcTK9j372XJQxJlNpju2nfHfxtGzNw3WtV848bPV2HigQjAUu2yLreQlqctoN4WdClZ8KkiemLPvlxK/SDLlWfSV5+eb7x5anDvFuCOfuOy9ulCDrZ8m32T2irjEIw4334FfF0PLeQlUfMPp/Nm+m9Q/I0uGEOU=" Feb 18 23:37:36 volumio sudo[8085]: pam_unix(sudo:session): session closed for user root Feb 18 23:37:36 volumio volumio[8041]: info: Loading plugin "services"... Feb 18 23:37:36 volumio sudo[8087]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 18 23:37:36 volumio sudo[8087]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 23:37:36 volumio volumio[8041]: info: Loading plugin "alsa_controller"... Feb 18 23:37:36 volumio sudo[8087]: pam_unix(sudo:session): session closed for user root Feb 18 23:37:36 volumio sudo[8095]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 18 23:37:36 volumio sudo[8095]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 23:37:36 volumio go-librespot[8077]: time="2026-02-18T23:37:36+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 23:37:36 volumio volumio[8041]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 18 23:37:36 volumio volumio[8041]: info: Loading plugin "wizard"... Feb 18 23:37:36 volumio volumio[8041]: info: Loading plugin "networkfs"... Feb 18 23:37:36 volumio volumio[8041]: info: Starting Udev Watcher for removable devices Feb 18 23:37:36 volumio go-librespot[8077]: time="2026-02-18T23:37:36+07:00" level=debug msg="completed keyexchange" Feb 18 23:37:36 volumio go-librespot[8077]: time="2026-02-18T23:37:36+07:00" level=debug msg="completed challenge" Feb 18 23:37:36 volumio volumio[8041]: info: Ignoring mount for partition: boot Feb 18 23:37:36 volumio volumio[8041]: info: Ignoring mount for partition: volumio Feb 18 23:37:36 volumio volumio[8041]: info: Ignoring mount for partition: volumio_data Feb 18 23:37:36 volumio volumio[8041]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 18 23:37:36 volumio volumio[8041]: info: Loading plugin "volumio_command_line_client"... Feb 18 23:37:36 volumio volumio[8041]: info: Loading plugin "upnp"... Feb 18 23:37:36 volumio volumio[8041]: info: [1771432656502] Starting Upmpd Daemon Feb 18 23:37:36 volumio volumio[8041]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 18 23:37:36 volumio volumio[8041]: info: Loading plugin "my_music"... Feb 18 23:37:36 volumio go-librespot[8077]: time="2026-02-18T23:37: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 18 23:37:36 volumio volumio[8041]: info: Loading plugin "mpd"... Feb 18 23:37:36 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 23:37:36 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 23:37:37 volumio volumio[8041]: info: Loading plugin "upnp_browser"... Feb 18 23:37:39 volumio sudo[8095]: pam_unix(sudo:session): session closed for user root Feb 18 23:37:39 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Feb 18 23:37:39 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 23:37:39 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 23:37:39 volumio go-librespot[8118]: go-librespot daemon starting... Feb 18 23:37:39 volumio go-librespot[8119]: time="2026-02-18T23:37:39+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 23:37:39 volumio go-librespot[8119]: time="2026-02-18T23:37:39+07:00" level=debug msg="app state loaded" Feb 18 23:37:39 volumio go-librespot[8119]: time="2026-02-18T23:37:39+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 23:37:40 volumio volumio[8041]: info: Starting UPNP Browser Feb 18 23:37:40 volumio volumio[8041]: info: Loading plugin "alarm-clock"... Feb 18 23:37:40 volumio go-librespot[8119]: time="2026-02-18T23:37:40+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 23:37:40 volumio go-librespot[8119]: time="2026-02-18T23:37:40+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 18 23:37:40 volumio go-librespot[8119]: time="2026-02-18T23:37:40+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 18 23:37:40 volumio go-librespot[8119]: time="2026-02-18T23:37:40+07:00" level=info msg="zeroconf server listening on port 43119" Feb 18 23:37:40 volumio volumio[8041]: info: Loading plugin "airplay_emulation"... Feb 18 23:37:40 volumio volumio[8041]: info: Starting Shairport Sync Feb 18 23:37:40 volumio volumio[8041]: info: Loading plugin "last_100"... Feb 18 23:37:40 volumio volumio[8041]: info: Loading plugin "webradio"... Feb 18 23:37:40 volumio go-librespot[8119]: time="2026-02-18T23:37:40+07:00" level=debug msg="obtained new client token: AADw7dux2cvGnacIoG/2sTkL/7UEALTlitnz6jaM4ehyuULPVS5lfUWFn0s0dKp5Ey3uINMpZmwPjv+ekS74p3M2gks9rWh9X9HktdEfeiYoBXu+hEBPgvY9hXaLACCE4lRd0j6iigwUNH2YeLXDwFiItGxcqNnBMdGyVYx9UEIfkVzBf4mKrWeQN/9Sv4fSyZV9quqqM6iy90qebFocF1KWz1xvGKcfsbIU9ndpQdJr22hphjkacIkMsA==" Feb 18 23:37:40 volumio go-librespot[8119]: time="2026-02-18T23:37:40+07:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:4070, retrying with a different AP" error="dial tcp 104.199.241.202:4070: connect: connection refused" Feb 18 23:37:40 volumio volumio[8041]: info: Loading plugin "i2s_dacs"... Feb 18 23:37:40 volumio go-librespot[8119]: time="2026-02-18T23:37:40+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 18 23:37:40 volumio volumio[8041]: info: Loading plugin "volumiodiscovery"... Feb 18 23:37:40 volumio go-librespot[8119]: time="2026-02-18T23:37:40+07:00" level=debug msg="connected to ap-gae2.spotify.com:80" Feb 18 23:37:40 volumio volumio[8041]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 18 23:37:40 volumio volumio[8041]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 18 23:37:40 volumio volumio[8041]: *** WARNING *** For more information see Feb 18 23:37:40 volumio volumio[8041]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 18 23:37:40 volumio volumio[8041]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 18 23:37:40 volumio volumio[8041]: *** WARNING *** For more information see Feb 18 23:37:40 volumio node[8041]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 18 23:37:40 volumio node[8041]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 18 23:37:40 volumio node[8041]: *** WARNING *** For more information see Feb 18 23:37:40 volumio node[8041]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 18 23:37:40 volumio node[8041]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 18 23:37:40 volumio node[8041]: *** WARNING *** For more information see Feb 18 23:37:40 volumio volumio[8041]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 18 23:37:40 volumio volumio[8041]: info: Discovery: Started advertising with name: Volumio Feb 18 23:37:40 volumio volumio[8041]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 18 23:37:40 volumio volumio[8041]: info: Loading plugin "spop"... Feb 18 23:37:40 volumio go-librespot[8119]: time="2026-02-18T23:37:40+07:00" level=debug msg="completed keyexchange" Feb 18 23:37:40 volumio go-librespot[8119]: time="2026-02-18T23:37:40+07:00" level=debug msg="completed challenge" Feb 18 23:37:40 volumio go-librespot[8119]: time="2026-02-18T23:37: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 18 23:37:40 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 23:37:40 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 23:37:42 volumio volumio[8041]: info: Loading plugin "ytcr"... Feb 18 23:37:44 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Feb 18 23:37:44 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 23:37:44 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 23:37:44 volumio go-librespot[8129]: go-librespot daemon starting... Feb 18 23:37:44 volumio go-librespot[8130]: time="2026-02-18T23:37:44+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 23:37:44 volumio go-librespot[8130]: time="2026-02-18T23:37:44+07:00" level=debug msg="app state loaded" Feb 18 23:37:44 volumio go-librespot[8130]: time="2026-02-18T23:37:44+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 23:37:44 volumio go-librespot[8130]: time="2026-02-18T23:37:44+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 23:37:44 volumio go-librespot[8130]: time="2026-02-18T23:37:44+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 18 23:37:44 volumio go-librespot[8130]: time="2026-02-18T23:37:44+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 18 23:37:44 volumio go-librespot[8130]: time="2026-02-18T23:37:44+07:00" level=info msg="zeroconf server listening on port 38615" Feb 18 23:37:44 volumio go-librespot[8130]: time="2026-02-18T23:37:44+07:00" level=debug msg="obtained new client token: AACgl9EDZyAnVw6XUhaPGuojEikz41aIalA16QPcHCBBe/AVDK096SIvPKGm9AL0WPjZ/hWzlOZkvDMjk3HF790wt5kAlhJcq/JjNvQoCizcDEvtCxFa4Xuh3t1bU87muhDIuJUPazf8b0hg7OGSJq9+L7RlWQQhvC8kC2M50JUEpfwFVEBaY2M4297lAWrZv7wS8qmAL/KuqBoQqOpmDefVK9CKaMU8pmmXVW+PXKNfpMkteh6xMeR3fA==" Feb 18 23:37:45 volumio go-librespot[8130]: time="2026-02-18T23:37:45+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 23:37:45 volumio go-librespot[8130]: time="2026-02-18T23:37:45+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 18 23:37:45 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 23:37:45 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 23:37:45 volumio volumio[8041]: info: Loading plugin "ytmusic"... Feb 18 23:37:46 volumio volumio-remote-updater[25144]: [2026-02-18 23:37:46] [connect] Successful connection Feb 18 23:37:46 volumio volumio[8041]: info: Loading plugin "outputs"... Feb 18 23:37:46 volumio volumio[8041]: info: Loading plugin "albumart"... Feb 18 23:37:46 volumio volumio[8041]: info: Plugin example_plugin is not enabled Feb 18 23:37:46 volumio volumio[8041]: info: Loading plugin "inputs"... Feb 18 23:37:46 volumio volumio[8041]: info: Loading plugin "updater_comm"... Feb 18 23:37:46 volumio volumio[8041]: info: Plugin mpdemulation is not enabled Feb 18 23:37:46 volumio volumio[8041]: info: Loading plugin "rest_api"... Feb 18 23:37:46 volumio volumio[8041]: info: Loading plugin "websocket"... Feb 18 23:37:46 volumio volumio[8041]: info: Starting Socket.io Server version 1.7.4 Feb 18 23:37:46 volumio volumio[8041]: info: Loading plugin "RoonBridge"... Feb 18 23:37:47 volumio volumio[8041]: info: Applying required configuration parameters for plugin RoonBridge Feb 18 23:37:47 volumio volumio[8041]: info: Loading i18n strings for locale en Feb 18 23:37:47 volumio volumio[8041]: Updating browse sources language Feb 18 23:37:47 volumio volumio[8041]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 23:37:47 volumio volumio[8041]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 18 23:37:47 volumio volumio[8041]: info: CoreCommandRouter::initPlayerControls Feb 18 23:37:47 volumio volumio[8151]: Forking 3 albumart workers Feb 18 23:37:47 volumio volumio[8041]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 23:37:47 volumio volumio[8041]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 23:37:47 volumio volumio[8041]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 23:37:47 volumio volumio[8041]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 23:37:47 volumio volumio[8041]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 23:37:47 volumio volumio[8041]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 23:37:47 volumio volumio[8041]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 23:37:47 volumio volumio[8041]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 23:37:47 volumio volumio[8041]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 18 23:37:47 volumio volumio[8041]: Express server listening on port 3000 Feb 18 23:37:47 volumio volumio[8041]: [Metrics] WebUI: 15s 962.26ms Feb 18 23:37:47 volumio volumio[8041]: info: CoreStateMachine::resetVolumioState Feb 18 23:37:47 volumio volumio[8041]: info: CoreStateMachine::getcurrentVolume Feb 18 23:37:47 volumio volumio[8041]: info: CoreCommandRouter::volumioRetrievevolume Feb 18 23:37:47 volumio sudo[8193]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 18 23:37:47 volumio sudo[8193]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 23:37:47 volumio sudo[8193]: pam_unix(sudo:session): session closed for user root Feb 18 23:37:47 volumio sudo[8195]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 18 23:37:47 volumio sudo[8195]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 23:37:47 volumio sudo[8195]: pam_unix(sudo:session): session closed for user root Feb 18 23:37:47 volumio volumio[8041]: info: Volumio Network Manager: Network status updated: 1 Feb 18 23:37:48 volumio volumio[8041]: info: VolumeController:: Volume=100 Mute =false Feb 18 23:37:48 volumio volumio[8041]: info: CoreStateMachine::pushState Feb 18 23:37:48 volumio volumio[8041]: info: CorePlayQueue::getTrack 0 Feb 18 23:37:48 volumio volumio[8041]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 18 23:37:48 volumio volumio[8041]: info: CoreCommandRouter::volumioPushState Feb 18 23:37:48 volumio volumio[8041]: info: CoreStateMachine::updateTrackBlock Feb 18 23:37:48 volumio volumio[8041]: info: CorePlayQueue::getTrackBlock Feb 18 23:37:48 volumio volumio[8041]: info: CoreCommandRouter::volumioRetrievevolume Feb 18 23:37:48 volumio volumio-remote-updater[25144]: [2026-02-18 23:37:48] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1771432666 101 Feb 18 23:37:48 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 11. Feb 18 23:37:48 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 23:37:48 volumio volumio[8041]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 1 Feb 18 23:37:48 volumio volumio[8041]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 23:37:48 volumio volumio[8041]: info: Reloading queue from file Feb 18 23:37:48 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 23:37:48 volumio volumio[8041]: info: CoreStateMachine::setRepeat null single undefined Feb 18 23:37:48 volumio go-librespot[8204]: go-librespot daemon starting... Feb 18 23:37:48 volumio volumio[8041]: info: CoreStateMachine::pushState Feb 18 23:37:48 volumio volumio[8041]: info: CorePlayQueue::getTrack 0 Feb 18 23:37:48 volumio volumio[8041]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 18 23:37:48 volumio volumio[8041]: info: CoreCommandRouter::volumioPushState Feb 18 23:37:48 volumio volumio[8041]: info: CoreStateMachine::setRandom null Feb 18 23:37:48 volumio volumio[8041]: info: CoreStateMachine::pushState Feb 18 23:37:48 volumio volumio[8041]: info: CorePlayQueue::getTrack 0 Feb 18 23:37:48 volumio volumio[8041]: info: CoreCommandRouter::volumioPushState Feb 18 23:37:48 volumio volumio[8041]: info: Setting Device type: Raspberry PI Feb 18 23:37:48 volumio go-librespot[8210]: time="2026-02-18T23:37:48+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 23:37:48 volumio go-librespot[8210]: time="2026-02-18T23:37:48+07:00" level=debug msg="app state loaded" Feb 18 23:37:48 volumio go-librespot[8210]: time="2026-02-18T23:37:48+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 23:37:48 volumio volumio[8041]: info: Completed loading Core Plugins Feb 18 23:37:48 volumio volumio[8041]: info: Preparing to generate the ALSA configuration file Feb 18 23:37:48 volumio volumio[8041]: info: VolumeController:: Volume=100 Mute =false Feb 18 23:37:48 volumio volumio[8041]: info: CoreStateMachine::pushState Feb 18 23:37:48 volumio volumio[8041]: info: CorePlayQueue::getTrack 0 Feb 18 23:37:48 volumio volumio[8041]: info: CoreCommandRouter::volumioPushState Feb 18 23:37:48 volumio volumio[8041]: info: Asound.conf file unchanged, so no further update is needed Feb 18 23:37:48 volumio volumio[8041]: info: Output device has changed, restarting MPD Feb 18 23:37:48 volumio sudo[8219]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 18 23:37:48 volumio sudo[8219]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 23:37:48 volumio volumio[8041]: info: Output device has changed, restarting Shairport Sync Feb 18 23:37:48 volumio volumio[8041]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 23:37:48 volumio volumio[8041]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 23:37:48 volumio sudo[8222]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 18 23:37:48 volumio sudo[8222]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 23:37:48 volumio sudo[8222]: pam_unix(sudo:session): session closed for user root Feb 18 23:37:48 volumio sudo[8219]: pam_unix(sudo:session): session closed for user root Feb 18 23:37:48 volumio sudo[8224]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 18 23:37:48 volumio sudo[8224]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 23:37:48 volumio volumio[8041]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 18 23:37:48 volumio volumio[8041]: info: ___________ START PLUGINS ___________ Feb 18 23:37:49 volumio volumio[8041]: info: ControllerMpd::onStart: Initializing MPD Feb 18 23:37:49 volumio volumio[8041]: info: Creating MPD Configuration file Feb 18 23:37:49 volumio volumio[8041]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 18 23:37:49 volumio volumio[8041]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 23:37:49 volumio volumio[8041]: info: [1771432669086] CoreMusicLibrary::Adding element Media Servers Feb 18 23:37:49 volumio volumio[8041]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 23:37:49 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 18 23:37:49 volumio volumio[8041]: info: UPNP Browser: Client initialized successfully Feb 18 23:37:49 volumio sudo[8236]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 18 23:37:49 volumio sudo[8236]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 23:37:49 volumio sudo[8234]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 18 23:37:49 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 18 23:37:49 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 18 23:37:49 volumio systemd[1]: mpd.service: Consumed 7.197s CPU time. Feb 18 23:37:49 volumio sudo[8234]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 23:37:49 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 18 23:37:49 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 18 23:37:49 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 18 23:37:49 volumio go-librespot[8210]: time="2026-02-18T23:37:49+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 23:37:49 volumio go-librespot[8210]: time="2026-02-18T23:37:49+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 18 23:37:49 volumio go-librespot[8210]: time="2026-02-18T23:37:49+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 18 23:37:49 volumio sudo[8234]: pam_unix(sudo:session): session closed for user root Feb 18 23:37:49 volumio volumio[8041]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 23:37:49 volumio volumio[8041]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 23:37:49 volumio go-librespot[8210]: time="2026-02-18T23:37:49+07:00" level=info msg="zeroconf server listening on port 38961" Feb 18 23:37:49 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 18 23:37:49 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 18 23:37:49 volumio volumio[8041]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 18 23:37:49 volumio volumio[8041]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 23:37:49 volumio volumio[8041]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 23:37:49 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 18 23:37:49 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 18 23:37:49 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 18 23:37:49 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 18 23:37:49 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 18 23:37:49 volumio volumio[8041]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 18 23:37:49 volumio volumio[8041]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 23:37:49 volumio volumio[8041]: info: [1771432669458] CoreMusicLibrary::Adding element Last_100 Feb 18 23:37:49 volumio volumio[8041]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 23:37:49 volumio volumio[8041]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 23:37:49 volumio volumio[8041]: info: [1771432669472] CoreMusicLibrary::Adding element Webradio Feb 18 23:37:49 volumio volumio[8041]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 23:37:49 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 18 23:37:49 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 18 23:37:49 volumio volumio[8041]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 18 23:37:49 volumio volumio[8041]: info: Initializing BBC Radios Feb 18 23:37:49 volumio go-librespot[8210]: time="2026-02-18T23:37:49+07:00" level=debug msg="obtained new client token: AACzycYE4QAGZ2QKYRyRsMXsqUlNrmAhoGtGy20+ZAOgcSwE0TsRwAH32EaiDgQQQc3Q8W0RE8yW0QrcaqD6nXpjMT2pfX+6LH0MMyMpzAUQs8wo7YnXoAycaxNygXve8d0uFpRnLqCR5jIbNR+m6PPRbRUAY28ocaawAvVECk4WRr2XYnmybZMV3mDYoI1p7y1S1V89NxEib+dx0Sp2D2aTlvLkmzUmKLePwodr832rG9bYXtsU8uJqNA==" Feb 18 23:37:49 volumio go-librespot[8210]: time="2026-02-18T23:37:49+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 23:37:49 volumio volumio[8041]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 18 23:37:49 volumio volumio[8041]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 23:37:49 volumio volumio[8041]: info: Creating Spotify config file Feb 18 23:37:49 volumio go-librespot[8210]: time="2026-02-18T23:37:49+07:00" level=debug msg="completed keyexchange" Feb 18 23:37:49 volumio volumio[8041]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 23:37:49 volumio go-librespot[8210]: time="2026-02-18T23:37:49+07:00" level=debug msg="completed challenge" Feb 18 23:37:49 volumio go-librespot[8210]: time="2026-02-18T23:37:49+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 18 23:37:49 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 23:37:49 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 23:37:50 volumio sudo[8250]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 18 23:37:50 volumio sudo[8250]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 18 23:37:50 volumio sudo[8250]: pam_unix(sudo:session): session closed for user root Feb 18 23:37:50 volumio volumio[8162]: Starting albumart workers Feb 18 23:37:50 volumio volumio[8041]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 23:37:50 volumio volumio[8041]: info: [1771432670954] CoreMusicLibrary::Adding element YouTube Music Feb 18 23:37:50 volumio volumio[8041]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 23:37:50 volumio volumio[8041]: Cannot find translation for source YouTube Music Feb 18 23:37:50 volumio volumio[8041]: info: Volumio Calling Home Feb 18 23:37:51 volumio sudo[8267]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Feb 18 23:37:51 volumio sudo[8267]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 23:37:51 volumio sudo[8267]: pam_unix(sudo:session): session closed for user root Feb 18 23:37:51 volumio volumio[8161]: Starting albumart workers Feb 18 23:37:51 volumio volumio[8163]: Starting albumart workers Feb 18 23:37:51 volumio volumio[8041]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Feb 18 23:37:51 volumio volumio[8041]: info: Discovery: Found device Volumio Feb 18 23:37:51 volumio volumio[8041]: info: CoreCommandRouter::volumioGetState Feb 18 23:37:51 volumio volumio[8041]: info: CorePlayQueue::getTrack 0 Feb 18 23:37:51 volumio volumio[8041]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Feb 18 23:37:51 volumio volumio[8041]: info: Discovery: Found device Volumio Feb 18 23:37:51 volumio volumio[8041]: info: CoreCommandRouter::volumioGetState Feb 18 23:37:51 volumio volumio[8041]: info: CorePlayQueue::getTrack 0 Feb 18 23:37:51 volumio volumio[8041]: info: MPD Permissions set Feb 18 23:37:51 volumio volumio[8041]: info: MPD Permissions set Feb 18 23:37:51 volumio volumio[8041]: info: Upmpdcli Daemon Started Feb 18 23:37:52 volumio volumio[8041]: info: Volumio called home Feb 18 23:37:52 volumio volumio[8041]: info: Spotify config file written Feb 18 23:37:52 volumio sudo[8274]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 18 23:37:52 volumio sudo[8274]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 23:37:52 volumio volumio[8041]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Feb 18 23:37:52 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 23:37:52 volumio volumio[8041]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 23:37:52 volumio volumio[8041]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 23:37:52 volumio volumio[8041]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 23:37:52 volumio volumio[8041]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 23:37:52 volumio volumio[8041]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 23:37:52 volumio volumio[8041]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 23:37:52 volumio volumio[8041]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 23:37:52 volumio volumio[8041]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 23:37:52 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 23:37:52 volumio go-librespot[8276]: go-librespot daemon starting... Feb 18 23:37:52 volumio sudo[8274]: pam_unix(sudo:session): session closed for user root Feb 18 23:37:52 volumio go-librespot[8279]: time="2026-02-18T23:37:52+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 23:37:52 volumio go-librespot[8279]: time="2026-02-18T23:37:52+07:00" level=debug msg="app state loaded" Feb 18 23:37:52 volumio go-librespot[8279]: time="2026-02-18T23:37:52+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 23:37:52 volumio volumio[8041]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 23:37:52 volumio volumio[8041]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 23:37:52 volumio volumio[8041]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 23:37:52 volumio volumio[8041]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 23:37:52 volumio volumio[8041]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 23:37:52 volumio volumio[8041]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 23:37:52 volumio volumio[8041]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 23:37:52 volumio volumio[8041]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 23:37:52 volumio volumio[8041]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 23:37:52 volumio volumio[8041]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 23:37:52 volumio volumio[8041]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 23:37:52 volumio volumio[8041]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 23:37:52 volumio volumio[8041]: info: No need to fix Spotify hosts Feb 18 23:37:53 volumio go-librespot[8279]: time="2026-02-18T23:37:53+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 23:37:53 volumio go-librespot[8279]: time="2026-02-18T23:37:53+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 18 23:37:53 volumio go-librespot[8279]: time="2026-02-18T23:37:53+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 18 23:37:53 volumio go-librespot[8279]: time="2026-02-18T23:37:53+07:00" level=info msg="zeroconf server listening on port 38291" Feb 18 23:37:53 volumio go-librespot[8279]: time="2026-02-18T23:37:53+07:00" level=debug msg="obtained new client token: AAALW520g1UPhrCgssj8fBNjJgm0/N9xPkvvXaYhldKK9X/0lQhyTl8eNX3I8C60kdhmNpZ3+seBT+yVGZ+RRDs0luKAKNuocwNDutKruJGKUPkKBiRfWJpWBhOn2NYqiz6DXIX8wvKRqGbeEvjGQzME9oytjP0qRCyv/h/0ATidQkyK8Mf2K15wVMmcVwb1KVD0QssaCgrNfiROklSLwn35dr/In1xryImvgzJuxrJPNZsck5RK07GQOA==" Feb 18 23:37:53 volumio go-librespot[8279]: time="2026-02-18T23:37:53+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 23:37:53 volumio go-librespot[8279]: time="2026-02-18T23:37:53+07:00" level=debug msg="completed keyexchange" Feb 18 23:37:53 volumio go-librespot[8279]: time="2026-02-18T23:37:53+07:00" level=debug msg="completed challenge" Feb 18 23:37:53 volumio volumio[8041]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 18 23:37:53 volumio volumio[8041]: SPOTIFY: BQDnISLI8tw01kt6-ns05b_gAhiOoeIZfvE4DqjMtBzk2FAKmtg_xa-iYdBz6yrkWYWTxsoYDarM9mXszLq_rBx2ghoHqdO8MBtM9LH-mPq_fvZXTiORc_7H8N11ee01eXn6XiiNw--I7wUCqI5QsseQDJFeNtPc0AIsYIrZHj0TRsi0AjmTgU310-y3KJyVLiof6bmFmviaKkwvspLYhNPsekgMSxdByG9CA-A6jVX4ejh_TngeELGlHgsfV4HBbKS4mmYupFZ47CzNX0ntofFiw8gUhMCEqKuc9TtoQO3Bv0PdPKDO0xXr Feb 18 23:37:53 volumio volumio[8041]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 18 23:37:53 volumio volumio[8041]: info: New Spotify access token = BQDnISLI8tw01kt6-ns05b_gAhiOoeIZfvE4DqjMtBzk2FAKmtg_xa-iYdBz6yrkWYWTxsoYDarM9mXszLq_rBx2ghoHqdO8MBtM9LH-mPq_fvZXTiORc_7H8N11ee01eXn6XiiNw--I7wUCqI5QsseQDJFeNtPc0AIsYIrZHj0TRsi0AjmTgU310-y3KJyVLiof6bmFmviaKkwvspLYhNPsekgMSxdByG9CA-A6jVX4ejh_TngeELGlHgsfV4HBbKS4mmYupFZ47CzNX0ntofFiw8gUhMCEqKuc9TtoQO3Bv0PdPKDO0xXr Feb 18 23:37:53 volumio volumio[8041]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 18 23:37:53 volumio volumio[8041]: info: Starting Shairport Sync Feb 18 23:37:53 volumio volumio[8041]: info: Starting Shairport Sync Feb 18 23:37:53 volumio go-librespot[8279]: time="2026-02-18T23:37:53+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 18 23:37:53 volumio volumio[8041]: info: Starting Shairport Sync Feb 18 23:37:53 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 23:37:53 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 23:37:54 volumio sudo[8313]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 18 23:37:54 volumio sudo[8317]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 18 23:37:54 volumio sudo[8317]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 23:37:54 volumio sudo[8313]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 23:37:54 volumio sudo[8315]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 18 23:37:54 volumio sudo[8315]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 23:37:54 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 18 23:37:54 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 18 23:37:54 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 18 23:37:54 volumio systemd[1]: shairport-sync.service: Consumed 2.392s CPU time. Feb 18 23:37:54 volumio volumio[8041]: info: CoreCommandRouter::volumioGetState Feb 18 23:37:54 volumio volumio[8041]: info: CorePlayQueue::getTrack 0 Feb 18 23:37:54 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 18 23:37:54 volumio sudo[8315]: pam_unix(sudo:session): session closed for user root Feb 18 23:37:54 volumio sudo[8313]: pam_unix(sudo:session): session closed for user root Feb 18 23:37:54 volumio sudo[8317]: pam_unix(sudo:session): session closed for user root Feb 18 23:37:54 volumio volumio[8041]: info: Shairport-Sync Started Feb 18 23:37:54 volumio volumio[8041]: Error adding Membership: Error: addMembership EINVAL Feb 18 23:37:54 volumio volumio[8041]: info: Shairport-Sync Started Feb 18 23:37:54 volumio volumio[8041]: info: Shairport-Sync Started Feb 18 23:37:54 volumio volumio[8041]: SPOTIFY: User informations: {"country":"PK","display_name":"215mmgea6kss3jxeqsqdquvji","email":"linh.ngotran@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/215mmgea6kss3jxeqsqdquvji"},"followers":{"href":null,"total":1},"href":"https://api.spotify.com/v1/users/215mmgea6kss3jxeqsqdquvji","id":"215mmgea6kss3jxeqsqdquvji","images":[],"product":"premium","type":"user","uri":"spotify:user:215mmgea6kss3jxeqsqdquvji"} Feb 18 23:37:54 volumio volumio[8041]: info: Spotify Successfully logged in Feb 18 23:37:54 volumio volumio[8041]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 23:37:54 volumio volumio[8041]: info: [1771432674624] CoreMusicLibrary::Adding element Spotify Feb 18 23:37:54 volumio volumio[8041]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 23:37:54 volumio volumio[8041]: Cannot find translation for source YouTube Music Feb 18 23:37:54 volumio volumio[8041]: Cannot find translation for source Spotify Feb 18 23:37:55 volumio volumio[8041]: info: [yt-cast-receiver] DIAL server listening on port 8098 Feb 18 23:37:55 volumio volumio[8041]: info: CoreCommandRouter::volumioRetrievevolume Feb 18 23:37:55 volumio volumio[8041]: info: VolumeController:: Volume=100 Mute =false Feb 18 23:37:55 volumio volumio[8041]: info: CoreCommandRouter::volumioGetState Feb 18 23:37:55 volumio volumio[8041]: info: CorePlayQueue::getTrack 0 Feb 18 23:37:55 volumio volumio[8041]: info: CoreStateMachine::pushState Feb 18 23:37:55 volumio volumio[8041]: info: CorePlayQueue::getTrack 0 Feb 18 23:37:55 volumio volumio[8041]: info: CoreCommandRouter::volumioPushState Feb 18 23:37:56 volumio volumio[8041]: info: go-librespot daemon successfully initialized Feb 18 23:37:57 volumio mpd[8265]: 2026-02-18T23:37:57 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 18 23:37:57 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 12. Feb 18 23:37:57 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 18 23:37:57 volumio sudo[8224]: pam_unix(sudo:session): session closed for user root Feb 18 23:37:57 volumio sudo[8236]: pam_unix(sudo:session): session closed for user root Feb 18 23:37:57 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 23:37:57 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 23:37:57 volumio go-librespot[8356]: go-librespot daemon starting... Feb 18 23:37:57 volumio go-librespot[8358]: time="2026-02-18T23:37:57+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 23:37:57 volumio go-librespot[8358]: time="2026-02-18T23:37:57+07:00" level=debug msg="app state loaded" Feb 18 23:37:57 volumio go-librespot[8358]: time="2026-02-18T23:37:57+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 23:37:57 volumio volumio[8041]: error: MPD error: The expression evaluated to a falsy value: Feb 18 23:37:57 volumio volumio[8041]: assert.ok(self.idling) Feb 18 23:37:57 volumio volumio[8041]: error: The expression evaluated to a falsy value: Feb 18 23:37:57 volumio volumio[8041]: assert.ok(self.idling) Feb 18 23:37:57 volumio volumio[8041]: error: updateQueue error: null Feb 18 23:37:57 volumio volumio[8041]: info: MPD running with PID8265 Feb 18 23:37:57 volumio volumio[8041]: ,establishing connection Feb 18 23:37:57 volumio volumio[8041]: info: Completed starting Core Plugins Feb 18 23:37:57 volumio volumio[8041]: info: ------------------------------------------- Feb 18 23:37:57 volumio volumio[8041]: info: ----- MyVolumio plugins startup ---- Feb 18 23:37:57 volumio volumio[8041]: info: ------------------------------------------- Feb 18 23:37:57 volumio volumio[8041]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 18 23:37:57 volumio volumio[8041]: error: updateQueue error: null Feb 18 23:37:57 volumio go-librespot[8358]: time="2026-02-18T23:37:57+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 23:37:57 volumio go-librespot[8358]: time="2026-02-18T23:37:57+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 18 23:37:57 volumio go-librespot[8358]: time="2026-02-18T23:37:57+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 18 23:37:57 volumio go-librespot[8358]: time="2026-02-18T23:37:57+07:00" level=info msg="zeroconf server listening on port 33739" Feb 18 23:37:57 volumio go-librespot[8358]: time="2026-02-18T23:37:57+07:00" level=debug msg="obtained new client token: AACT+/xTnqQ6fGJ/55A3VULeygI51JatYjWWGTWgSXbnx10ylLnj3GQ+5+s4LSB7f/hocrbB7yfx/EDXk/+OK6LineD0AI5ZuM0u+5lfvWDEqOMJV0xcctowMHtP7XGGyIGGku3UAo3RTXMoNw29eDjZE0/nWDULTCnZmX4XjyhdV64s8iyuzHIpykpsPqe9Vppu1L+t7a4VA3aX3dBRIu/fDE/uPPezoQg8zqzxF8R3fiNbk5PWOAWZdQ==" Feb 18 23:37:58 volumio go-librespot[8358]: time="2026-02-18T23:37:58+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 23:37:58 volumio go-librespot[8358]: time="2026-02-18T23:37:58+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 18 23:37:58 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 23:37:58 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 23:37:59 volumio volumio[8041]: info: Initializing connection to go-librespot Websocket Feb 18 23:37:59 volumio volumio[8041]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 18 23:38:01 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 13. Feb 18 23:38:01 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 23:38:01 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 23:38:01 volumio go-librespot[8366]: go-librespot daemon starting... Feb 18 23:38:01 volumio go-librespot[8367]: time="2026-02-18T23:38:01+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 23:38:01 volumio go-librespot[8367]: time="2026-02-18T23:38:01+07:00" level=debug msg="app state loaded" Feb 18 23:38:01 volumio go-librespot[8367]: time="2026-02-18T23:38:01+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 23:38:01 volumio go-librespot[8367]: time="2026-02-18T23:38:01+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 23:38:01 volumio go-librespot[8367]: time="2026-02-18T23:38:01+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 18 23:38:01 volumio go-librespot[8367]: time="2026-02-18T23:38:01+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 18 23:38:01 volumio go-librespot[8367]: time="2026-02-18T23:38:01+07:00" level=info msg="zeroconf server listening on port 36497" Feb 18 23:38:02 volumio volumio[8041]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 18 23:38:02 volumio go-librespot[8367]: time="2026-02-18T23:38:02+07:00" level=debug msg="obtained new client token: AABUfLfWofL4rFLJ/ZpnnDOw5H5UG8hXgZZjO9a7US/NZovRu6w6Cf9oysISACkiTZfy0jxY4Nfl/ptygU71pqwEgTTIrTkg5n67S5L736qG7ivYgayVWs14IbuJCpCin8GxcqDbiVL2q9aEtL4lEVndhEECZwdXmtgDkKceDQ5EKmosL/HqQI0tXITKjWnCRChxFKiZigHgyP5xVhDTVCqeHH6zYHqjGea1/FcGNv2XvuD6Vi35Gx8=" Feb 18 23:38:02 volumio go-librespot[8367]: time="2026-02-18T23:38:02+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 23:38:02 volumio go-librespot[8367]: time="2026-02-18T23:38:02+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 18 23:38:02 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 23:38:02 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 23:38:02 volumio volumio[8041]: info: Initializing connection to go-librespot Websocket Feb 18 23:38:02 volumio volumio[8041]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 18 23:38:05 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 14. Feb 18 23:38:05 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 23:38:05 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 23:38:05 volumio go-librespot[8375]: go-librespot daemon starting... Feb 18 23:38:05 volumio go-librespot[8376]: time="2026-02-18T23:38:05+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 23:38:05 volumio go-librespot[8376]: time="2026-02-18T23:38:05+07:00" level=debug msg="app state loaded" Feb 18 23:38:05 volumio go-librespot[8376]: time="2026-02-18T23:38:05+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 23:38:05 volumio volumio[8041]: info: Initializing connection to go-librespot Websocket Feb 18 23:38:05 volumio go-librespot[8376]: time="2026-02-18T23:38:05+07:00" level=debug msg="new websocket client" Feb 18 23:38:05 volumio volumio[8041]: info: Connection to go-librespot Websocket established Feb 18 23:38:06 volumio volumio[8041]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 18 23:38:06 volumio volumio[8041]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 18 23:38:06 volumio volumio[8041]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 18 23:38:06 volumio volumio[8041]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 18 23:38:06 volumio volumio[8041]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 18 23:38:06 volumio volumio[8041]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 18 23:38:06 volumio volumio[8041]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 18 23:38:06 volumio volumio[8041]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 18 23:38:06 volumio volumio[8041]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 18 23:38:06 volumio volumio[8041]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 18 23:38:06 volumio volumio[8041]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 18 23:38:06 volumio volumio[8041]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 18 23:38:06 volumio volumio[8041]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 18 23:38:06 volumio volumio[8041]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 18 23:38:06 volumio volumio[8041]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 18 23:38:06 volumio volumio[8041]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 18 23:38:06 volumio volumio[8041]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 18 23:38:06 volumio volumio[8041]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 18 23:38:06 volumio volumio[8041]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 18 23:38:06 volumio volumio[8041]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 18 23:38:06 volumio volumio[8041]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 18 23:38:06 volumio volumio[8041]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 18 23:38:06 volumio volumio[8041]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 18 23:38:06 volumio volumio[8041]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 18 23:38:06 volumio volumio[8041]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 18 23:38:06 volumio volumio[8041]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 18 23:38:06 volumio volumio[8041]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 18 23:38:06 volumio volumio[8041]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 18 23:38:06 volumio volumio[8041]: info: Adding plugin bluetooth to MyMusic Plugins Feb 18 23:38:06 volumio volumio[8041]: info: Adding plugin multiroom to MyMusic Plugins Feb 18 23:38:06 volumio volumio[8041]: info: Adding plugin metavolumio to MyMusic Plugins Feb 18 23:38:06 volumio volumio[8041]: info: Adding plugin cd_controller to MyMusic Plugins Feb 18 23:38:06 volumio volumio[8041]: info: Adding plugin qobuzconnect to MyMusic Plugins Feb 18 23:38:06 volumio volumio[8041]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 18 23:38:06 volumio volumio[8041]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 18 23:38:06 volumio volumio[8041]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 18 23:38:06 volumio go-librespot[8376]: time="2026-02-18T23:38:06+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 23:38:06 volumio go-librespot[8376]: time="2026-02-18T23:38:06+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 18 23:38:06 volumio go-librespot[8376]: time="2026-02-18T23:38:06+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 18 23:38:06 volumio go-librespot[8376]: time="2026-02-18T23:38:06+07:00" level=info msg="zeroconf server listening on port 34849" Feb 18 23:38:06 volumio go-librespot[8376]: time="2026-02-18T23:38:06+07:00" level=debug msg="obtained new client token: AAB07lVaRqEDA3BOdR+0LplrnpcjYp9sVRHJAcHME/uGicK3arzCaY6pY9mUWwCI5whG2sZhaKMBE8bCry02L47y1an0KuwXWPwfuahO0Lh8G32M1XYxF+S1VfnE1pjps/wfGk29P8i83/n6QpEDwL6i+FYKJhMDCycTZObYUn1XPPSVHvYlqUNB+qNqLuvTkbvShApzh1wnDZViclo9z+nJq7xd8q75JDbtavG6iiyCGbY3InKcwL969A==" Feb 18 23:38:06 volumio go-librespot[8376]: time="2026-02-18T23:38:06+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 23:38:06 volumio go-librespot[8376]: time="2026-02-18T23:38:06+07:00" level=debug msg="completed keyexchange" Feb 18 23:38:06 volumio go-librespot[8376]: time="2026-02-18T23:38:06+07:00" level=debug msg="completed challenge" Feb 18 23:38:06 volumio go-librespot[8376]: time="2026-02-18T23:38:06+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 18 23:38:06 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 23:38:06 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 23:38:07 volumio volumio[8041]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 18 23:38:07 volumio volumio[8041]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 18 23:38:07 volumio volumio[8041]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 23:38:07 volumio volumio[8041]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 23:38:07 volumio volumio[8041]: info: Starting MyVolumio Remote Streaming Endpoints Feb 18 23:38:08 volumio volumio[8041]: info: MyVolumio login type: Token Feb 18 23:38:08 volumio volumio[8041]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 18 23:38:08 volumio volumio[8041]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 18 23:38:09 volumio volumio[8041]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 18 23:38:09 volumio volumio[8041]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 18 23:38:09 volumio volumio[8041]: info: Streaming services startup Feb 18 23:38:09 volumio volumio[8041]: info: Starting Streaming Daemon Feb 18 23:38:09 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 15. Feb 18 23:38:09 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 23:38:09 volumio sudo[8399]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 18 23:38:09 volumio volumio[8041]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 18 23:38:09 volumio sudo[8399]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 23:38:09 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 23:38:09 volumio go-librespot[8404]: go-librespot daemon starting... Feb 18 23:38:09 volumio sudo[8399]: pam_unix(sudo:session): session closed for user root Feb 18 23:38:09 volumio go-librespot[8406]: time="2026-02-18T23:38:09+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 23:38:09 volumio go-librespot[8406]: time="2026-02-18T23:38:09+07:00" level=debug msg="app state loaded" Feb 18 23:38:09 volumio go-librespot[8406]: time="2026-02-18T23:38:09+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 23:38:09 volumio volumio[8041]: info: Getting Spotify volume Feb 18 23:38:10 volumio volumio[8041]: info: Connection to go-librespot Websocket closed Feb 18 23:38:10 volumio volumio[8041]: error: Cannot start Volumio Streaming Daemon Feb 18 23:38:10 volumio volumio[8041]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 18 23:38:10 volumio volumio[8041]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 18 23:38:10 volumio volumio[8041]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Feb 18 23:38:10 volumio volumio[8041]: info: CoreCommandRouter::volumioGetState Feb 18 23:38:10 volumio volumio[8041]: info: CorePlayQueue::getTrack 0 Feb 18 23:38:10 volumio volumio[8041]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Feb 18 23:38:10 volumio volumio[8041]: SPOTIFY: SPOTIFY VOLUME undefined Feb 18 23:38:10 volumio volumio[8041]: SPOTIFY: VOLUMIO VOLUME 100 Feb 18 23:38:10 volumio volumio[8041]: info: Aligning Spotify Volume to Volumio Volume Feb 18 23:38:10 volumio volumio[8041]: info: CoreCommandRouter::volumioGetState Feb 18 23:38:10 volumio volumio[8041]: info: CorePlayQueue::getTrack 0 Feb 18 23:38:10 volumio volumio[8041]: info: Setting Spotify Volume from Volumio: 100 Feb 18 23:38:10 volumio go-librespot[8406]: time="2026-02-18T23:38:10+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 23:38:10 volumio go-librespot[8406]: time="2026-02-18T23:38:10+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 18 23:38:10 volumio go-librespot[8406]: time="2026-02-18T23:38:10+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 18 23:38:10 volumio go-librespot[8406]: time="2026-02-18T23:38:10+07:00" level=info msg="zeroconf server listening on port 44823" Feb 18 23:38:10 volumio go-librespot[8406]: time="2026-02-18T23:38:10+07:00" level=debug msg="obtained new client token: AACoVpWjEocdawxkBVKAn0eOwnxFH0ALIk3Mi9rSCM4FF2X7f3SdrGEWmzBubPa1St6WWwR7VImkVSmJgy2qjWDqejPbbDDeYowfK1JYLj8N/8q5ntcxvQbkh6UXq9xmSE+beY5Y+Xe3th9ccz1lqj1ooddl0uOClPbVFHKxy0O2O2r05h02IjJtPH746KNCMDXNHG74+D1AGNamBRm1F5OsCx7cPPoMjUxiOYHex/GINJnPP/HQeCIoCA==" Feb 18 23:38:10 volumio go-librespot[8406]: time="2026-02-18T23:38:10+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 23:38:10 volumio go-librespot[8406]: time="2026-02-18T23:38:10+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 18 23:38:10 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 23:38:10 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 23:38:10 volumio volumio[8041]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 18 23:38:10 volumio volumio[8041]: Error: socket hang up Feb 18 23:38:10 volumio volumio[8041]: at connResetException (node:internal/errors:720:14) Feb 18 23:38:10 volumio volumio[8041]: at Socket.socketOnEnd (node:_http_client:519:23) Feb 18 23:38:10 volumio volumio[8041]: at Socket.emit (node:events:526:35) Feb 18 23:38:10 volumio volumio[8041]: at endReadableNT (node:internal/streams/readable:1376:12) Feb 18 23:38:10 volumio volumio[8041]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Feb 18 23:38:10 volumio volumio[8041]: code: 'ECONNRESET', Feb 18 23:38:10 volumio volumio[8041]: response: undefined Feb 18 23:38:10 volumio volumio[8041]: } Feb 18 23:38:10 volumio volumio[8041]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 18 23:38:12 volumio sudo[8427]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-18 23:37' Feb 18 23:38:12 volumio sudo[8427]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) PRETTY_NAME="Raspbian GNU/Linux 12 (bookworm)" NAME="Raspbian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="b05a530ca81d05eb9a84d0acf82089f0a60b8ee6" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="4ad85e2147d972f0b838d33c21382d2d813b2ae8" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu Dec 25 09:13:19 UTC 2025" VOLUMIO_VERSION="4.084" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="792f09af7488531aecd1aadcaa9b175e"