Feb 18 23:42:00 volumio go-librespot[10525]: time="2026-02-18T23:42:00+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:42:00 volumio go-librespot[10525]: time="2026-02-18T23:42:00+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:42:00 volumio go-librespot[10525]: time="2026-02-18T23:42:00+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:42:00 volumio go-librespot[10525]: time="2026-02-18T23:42:00+07:00" level=info msg="zeroconf server listening on port 39059" Feb 18 23:42:00 volumio go-librespot[10525]: time="2026-02-18T23:42:00+07:00" level=debug msg="obtained new client token: AADFEhHrwFEeUd9BRuwExobr2vPXSpY+pTWrurmO01T5lCicgaZ/MEDH5HHXjSQhc/YegHQqGtUU99Xm+2YRQr8kItibGoij+bjUBgRzDPiytQl00mQX4943Klc/WP3Krmo4HBFi9DMzWvolv5xRYe7vHS143a7YK/fnlkr3YIndkNSFOMJCSjROAhaGTpRrgc4QxmoW6vAKxxIf7FO4nJjCeTkzfDjAyGD5N0ZSiLJX1ELYfrA/tMLuRw==" Feb 18 23:42:00 volumio go-librespot[10525]: time="2026-02-18T23:42:00+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 23:42:00 volumio go-librespot[10525]: time="2026-02-18T23:42:00+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 18 23:42:00 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 23:42:00 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 23:42:00 volumio volumio[10280]: info: Starting Shairport Sync Feb 18 23:42:00 volumio volumio[10280]: info: Starting Shairport Sync Feb 18 23:42:01 volumio volumio[10280]: info: Starting Shairport Sync Feb 18 23:42:01 volumio sudo[10556]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 18 23:42:01 volumio sudo[10556]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 23:42:01 volumio sudo[10558]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 18 23:42:01 volumio sudo[10558]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 23:42:01 volumio sudo[10560]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 18 23:42:01 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 18 23:42:01 volumio sudo[10560]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 23:42:01 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 18 23:42:01 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 18 23:42:01 volumio systemd[1]: shairport-sync.service: Consumed 2.377s CPU time. Feb 18 23:42:01 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 18 23:42:01 volumio sudo[10556]: pam_unix(sudo:session): session closed for user root Feb 18 23:42:01 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 18 23:42:01 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 18 23:42:01 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 18 23:42:01 volumio volumio[10280]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 18 23:42:01 volumio volumio[10280]: SPOTIFY: BQBSeXpxXtRQOZkUBWstJzcpCQiQ2sb_zkfNGbgrI4vNEtJ5FFHJEYpa8aOuaxJKIethnBduDkcQNhlkadIRuN6UvidzZwAV3nSoY2WZSLK1he7pngH3QwU4qHWNwOD-O1dpXNMNW5pDT90x89ZF2UaM8FCv2jfUz4IsYQ0ED_SD1Db4OojQeFfHxH1FzP37JFLaf29J150UFpXiEzC9fIJj0CXgDt3kLy87TkbM3g8nWRULqUF1qqDFMFvz6yRGZeSkT9f6i7w63Af-3rANsMBKleElA8hEDPiRRkBK-4jHRxnECly-nY-6 Feb 18 23:42:01 volumio volumio[10280]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 18 23:42:01 volumio volumio[10280]: info: New Spotify access token = BQBSeXpxXtRQOZkUBWstJzcpCQiQ2sb_zkfNGbgrI4vNEtJ5FFHJEYpa8aOuaxJKIethnBduDkcQNhlkadIRuN6UvidzZwAV3nSoY2WZSLK1he7pngH3QwU4qHWNwOD-O1dpXNMNW5pDT90x89ZF2UaM8FCv2jfUz4IsYQ0ED_SD1Db4OojQeFfHxH1FzP37JFLaf29J150UFpXiEzC9fIJj0CXgDt3kLy87TkbM3g8nWRULqUF1qqDFMFvz6yRGZeSkT9f6i7w63Af-3rANsMBKleElA8hEDPiRRkBK-4jHRxnECly-nY-6 Feb 18 23:42:01 volumio volumio[10280]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 18 23:42:01 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 18 23:42:01 volumio volumio[10280]: info: CoreCommandRouter::volumioGetState Feb 18 23:42:01 volumio volumio[10280]: info: CorePlayQueue::getTrack 0 Feb 18 23:42:01 volumio volumio[10280]: info: Shairport-Sync Started Feb 18 23:42:01 volumio sudo[10560]: pam_unix(sudo:session): session closed for user root Feb 18 23:42:01 volumio volumio[10280]: Error adding Membership: Error: addMembership EINVAL Feb 18 23:42:01 volumio sudo[10558]: pam_unix(sudo:session): session closed for user root Feb 18 23:42:01 volumio volumio[10280]: info: Shairport-Sync Started Feb 18 23:42:01 volumio volumio[10280]: info: Shairport-Sync Started Feb 18 23:42:01 volumio volumio[10280]: 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:42:01 volumio volumio[10280]: info: Spotify Successfully logged in Feb 18 23:42:01 volumio volumio[10280]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 23:42:01 volumio volumio[10280]: info: [1771432921910] CoreMusicLibrary::Adding element Spotify Feb 18 23:42:01 volumio volumio[10280]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 23:42:01 volumio volumio[10280]: Cannot find translation for source YouTube Music Feb 18 23:42:01 volumio volumio[10280]: Cannot find translation for source Spotify Feb 18 23:42:02 volumio volumio[10280]: info: [yt-cast-receiver] DIAL server listening on port 8098 Feb 18 23:42:02 volumio volumio[10280]: info: CoreCommandRouter::volumioRetrievevolume Feb 18 23:42:02 volumio volumio[10280]: info: VolumeController:: Volume=100 Mute =false Feb 18 23:42:02 volumio volumio[10280]: info: CoreCommandRouter::volumioGetState Feb 18 23:42:02 volumio volumio[10280]: info: CorePlayQueue::getTrack 0 Feb 18 23:42:02 volumio volumio[10280]: info: CoreStateMachine::pushState Feb 18 23:42:02 volumio volumio[10280]: info: CorePlayQueue::getTrack 0 Feb 18 23:42:02 volumio volumio[10280]: info: CoreCommandRouter::volumioPushState Feb 18 23:42:03 volumio volumio[10280]: info: go-librespot daemon successfully initialized Feb 18 23:42:04 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Feb 18 23:42:04 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 23:42:04 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 23:42:04 volumio go-librespot[10613]: go-librespot daemon starting... Feb 18 23:42:04 volumio go-librespot[10614]: time="2026-02-18T23:42:04+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 23:42:04 volumio go-librespot[10614]: time="2026-02-18T23:42:04+07:00" level=debug msg="app state loaded" Feb 18 23:42:04 volumio go-librespot[10614]: time="2026-02-18T23:42:04+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 23:42:04 volumio mpd[10500]: 2026-02-18T23:42:04 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 18 23:42:04 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 18 23:42:04 volumio sudo[10460]: pam_unix(sudo:session): session closed for user root Feb 18 23:42:04 volumio sudo[10471]: pam_unix(sudo:session): session closed for user root Feb 18 23:42:04 volumio volumio[10280]: error: MPD error: The expression evaluated to a falsy value: Feb 18 23:42:04 volumio volumio[10280]: assert.ok(self.idling) Feb 18 23:42:04 volumio volumio[10280]: error: The expression evaluated to a falsy value: Feb 18 23:42:04 volumio volumio[10280]: assert.ok(self.idling) Feb 18 23:42:04 volumio volumio[10280]: info: MPD running with PID10500 Feb 18 23:42:04 volumio volumio[10280]: ,establishing connection Feb 18 23:42:04 volumio volumio[10280]: error: updateQueue error: null Feb 18 23:42:04 volumio volumio[10280]: info: Completed starting Core Plugins Feb 18 23:42:04 volumio volumio[10280]: info: ------------------------------------------- Feb 18 23:42:04 volumio volumio[10280]: info: ----- MyVolumio plugins startup ---- Feb 18 23:42:04 volumio volumio[10280]: info: ------------------------------------------- Feb 18 23:42:04 volumio volumio[10280]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 18 23:42:04 volumio volumio[10280]: error: updateQueue error: null Feb 18 23:42:04 volumio go-librespot[10614]: time="2026-02-18T23:42:04+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 23:42:04 volumio go-librespot[10614]: time="2026-02-18T23:42:04+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 18 23:42:04 volumio go-librespot[10614]: time="2026-02-18T23:42:04+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 18 23:42:04 volumio go-librespot[10614]: time="2026-02-18T23:42:04+07:00" level=info msg="zeroconf server listening on port 41599" Feb 18 23:42:04 volumio go-librespot[10614]: time="2026-02-18T23:42:04+07:00" level=debug msg="obtained new client token: AAC3j3ztC92ZxayoowZdE/kh0wDLWoK829rXkckBrVPl+8gIHqnELWiCaFg/C33R2sBc55qAUGqKx3hDzKs5NwDcKDzyQOsTTWRjXn4NFU0fMSb47oQ1NiaQi8ZZRm16h9o5332AAGXRsKRReiIfaEQZ5Du6L+/Wy7dtNkGoUJF9Du7oQo8kLtapY3e1ITICCxOsHKPL6SCWX7K6wRGjZCGrjYCUJhFZCjmymXCogp5Hvllu6KZH2946PQ==" Feb 18 23:42:05 volumio go-librespot[10614]: time="2026-02-18T23:42:05+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 23:42:05 volumio go-librespot[10614]: time="2026-02-18T23:42:05+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:42:05 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 23:42:05 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 23:42:06 volumio volumio[10280]: info: Initializing connection to go-librespot Websocket Feb 18 23:42:06 volumio volumio[10280]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 18 23:42:08 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Feb 18 23:42:08 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 23:42:08 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 23:42:08 volumio go-librespot[10625]: go-librespot daemon starting... Feb 18 23:42:08 volumio go-librespot[10626]: time="2026-02-18T23:42:08+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 23:42:08 volumio go-librespot[10626]: time="2026-02-18T23:42:08+07:00" level=debug msg="app state loaded" Feb 18 23:42:08 volumio go-librespot[10626]: time="2026-02-18T23:42:08+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 23:42:08 volumio go-librespot[10626]: time="2026-02-18T23:42:08+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 23:42:08 volumio go-librespot[10626]: time="2026-02-18T23:42:08+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:42:08 volumio go-librespot[10626]: time="2026-02-18T23:42:08+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:42:08 volumio go-librespot[10626]: time="2026-02-18T23:42:08+07:00" level=info msg="zeroconf server listening on port 46041" Feb 18 23:42:09 volumio go-librespot[10626]: time="2026-02-18T23:42:09+07:00" level=debug msg="obtained new client token: AACLQb3FjORKgwU4A3rzf/1T+rKldVBb01LQ0lY6xLIDuddoMfIaPkcucfZl862gEzJ+YdaYkZOUaBjEwj3EUKH7lxNpkpW0ITARC1c2nkLEzgiAsyJtWTOIBogBa1RzHuogzqFWMFH1euhEifkMjldtum70/PLuC24VvHDD8kyjIad4SIdFlW45vv/U/kKnBLlT4CYv+1iy96r3cWCCpzDBmBICBEvFZpeclnEunTh+BSglO/FsejU=" Feb 18 23:42:09 volumio go-librespot[10626]: time="2026-02-18T23:42:09+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:42:09 volumio volumio[10280]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 18 23:42:09 volumio go-librespot[10626]: time="2026-02-18T23:42:09+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Feb 18 23:42:09 volumio go-librespot[10626]: time="2026-02-18T23:42:09+07:00" level=debug msg="completed keyexchange" Feb 18 23:42:09 volumio go-librespot[10626]: time="2026-02-18T23:42:09+07:00" level=debug msg="completed challenge" Feb 18 23:42:09 volumio go-librespot[10626]: time="2026-02-18T23:42:09+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:42:09 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 23:42:09 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 23:42:09 volumio volumio[10280]: info: Initializing connection to go-librespot Websocket Feb 18 23:42:09 volumio volumio[10280]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 18 23:42:12 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Feb 18 23:42:12 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 23:42:12 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 23:42:12 volumio go-librespot[10633]: go-librespot daemon starting... Feb 18 23:42:12 volumio go-librespot[10634]: time="2026-02-18T23:42:12+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 23:42:12 volumio go-librespot[10634]: time="2026-02-18T23:42:12+07:00" level=debug msg="app state loaded" Feb 18 23:42:12 volumio go-librespot[10634]: time="2026-02-18T23:42:12+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 23:42:12 volumio volumio[10280]: info: Initializing connection to go-librespot Websocket Feb 18 23:42:12 volumio go-librespot[10634]: time="2026-02-18T23:42:12+07:00" level=debug msg="new websocket client" Feb 18 23:42:12 volumio volumio[10280]: info: Connection to go-librespot Websocket established Feb 18 23:42:13 volumio go-librespot[10634]: time="2026-02-18T23:42:13+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 18 23:42:13 volumio go-librespot[10634]: time="2026-02-18T23:42:13+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 18 23:42:13 volumio go-librespot[10634]: time="2026-02-18T23:42:13+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 18 23:42:13 volumio go-librespot[10634]: time="2026-02-18T23:42:13+07:00" level=info msg="zeroconf server listening on port 35131" Feb 18 23:42:13 volumio go-librespot[10634]: time="2026-02-18T23:42:13+07:00" level=debug msg="obtained new client token: AAAqqyP3VV5aPVf9O0sOztE6Ix3sbT+5Jg9Rgjc419rtvJQGEhsbkkTb64M2aBMvqTNWVyNVnU0sfLVs0FDFfCSxxlBKw67YyCzyRqOd+j5FbUepFPwWhqGscvFkUWXtxV0iLi4O6ZT7AWjsBPGiJQa6uRctmr4YW1x2n41VdrDIWCurX4CvMLsZIEE6WHu+BBiZlbT8Uo6MlOrizWLymxRpvTAJu08ntnn8BuezhtEQdAbBWlRT/kqYhQ==" Feb 18 23:42:13 volumio volumio[10280]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 18 23:42:13 volumio volumio[10280]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 18 23:42:13 volumio volumio[10280]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 18 23:42:13 volumio volumio[10280]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 18 23:42:13 volumio volumio[10280]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 18 23:42:13 volumio volumio[10280]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 18 23:42:13 volumio volumio[10280]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 18 23:42:13 volumio volumio[10280]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 18 23:42:13 volumio volumio[10280]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 18 23:42:13 volumio volumio[10280]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 18 23:42:13 volumio volumio[10280]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 18 23:42:13 volumio volumio[10280]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 18 23:42:13 volumio volumio[10280]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 18 23:42:13 volumio volumio[10280]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 18 23:42:13 volumio volumio[10280]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 18 23:42:13 volumio volumio[10280]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 18 23:42:13 volumio volumio[10280]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 18 23:42:13 volumio volumio[10280]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 18 23:42:13 volumio volumio[10280]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 18 23:42:13 volumio volumio[10280]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 18 23:42:13 volumio volumio[10280]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 18 23:42:13 volumio volumio[10280]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 18 23:42:13 volumio volumio[10280]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 18 23:42:13 volumio volumio[10280]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 18 23:42:13 volumio volumio[10280]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 18 23:42:13 volumio volumio[10280]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 18 23:42:13 volumio volumio[10280]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 18 23:42:13 volumio volumio[10280]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 18 23:42:13 volumio volumio[10280]: info: Adding plugin bluetooth to MyMusic Plugins Feb 18 23:42:13 volumio volumio[10280]: info: Adding plugin multiroom to MyMusic Plugins Feb 18 23:42:13 volumio volumio[10280]: info: Adding plugin metavolumio to MyMusic Plugins Feb 18 23:42:13 volumio volumio[10280]: info: Adding plugin cd_controller to MyMusic Plugins Feb 18 23:42:13 volumio volumio[10280]: info: Adding plugin qobuzconnect to MyMusic Plugins Feb 18 23:42:13 volumio volumio[10280]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 18 23:42:13 volumio volumio[10280]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 18 23:42:13 volumio go-librespot[10634]: time="2026-02-18T23:42:13+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 23:42:13 volumio volumio[10280]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 18 23:42:13 volumio go-librespot[10634]: time="2026-02-18T23:42:13+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:42:13 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 23:42:13 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 23:42:15 volumio volumio[10280]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 18 23:42:15 volumio volumio[10280]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 18 23:42:15 volumio volumio[10280]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 23:42:15 volumio volumio[10280]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 23:42:15 volumio volumio[10280]: info: Starting MyVolumio Remote Streaming Endpoints Feb 18 23:42:15 volumio volumio[10280]: info: MyVolumio login type: Token Feb 18 23:42:15 volumio volumio[10280]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 18 23:42:15 volumio volumio[10280]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 18 23:42:16 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Feb 18 23:42:16 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 23:42:16 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 23:42:16 volumio go-librespot[10655]: go-librespot daemon starting... Feb 18 23:42:16 volumio go-librespot[10656]: time="2026-02-18T23:42:16+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 23:42:16 volumio go-librespot[10656]: time="2026-02-18T23:42:16+07:00" level=debug msg="app state loaded" Feb 18 23:42:16 volumio go-librespot[10656]: time="2026-02-18T23:42:16+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 23:42:17 volumio volumio[10280]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 18 23:42:17 volumio volumio[10280]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 18 23:42:17 volumio volumio[10280]: info: Streaming services startup Feb 18 23:42:17 volumio volumio[10280]: info: Starting Streaming Daemon Feb 18 23:42:17 volumio sudo[10664]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 18 23:42:17 volumio sudo[10664]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 23:42:17 volumio volumio[10280]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 18 23:42:17 volumio sudo[10664]: pam_unix(sudo:session): session closed for user root Feb 18 23:42:17 volumio volumio[10280]: info: Getting Spotify volume Feb 18 23:42:17 volumio volumio[10280]: info: Connection to go-librespot Websocket closed Feb 18 23:42:17 volumio volumio[10280]: error: Cannot start Volumio Streaming Daemon Feb 18 23:42:17 volumio volumio[10280]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 18 23:42:17 volumio volumio[10280]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 18 23:42:17 volumio go-librespot[10656]: time="2026-02-18T23:42:17+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:42:17 volumio go-librespot[10656]: time="2026-02-18T23:42:17+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:42:17 volumio go-librespot[10656]: time="2026-02-18T23:42:17+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:42:17 volumio volumio[10280]: 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:42:17 volumio go-librespot[10656]: time="2026-02-18T23:42:17+07:00" level=info msg="zeroconf server listening on port 34167" Feb 18 23:42:17 volumio volumio[10280]: info: CoreCommandRouter::volumioGetState Feb 18 23:42:17 volumio volumio[10280]: info: CorePlayQueue::getTrack 0 Feb 18 23:42:17 volumio volumio[10280]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Feb 18 23:42:17 volumio volumio[10280]: SPOTIFY: SPOTIFY VOLUME undefined Feb 18 23:42:17 volumio volumio[10280]: SPOTIFY: VOLUMIO VOLUME 100 Feb 18 23:42:17 volumio volumio[10280]: info: Aligning Spotify Volume to Volumio Volume Feb 18 23:42:17 volumio volumio[10280]: info: CoreCommandRouter::volumioGetState Feb 18 23:42:17 volumio volumio[10280]: info: CorePlayQueue::getTrack 0 Feb 18 23:42:17 volumio volumio[10280]: info: Setting Spotify Volume from Volumio: 100 Feb 18 23:42:17 volumio go-librespot[10656]: time="2026-02-18T23:42:17+07:00" level=debug msg="obtained new client token: AAD8UZiMdMDPjLY4f2PneAsu4wa00XLZSmuulozvKFRmcxl72hIVf4TnHWvfeknK+N1xyGm1I7OphIjgSPfThQJf0yWYk1CQtcWnrgN+gEvwCVHQy30ElewGE1eQsN4F1wLklZ7dRhHW8MvDnFs0YUK9uU1mVDuoSekxxx5UX7jX35Fauiqrp6dg+F3SeIzT9pJxsc4y9YezezzRQIZV+kju+UsE7BOtVUKRsqH1O0VPfyxLm8DHvf8YhA==" Feb 18 23:42:17 volumio go-librespot[10656]: time="2026-02-18T23:42:17+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 23:42:18 volumio go-librespot[10656]: time="2026-02-18T23:42:18+07:00" level=debug msg="completed keyexchange" Feb 18 23:42:18 volumio go-librespot[10656]: time="2026-02-18T23:42:18+07:00" level=debug msg="completed challenge" Feb 18 23:42:18 volumio go-librespot[10656]: time="2026-02-18T23:42:18+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 18 23:42:18 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 23:42:18 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 23:42:18 volumio volumio[10280]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 18 23:42:18 volumio volumio[10280]: Error: socket hang up Feb 18 23:42:18 volumio volumio[10280]: at connResetException (node:internal/errors:720:14) Feb 18 23:42:18 volumio volumio[10280]: at Socket.socketOnEnd (node:_http_client:519:23) Feb 18 23:42:18 volumio volumio[10280]: at Socket.emit (node:events:526:35) Feb 18 23:42:18 volumio volumio[10280]: at endReadableNT (node:internal/streams/readable:1376:12) Feb 18 23:42:18 volumio volumio[10280]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Feb 18 23:42:18 volumio volumio[10280]: code: 'ECONNRESET', Feb 18 23:42:18 volumio volumio[10280]: response: undefined Feb 18 23:42:18 volumio volumio[10280]: } Feb 18 23:42:18 volumio volumio[10280]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 18 23:42:19 volumio sudo[10686]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-18 23:41' Feb 18 23:42:19 volumio sudo[10686]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 23:42:19 volumio sudo[10686]: pam_unix(sudo:session): session closed for user root Feb 18 23:42:19 volumio volumio-remote-updater[25144]: [2026-02-18 23:42:19] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Feb 18 23:42:19 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Feb 18 23:42:20 volumio volumio-remote-updater[25144]: [2026-02-18 23:42:19] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Feb 18 23:42:20 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Feb 18 23:42:20 volumio systemd[1]: volumio.service: Consumed 56.072s CPU time. Feb 18 23:42:20 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 18 23:42:20 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 22609. Feb 18 23:42:20 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 18 23:42:20 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Feb 18 23:42:20 volumio systemd[1]: volumio.service: Consumed 56.072s CPU time. Feb 18 23:42:20 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Feb 18 23:42:21 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Feb 18 23:42:21 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 23:42:21 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 23:42:21 volumio go-librespot[10711]: go-librespot daemon starting... Feb 18 23:42:21 volumio go-librespot[10712]: time="2026-02-18T23:42:21+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 23:42:21 volumio go-librespot[10712]: time="2026-02-18T23:42:21+07:00" level=debug msg="app state loaded" Feb 18 23:42:21 volumio go-librespot[10712]: time="2026-02-18T23:42:21+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 23:42:21 volumio go-librespot[10712]: time="2026-02-18T23:42:21+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 18 23:42:21 volumio go-librespot[10712]: time="2026-02-18T23:42:21+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 18 23:42:21 volumio go-librespot[10712]: time="2026-02-18T23:42:21+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 18 23:42:21 volumio go-librespot[10712]: time="2026-02-18T23:42:21+07:00" level=info msg="zeroconf server listening on port 44129" Feb 18 23:42:22 volumio go-librespot[10712]: time="2026-02-18T23:42:22+07:00" level=debug msg="obtained new client token: AAAFIM27yiS0BnFmrAe4lVah/lJFHlN4sqqaIf+T07sR2BPNdQWFVL0kQuxJuOKYZIAwk3CYvegiObML0VWXbMQt4hjp29MOlkjnzwPFY7pMnUGq24BkqeMrUnGE+eVKWM0OMGA81UjlnHyk4nNh2Sib4AjqxS1S5MHAHIU7pCqtnpyBM00T5UoTlDFG6IrTbgJqWGI1271O+FMNChs1T62NZhEXaj02nIBwJi+M8IxadbYOoMQkMK8=" Feb 18 23:42:22 volumio go-librespot[10712]: time="2026-02-18T23:42:22+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:42:22 volumio go-librespot[10712]: time="2026-02-18T23:42:22+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Feb 18 23:42:22 volumio go-librespot[10712]: time="2026-02-18T23:42:22+07:00" level=debug msg="completed keyexchange" Feb 18 23:42:22 volumio go-librespot[10712]: time="2026-02-18T23:42:22+07:00" level=debug msg="completed challenge" Feb 18 23:42:22 volumio go-librespot[10712]: time="2026-02-18T23:42:22+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:42:22 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 23:42:22 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 23:42:23 volumio volumio[10701]: info: ------------------------------------------- Feb 18 23:42:23 volumio volumio[10701]: info: ----- Volumio3 ---- Feb 18 23:42:23 volumio volumio[10701]: info: ------------------------------------------- Feb 18 23:42:23 volumio volumio[10701]: info: ----- System startup ---- Feb 18 23:42:23 volumio volumio[10701]: info: ------------------------------------------- Feb 18 23:42:25 volumio volumio-remote-updater[25144]: [2026-02-18 23:42:24] [connect] Successful connection Feb 18 23:42:25 volumio volumio[10701]: info: MYVOLUMIO Environment detected Feb 18 23:42:25 volumio volumio[10701]: info: Plugin folders cleanup Feb 18 23:42:25 volumio volumio[10701]: info: Scanning into folder /volumio/app/plugins/ Feb 18 23:42:25 volumio volumio[10701]: info: Scanning category audio_interface Feb 18 23:42:25 volumio volumio[10701]: info: Scanning category miscellanea Feb 18 23:42:25 volumio volumio[10701]: info: Scanning category music_service Feb 18 23:42:25 volumio volumio[10701]: info: Scanning category plugins.json Feb 18 23:42:25 volumio volumio[10701]: info: Scanning category system_controller Feb 18 23:42:25 volumio volumio[10701]: info: Scanning category user_interface Feb 18 23:42:25 volumio volumio[10701]: info: Scanning into folder /data/plugins/ Feb 18 23:42:25 volumio volumio[10701]: info: Scanning category music_service Feb 18 23:42:25 volumio volumio[10701]: info: Plugin folders cleanup completed Feb 18 23:42:25 volumio volumio[10701]: info: ------------------------------------------- Feb 18 23:42:25 volumio volumio[10701]: info: ----- Core plugins startup ---- Feb 18 23:42:25 volumio volumio[10701]: info: ------------------------------------------- Feb 18 23:42:25 volumio volumio[10701]: info: Loading plugins from folder /volumio/app/plugins/ Feb 18 23:42:25 volumio volumio[10701]: info: Adding plugin upnp to MyMusic Plugins Feb 18 23:42:25 volumio volumio[10701]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 18 23:42:25 volumio volumio[10701]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 18 23:42:25 volumio volumio[10701]: info: Loading plugins from folder /data/plugins/ Feb 18 23:42:25 volumio volumio[10701]: info: Loading plugin "system"... Feb 18 23:42:25 volumio volumio[10701]: info: Loading plugin "appearance"... Feb 18 23:42:25 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Feb 18 23:42:25 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 23:42:25 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 23:42:25 volumio go-librespot[10731]: go-librespot daemon starting... Feb 18 23:42:25 volumio go-librespot[10732]: time="2026-02-18T23:42:25+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 23:42:25 volumio go-librespot[10732]: time="2026-02-18T23:42:25+07:00" level=debug msg="app state loaded" Feb 18 23:42:25 volumio go-librespot[10732]: time="2026-02-18T23:42:25+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 23:42:26 volumio go-librespot[10732]: time="2026-02-18T23:42:26+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 23:42:26 volumio go-librespot[10732]: time="2026-02-18T23:42:26+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 18 23:42:26 volumio go-librespot[10732]: time="2026-02-18T23:42:26+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 18 23:42:26 volumio go-librespot[10732]: time="2026-02-18T23:42:26+07:00" level=info msg="zeroconf server listening on port 34971" Feb 18 23:42:26 volumio go-librespot[10732]: time="2026-02-18T23:42:26+07:00" level=debug msg="obtained new client token: AAAY7wgoTK8L23Q4LKtJz25g4eBNt4kO+Wx84+QNMBHvdMjs3WwpMo/XMxfx5g8tZN+1YTgaFmVxLNJyC5HRI9QOsmk8N4s3Auud7MOGLo2697XSN+fbOiFnmZBOo3QMx1w3xYi77eAbO+iOZN1G/bUc1FIJ8R1iq0GhgnlF3BbcA1vSTusTXbrK5PCq71CcfJTZHV5ev9874bzhP5XNsxdTon6QU/CZsyPFP5AZJsrG3XzBv4oQy9mt1A==" Feb 18 23:42:26 volumio go-librespot[10732]: time="2026-02-18T23:42:26+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 23:42:26 volumio go-librespot[10732]: time="2026-02-18T23:42:26+07:00" level=debug msg="completed keyexchange" Feb 18 23:42:26 volumio go-librespot[10732]: time="2026-02-18T23:42:26+07:00" level=debug msg="completed challenge" Feb 18 23:42:26 volumio go-librespot[10732]: time="2026-02-18T23:42:26+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:42:26 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 23:42:26 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 23:42:27 volumio volumio[10701]: info: Loading plugin "network"... Feb 18 23:42:27 volumio volumio[10701]: info: Refreshing Cached IP Addresses Feb 18 23:42:27 volumio sudo[10741]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 18 23:42:27 volumio sudo[10741]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 23:42:27 volumio volumio[10701]: info: Loading plugin "services"... Feb 18 23:42:27 volumio sudo[10743]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 18 23:42:27 volumio sudo[10743]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 23:42:27 volumio volumio[10701]: info: Loading plugin "alsa_controller"... Feb 18 23:42:27 volumio sudo[10741]: pam_unix(sudo:session): session closed for user root Feb 18 23:42:27 volumio sudo[10743]: pam_unix(sudo:session): session closed for user root Feb 18 23:42:27 volumio sudo[10750]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 18 23:42:27 volumio sudo[10750]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 23:42:27 volumio volumio[10701]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 18 23:42:27 volumio volumio[10701]: info: Loading plugin "wizard"... Feb 18 23:42:27 volumio volumio[10701]: info: Loading plugin "networkfs"... Feb 18 23:42:27 volumio volumio[10701]: info: Starting Udev Watcher for removable devices Feb 18 23:42:27 volumio volumio[10701]: info: Ignoring mount for partition: boot Feb 18 23:42:27 volumio volumio[10701]: info: Ignoring mount for partition: volumio Feb 18 23:42:27 volumio volumio[10701]: info: Ignoring mount for partition: volumio_data Feb 18 23:42:27 volumio volumio[10701]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 18 23:42:27 volumio volumio[10701]: info: Loading plugin "volumio_command_line_client"... Feb 18 23:42:27 volumio volumio[10701]: info: Loading plugin "upnp"... Feb 18 23:42:27 volumio volumio[10701]: info: [1771432947785] Starting Upmpd Daemon Feb 18 23:42:27 volumio volumio[10701]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 18 23:42:27 volumio volumio[10701]: info: Loading plugin "my_music"... Feb 18 23:42:27 volumio volumio[10701]: info: Loading plugin "mpd"... Feb 18 23:42:28 volumio volumio[10701]: info: Loading plugin "upnp_browser"... Feb 18 23:42:29 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Feb 18 23:42:29 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 23:42:29 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 23:42:29 volumio go-librespot[10774]: go-librespot daemon starting... Feb 18 23:42:29 volumio go-librespot[10775]: time="2026-02-18T23:42:29+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 23:42:29 volumio go-librespot[10775]: time="2026-02-18T23:42:29+07:00" level=debug msg="app state loaded" Feb 18 23:42:29 volumio go-librespot[10775]: time="2026-02-18T23:42:29+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 23:42:30 volumio sudo[10750]: pam_unix(sudo:session): session closed for user root Feb 18 23:42:30 volumio go-librespot[10775]: time="2026-02-18T23:42:30+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:42:30 volumio go-librespot[10775]: time="2026-02-18T23:42:30+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:42:30 volumio go-librespot[10775]: time="2026-02-18T23:42:30+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:42:30 volumio go-librespot[10775]: time="2026-02-18T23:42:30+07:00" level=info msg="zeroconf server listening on port 39283" Feb 18 23:42:30 volumio go-librespot[10775]: time="2026-02-18T23:42:30+07:00" level=debug msg="obtained new client token: AADTsg2jIzoAHw7Pu+D35nppJGeGmyICa0DrA3DkInuL9p+kDxPkoNMBsYMrPIKSa4dSQh4GSkqgPIfitD4grsge2hno8sEyagQr2JESvqf6TAoUWisrWb9QVzu+CCSjaEjkI6Zx1FlQ2liD/5j2ENguPKG9gwGV/Pq9TCZ671+vUwrGFI3CN/xxgBT+ojMDFTw8PwV90Brx+kdEu3Zh1i6tKj2DbQerE0T/HsD53YREH33NpvpEJiJHFg==" Feb 18 23:42:30 volumio go-librespot[10775]: time="2026-02-18T23:42:30+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 23:42:31 volumio go-librespot[10775]: time="2026-02-18T23:42:31+07:00" level=debug msg="completed keyexchange" Feb 18 23:42:31 volumio go-librespot[10775]: time="2026-02-18T23:42:31+07:00" level=debug msg="completed challenge" Feb 18 23:42:31 volumio go-librespot[10775]: time="2026-02-18T23:42:31+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 18 23:42:31 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 23:42:31 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 23:42:31 volumio volumio[10701]: info: Starting UPNP Browser Feb 18 23:42:31 volumio volumio[10701]: info: Loading plugin "alarm-clock"... Feb 18 23:42:31 volumio volumio[10701]: info: Loading plugin "airplay_emulation"... Feb 18 23:42:31 volumio volumio[10701]: info: Starting Shairport Sync Feb 18 23:42:31 volumio volumio[10701]: info: Loading plugin "last_100"... Feb 18 23:42:31 volumio volumio[10701]: info: Loading plugin "webradio"... Feb 18 23:42:31 volumio volumio[10701]: info: Loading plugin "i2s_dacs"... Feb 18 23:42:31 volumio volumio[10701]: info: Loading plugin "volumiodiscovery"... Feb 18 23:42:32 volumio volumio[10701]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 18 23:42:32 volumio volumio[10701]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 18 23:42:32 volumio volumio[10701]: *** WARNING *** For more information see Feb 18 23:42:32 volumio volumio[10701]: *** 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:42:32 volumio volumio[10701]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 18 23:42:32 volumio volumio[10701]: *** WARNING *** For more information see Feb 18 23:42:32 volumio node[10701]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 18 23:42:32 volumio node[10701]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 18 23:42:32 volumio node[10701]: *** WARNING *** For more information see Feb 18 23:42:32 volumio node[10701]: *** 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:42:32 volumio node[10701]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 18 23:42:32 volumio node[10701]: *** WARNING *** For more information see Feb 18 23:42:32 volumio volumio[10701]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 18 23:42:32 volumio volumio[10701]: info: Discovery: Started advertising with name: Volumio Feb 18 23:42:32 volumio volumio[10701]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 18 23:42:32 volumio volumio[10701]: info: Loading plugin "spop"... Feb 18 23:42:33 volumio volumio[10701]: info: Loading plugin "ytcr"... Feb 18 23:42:34 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Feb 18 23:42:34 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 23:42:34 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 23:42:34 volumio go-librespot[10786]: go-librespot daemon starting... Feb 18 23:42:34 volumio go-librespot[10787]: time="2026-02-18T23:42:34+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 23:42:34 volumio go-librespot[10787]: time="2026-02-18T23:42:34+07:00" level=debug msg="app state loaded" Feb 18 23:42:34 volumio go-librespot[10787]: time="2026-02-18T23:42:34+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 23:42:34 volumio go-librespot[10787]: time="2026-02-18T23:42:34+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:42:34 volumio go-librespot[10787]: time="2026-02-18T23:42:34+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:42:34 volumio go-librespot[10787]: time="2026-02-18T23:42:34+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:42:34 volumio go-librespot[10787]: time="2026-02-18T23:42:34+07:00" level=info msg="zeroconf server listening on port 45855" Feb 18 23:42:35 volumio go-librespot[10787]: time="2026-02-18T23:42:35+07:00" level=debug msg="obtained new client token: AADa/6O49ky5+h4J6H+HRzK6S9WaP6wYFKAo+NYD8cl1dxbNrFp7oSdPvNVyueQWvJJMwMkFnjjcKRgnltOcogPohjrQ/JQKzhNhFws/7LV9Y+8fMSkRW6Os88kQHksVwv5t/mOuK1HuJUuylDq8j9b4k5LJkOA7ZV5ZvO5S4XVv4+vlwuAKnCcNMcQXEHX69/PmSdKF9o1G777tJI/UrGA8ZwrzMCr3N8ImU11X/J3j6XNY05OA0V0=" Feb 18 23:42:35 volumio go-librespot[10787]: time="2026-02-18T23:42:35+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 23:42:35 volumio go-librespot[10787]: time="2026-02-18T23:42:35+07:00" level=debug msg="completed keyexchange" Feb 18 23:42:35 volumio go-librespot[10787]: time="2026-02-18T23:42:35+07:00" level=debug msg="completed challenge" Feb 18 23:42:35 volumio go-librespot[10787]: time="2026-02-18T23:42:35+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:42:35 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 23:42:35 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 23:42:36 volumio volumio[10701]: info: Loading plugin "ytmusic"... Feb 18 23:42:37 volumio volumio-remote-updater[25144]: [2026-02-18 23:42:37] [connect] Successful connection Feb 18 23:42:37 volumio volumio[10701]: info: Loading plugin "outputs"... Feb 18 23:42:37 volumio volumio[10701]: info: Loading plugin "albumart"... Feb 18 23:42:37 volumio volumio[10701]: info: Plugin example_plugin is not enabled Feb 18 23:42:37 volumio volumio[10701]: info: Loading plugin "inputs"... Feb 18 23:42:37 volumio volumio[10701]: info: Loading plugin "updater_comm"... Feb 18 23:42:37 volumio volumio[10701]: info: Plugin mpdemulation is not enabled Feb 18 23:42:37 volumio volumio[10701]: info: Loading plugin "rest_api"... Feb 18 23:42:37 volumio volumio[10701]: info: Loading plugin "websocket"... Feb 18 23:42:37 volumio volumio[10701]: info: Starting Socket.io Server version 1.7.4 Feb 18 23:42:37 volumio volumio[10701]: info: Loading plugin "RoonBridge"... Feb 18 23:42:38 volumio volumio[10701]: info: Applying required configuration parameters for plugin RoonBridge Feb 18 23:42:38 volumio volumio[10701]: info: Loading i18n strings for locale en Feb 18 23:42:38 volumio volumio[10701]: Updating browse sources language Feb 18 23:42:38 volumio volumio[10701]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 23:42:38 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Feb 18 23:42:38 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 23:42:38 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 23:42:38 volumio go-librespot[10818]: go-librespot daemon starting... Feb 18 23:42:38 volumio go-librespot[10819]: time="2026-02-18T23:42:38+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 23:42:38 volumio go-librespot[10819]: time="2026-02-18T23:42:38+07:00" level=debug msg="app state loaded" Feb 18 23:42:38 volumio go-librespot[10819]: time="2026-02-18T23:42:38+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 23:42:38 volumio volumio[10701]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 18 23:42:38 volumio volumio[10701]: info: CoreCommandRouter::initPlayerControls Feb 18 23:42:38 volumio volumio[10701]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 23:42:38 volumio volumio[10701]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 23:42:38 volumio volumio[10701]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 23:42:38 volumio volumio[10701]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 23:42:38 volumio volumio[10701]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 23:42:38 volumio volumio[10701]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 23:42:38 volumio volumio[10701]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 23:42:38 volumio volumio[10701]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 23:42:38 volumio volumio[10701]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 18 23:42:38 volumio volumio[10701]: Express server listening on port 3000 Feb 18 23:42:38 volumio volumio[10701]: [Metrics] WebUI: 15s 904.58ms Feb 18 23:42:38 volumio volumio[10701]: info: CoreStateMachine::resetVolumioState Feb 18 23:42:38 volumio volumio[10701]: info: CoreStateMachine::getcurrentVolume Feb 18 23:42:38 volumio volumio[10701]: info: CoreCommandRouter::volumioRetrievevolume Feb 18 23:42:38 volumio volumio[10808]: Forking 3 albumart workers Feb 18 23:42:38 volumio sudo[10831]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 18 23:42:38 volumio sudo[10831]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 23:42:39 volumio sudo[10831]: pam_unix(sudo:session): session closed for user root Feb 18 23:42:39 volumio sudo[10834]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 18 23:42:39 volumio sudo[10834]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 23:42:39 volumio sudo[10834]: pam_unix(sudo:session): session closed for user root Feb 18 23:42:39 volumio volumio[10701]: info: Volumio Network Manager: Network status updated: 1 Feb 18 23:42:39 volumio go-librespot[10819]: time="2026-02-18T23:42:39+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 23:42:39 volumio go-librespot[10819]: time="2026-02-18T23:42:39+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 18 23:42:39 volumio go-librespot[10819]: time="2026-02-18T23:42:39+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 18 23:42:39 volumio go-librespot[10819]: time="2026-02-18T23:42:39+07:00" level=info msg="zeroconf server listening on port 39393" Feb 18 23:42:39 volumio volumio[10701]: info: VolumeController:: Volume=100 Mute =false Feb 18 23:42:39 volumio volumio[10701]: info: CoreStateMachine::pushState Feb 18 23:42:39 volumio volumio[10701]: info: CorePlayQueue::getTrack 0 Feb 18 23:42:39 volumio volumio[10701]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 18 23:42:39 volumio volumio[10701]: info: CoreCommandRouter::volumioPushState Feb 18 23:42:39 volumio volumio[10701]: info: CoreStateMachine::updateTrackBlock Feb 18 23:42:39 volumio volumio[10701]: info: CorePlayQueue::getTrackBlock Feb 18 23:42:39 volumio volumio[10701]: info: CoreCommandRouter::volumioRetrievevolume Feb 18 23:42:39 volumio volumio-remote-updater[25144]: [2026-02-18 23:42:39] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1771432957 101 Feb 18 23:42:39 volumio go-librespot[10819]: time="2026-02-18T23:42:39+07:00" level=debug msg="obtained new client token: AADXPB1pirXU5x7pJeaQeIlZzuveXKO3L2rcMsWbrHEBJ46McfRrcrBuyCx34ZKpLVHirRTT3ekSQCqE31hxnyAcmomGGFf5PxzxowclbwlSe5X0Q8sm7IAuRW6HCy2zWK7SK+elFt6cet5GfwcySz/CY0HtFAl9XNwvJAq9jpuPP/Ko1U2GmCTOrYl2sHGBYDkZJ2GXSok0CZgZBS1aFenWkuGcMNg0pr9er5xLCezRIhKPZqlpYE+0lw==" Feb 18 23:42:39 volumio volumio[10701]: 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:42:39 volumio volumio[10701]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 23:42:39 volumio volumio[10701]: info: Reloading queue from file Feb 18 23:42:39 volumio go-librespot[10819]: time="2026-02-18T23:42:39+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 23:42:39 volumio volumio[10701]: info: CoreStateMachine::setRepeat null single undefined Feb 18 23:42:39 volumio volumio[10701]: info: CoreStateMachine::pushState Feb 18 23:42:39 volumio volumio[10701]: info: CorePlayQueue::getTrack 0 Feb 18 23:42:39 volumio volumio[10701]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 18 23:42:39 volumio volumio[10701]: info: CoreCommandRouter::volumioPushState Feb 18 23:42:39 volumio volumio[10701]: info: CoreStateMachine::setRandom null Feb 18 23:42:39 volumio volumio[10701]: info: CoreStateMachine::pushState Feb 18 23:42:39 volumio volumio[10701]: info: CorePlayQueue::getTrack 0 Feb 18 23:42:39 volumio volumio[10701]: info: CoreCommandRouter::volumioPushState Feb 18 23:42:39 volumio volumio[10701]: info: Setting Device type: Raspberry PI Feb 18 23:42:39 volumio go-librespot[10819]: time="2026-02-18T23:42:39+07:00" level=debug msg="completed keyexchange" Feb 18 23:42:39 volumio go-librespot[10819]: time="2026-02-18T23:42:39+07:00" level=debug msg="completed challenge" Feb 18 23:42:39 volumio volumio[10701]: info: Completed loading Core Plugins Feb 18 23:42:39 volumio volumio[10701]: info: Preparing to generate the ALSA configuration file Feb 18 23:42:39 volumio go-librespot[10819]: time="2026-02-18T23:42:39+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:42:39 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 23:42:39 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 23:42:40 volumio volumio[10701]: info: VolumeController:: Volume=100 Mute =false Feb 18 23:42:40 volumio volumio[10701]: info: CoreStateMachine::pushState Feb 18 23:42:40 volumio volumio[10701]: info: CorePlayQueue::getTrack 0 Feb 18 23:42:40 volumio volumio[10701]: info: CoreCommandRouter::volumioPushState Feb 18 23:42:40 volumio volumio[10701]: info: Asound.conf file unchanged, so no further update is needed Feb 18 23:42:40 volumio volumio[10701]: info: Output device has changed, restarting MPD Feb 18 23:42:40 volumio volumio[10701]: info: Output device has changed, restarting Shairport Sync Feb 18 23:42:40 volumio volumio[10701]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 23:42:40 volumio volumio[10701]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 23:42:40 volumio sudo[10881]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 18 23:42:40 volumio sudo[10881]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 23:42:40 volumio sudo[10883]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 18 23:42:40 volumio sudo[10883]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 23:42:40 volumio sudo[10879]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 18 23:42:40 volumio sudo[10879]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 23:42:40 volumio sudo[10881]: pam_unix(sudo:session): session closed for user root Feb 18 23:42:40 volumio volumio[10701]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 18 23:42:40 volumio volumio[10701]: info: ___________ START PLUGINS ___________ Feb 18 23:42:40 volumio volumio[10701]: info: ControllerMpd::onStart: Initializing MPD Feb 18 23:42:40 volumio volumio[10701]: info: Creating MPD Configuration file Feb 18 23:42:40 volumio sudo[10892]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 18 23:42:40 volumio sudo[10892]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 23:42:40 volumio sudo[10892]: pam_unix(sudo:session): session closed for user root Feb 18 23:42:40 volumio volumio[10701]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 18 23:42:40 volumio volumio[10701]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 23:42:40 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 18 23:42:40 volumio volumio[10701]: info: [1771432960365] CoreMusicLibrary::Adding element Media Servers Feb 18 23:42:40 volumio volumio[10701]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 23:42:40 volumio sudo[10879]: pam_unix(sudo:session): session closed for user root Feb 18 23:42:40 volumio volumio[10701]: info: UPNP Browser: Client initialized successfully Feb 18 23:42:40 volumio sudo[10895]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 18 23:42:40 volumio sudo[10895]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 23:42:40 volumio volumio[10701]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 23:42:40 volumio volumio[10701]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 23:42:40 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 18 23:42:40 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 18 23:42:40 volumio systemd[1]: mpd.service: Consumed 7.225s CPU time. Feb 18 23:42:40 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 18 23:42:40 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 18 23:42:40 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 18 23:42:40 volumio volumio[10701]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 18 23:42:40 volumio volumio[10701]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 23:42:40 volumio volumio[10701]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 23:42:40 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 18 23:42:40 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 18 23:42:40 volumio volumio[10701]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 18 23:42:40 volumio volumio[10701]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 23:42:40 volumio volumio[10701]: info: [1771432960732] CoreMusicLibrary::Adding element Last_100 Feb 18 23:42:40 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 18 23:42:40 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 18 23:42:40 volumio volumio[10701]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 23:42:40 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 18 23:42:40 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 18 23:42:40 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 18 23:42:40 volumio volumio[10701]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 23:42:40 volumio volumio[10701]: info: [1771432960768] CoreMusicLibrary::Adding element Webradio Feb 18 23:42:40 volumio volumio[10701]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 23:42:40 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 18 23:42:40 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 18 23:42:40 volumio volumio[10701]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 18 23:42:40 volumio volumio[10701]: info: Initializing BBC Radios Feb 18 23:42:41 volumio volumio[10701]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 18 23:42:41 volumio volumio[10701]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 23:42:41 volumio volumio[10701]: info: Creating Spotify config file Feb 18 23:42:41 volumio volumio[10701]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 23:42:41 volumio sudo[10908]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 18 23:42:41 volumio sudo[10908]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 18 23:42:41 volumio sudo[10908]: pam_unix(sudo:session): session closed for user root Feb 18 23:42:42 volumio volumio[10835]: Starting albumart workers Feb 18 23:42:42 volumio volumio[10836]: Starting albumart workers Feb 18 23:42:42 volumio volumio[10701]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 23:42:42 volumio volumio[10701]: info: [1771432962353] CoreMusicLibrary::Adding element YouTube Music Feb 18 23:42:42 volumio volumio[10701]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 23:42:42 volumio volumio[10701]: Cannot find translation for source YouTube Music Feb 18 23:42:42 volumio volumio[10701]: info: Volumio Calling Home Feb 18 23:42:42 volumio sudo[10925]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Feb 18 23:42:42 volumio sudo[10925]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 23:42:42 volumio volumio[10832]: Starting albumart workers Feb 18 23:42:42 volumio sudo[10925]: pam_unix(sudo:session): session closed for user root Feb 18 23:42:43 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Feb 18 23:42:43 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 23:42:43 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 23:42:43 volumio go-librespot[10930]: go-librespot daemon starting... Feb 18 23:42:43 volumio volumio[10701]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Feb 18 23:42:43 volumio volumio[10701]: info: Discovery: Found device Volumio Feb 18 23:42:43 volumio volumio[10701]: info: CoreCommandRouter::volumioGetState Feb 18 23:42:43 volumio volumio[10701]: info: CorePlayQueue::getTrack 0 Feb 18 23:42:43 volumio volumio[10701]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Feb 18 23:42:43 volumio volumio[10701]: info: Discovery: Found device Volumio Feb 18 23:42:43 volumio volumio[10701]: info: CoreCommandRouter::volumioGetState Feb 18 23:42:43 volumio volumio[10701]: info: CorePlayQueue::getTrack 0 Feb 18 23:42:43 volumio go-librespot[10931]: time="2026-02-18T23:42:43+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 23:42:43 volumio go-librespot[10931]: time="2026-02-18T23:42:43+07:00" level=debug msg="app state loaded" Feb 18 23:42:43 volumio go-librespot[10931]: time="2026-02-18T23:42:43+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 23:42:43 volumio volumio[10701]: info: MPD Permissions set Feb 18 23:42:43 volumio volumio[10701]: info: MPD Permissions set Feb 18 23:42:43 volumio volumio[10701]: info: Upmpdcli Daemon Started Feb 18 23:42:43 volumio volumio[10701]: info: Spotify config file written Feb 18 23:42:43 volumio sudo[10939]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 18 23:42:43 volumio volumio[10701]: 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:42:43 volumio sudo[10939]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 23:42:43 volumio volumio[10701]: info: Volumio called home Feb 18 23:42:43 volumio volumio[10701]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 23:42:43 volumio volumio[10701]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 23:42:43 volumio volumio[10701]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 23:42:43 volumio volumio[10701]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 23:42:43 volumio volumio[10701]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 23:42:43 volumio volumio[10701]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 23:42:43 volumio volumio[10701]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 23:42:43 volumio volumio[10701]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 23:42:43 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Feb 18 23:42:43 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Feb 18 23:42:43 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 23:42:43 volumio volumio[10701]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 23:42:43 volumio volumio[10701]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 23:42:43 volumio volumio[10701]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 23:42:43 volumio volumio[10701]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 23:42:43 volumio volumio[10701]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 23:42:43 volumio volumio[10701]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 23:42:43 volumio volumio[10701]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 23:42:43 volumio volumio[10701]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 23:42:43 volumio volumio[10701]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 23:42:43 volumio volumio[10701]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 23:42:43 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 23:42:43 volumio go-librespot[10946]: go-librespot daemon starting... Feb 18 23:42:43 volumio sudo[10939]: pam_unix(sudo:session): session closed for user root Feb 18 23:42:43 volumio go-librespot[10949]: time="2026-02-18T23:42:43+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 23:42:43 volumio go-librespot[10949]: time="2026-02-18T23:42:43+07:00" level=debug msg="app state loaded" Feb 18 23:42:43 volumio go-librespot[10949]: time="2026-02-18T23:42:43+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 23:42:43 volumio volumio[10701]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 23:42:43 volumio volumio[10701]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 23:42:43 volumio volumio[10701]: info: No need to fix Spotify hosts Feb 18 23:42:44 volumio go-librespot[10949]: time="2026-02-18T23:42: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 23:42:44 volumio go-librespot[10949]: time="2026-02-18T23:42:44+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:42:44 volumio go-librespot[10949]: time="2026-02-18T23:42:44+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:42:44 volumio go-librespot[10949]: time="2026-02-18T23:42:44+07:00" level=info msg="zeroconf server listening on port 43473" Feb 18 23:42:44 volumio go-librespot[10949]: time="2026-02-18T23:42:44+07:00" level=debug msg="obtained new client token: AACvla0xCTQr36+A5ps3j7R6WAeSkrEiWzcxvzf06SEQjp/iDliricOAG5HaX27ZV8HtZQ/lxBhh9vLNRPzZWl2xd09J42LFmoHQprsAf3AS/P7Y1mhe52cSLfgQWJWAap8Tp3sGm5Y63pqE/U4sSGtQxXCwb3C1aFDCQB8eMYIjK2A2JgnEKmazOqYfVzb0tky1oithacCks4lU3bkMN7m26gWzxFSYMFrWbNxShoONvchsk8YgAx9Y+Q==" Feb 18 23:42:44 volumio go-librespot[10949]: time="2026-02-18T23:42:44+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 23:42:44 volumio go-librespot[10949]: time="2026-02-18T23:42:44+07:00" level=debug msg="completed keyexchange" Feb 18 23:42:44 volumio go-librespot[10949]: time="2026-02-18T23:42:44+07:00" level=debug msg="completed challenge" Feb 18 23:42:44 volumio go-librespot[10949]: time="2026-02-18T23:42:44+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:42:44 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 23:42:44 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 23:42:45 volumio volumio[10701]: info: Starting Shairport Sync Feb 18 23:42:45 volumio volumio[10701]: info: Starting Shairport Sync Feb 18 23:42:45 volumio volumio[10701]: info: Starting Shairport Sync Feb 18 23:42:45 volumio sudo[10979]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 18 23:42:45 volumio sudo[10979]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 23:42:45 volumio sudo[10981]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 18 23:42:45 volumio sudo[10981]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 23:42:45 volumio sudo[10984]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 18 23:42:45 volumio sudo[10984]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 23:42:45 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 18 23:42:45 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 18 23:42:45 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 18 23:42:45 volumio systemd[1]: shairport-sync.service: Consumed 2.369s CPU time. Feb 18 23:42:45 volumio volumio[10701]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 18 23:42:45 volumio volumio[10701]: SPOTIFY: BQCU4aoEd3TeDWQkEDpjQd2oPRPiJfDiiWa_y9ZlkmtRUpRFVF81xvL3DFyKVBPeOgA7djRKNbPBJvmTJ22HSGxSJDVLWNGlowfF_LGdl_AvWhnM8S-pzDtd4JqlkID5NTXSQK4ggGS_JiqYMJXF8nPLv1pUD8TGgu4Ywv9EDsRp3oQ7dtzNBiud3ut1Zcyu3IvA2f4usb6JgXGLfhOFKnFMnVdJzbOt6s6U4EX2C0O2dIPAO6DjT41VJNsyFtnbmwAtTQ3qeqNQZHXTz63OfnE-n89rS8JTowj7c2oPkkvQGDGMfY4rAc9J Feb 18 23:42:45 volumio volumio[10701]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 18 23:42:45 volumio volumio[10701]: info: New Spotify access token = BQCU4aoEd3TeDWQkEDpjQd2oPRPiJfDiiWa_y9ZlkmtRUpRFVF81xvL3DFyKVBPeOgA7djRKNbPBJvmTJ22HSGxSJDVLWNGlowfF_LGdl_AvWhnM8S-pzDtd4JqlkID5NTXSQK4ggGS_JiqYMJXF8nPLv1pUD8TGgu4Ywv9EDsRp3oQ7dtzNBiud3ut1Zcyu3IvA2f4usb6JgXGLfhOFKnFMnVdJzbOt6s6U4EX2C0O2dIPAO6DjT41VJNsyFtnbmwAtTQ3qeqNQZHXTz63OfnE-n89rS8JTowj7c2oPkkvQGDGMfY4rAc9J Feb 18 23:42:45 volumio volumio[10701]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 18 23:42:45 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 18 23:42:45 volumio sudo[10979]: pam_unix(sudo:session): session closed for user root Feb 18 23:42:45 volumio sudo[10984]: pam_unix(sudo:session): session closed for user root Feb 18 23:42:45 volumio sudo[10981]: pam_unix(sudo:session): session closed for user root Feb 18 23:42:45 volumio volumio[10701]: info: CoreCommandRouter::volumioGetState Feb 18 23:42:45 volumio volumio[10701]: info: CorePlayQueue::getTrack 0 Feb 18 23:42:45 volumio volumio[10701]: info: Shairport-Sync Started Feb 18 23:42:45 volumio volumio[10701]: Error adding Membership: Error: addMembership EINVAL Feb 18 23:42:45 volumio volumio[10701]: info: Shairport-Sync Started Feb 18 23:42:45 volumio volumio[10701]: info: Shairport-Sync Started Feb 18 23:42:46 volumio volumio[10701]: 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:42:46 volumio volumio[10701]: info: Spotify Successfully logged in Feb 18 23:42:46 volumio volumio[10701]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 23:42:46 volumio volumio[10701]: info: [1771432966130] CoreMusicLibrary::Adding element Spotify Feb 18 23:42:46 volumio volumio[10701]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 23:42:46 volumio volumio[10701]: Cannot find translation for source YouTube Music Feb 18 23:42:46 volumio volumio[10701]: Cannot find translation for source Spotify Feb 18 23:42:46 volumio volumio[10701]: info: [yt-cast-receiver] DIAL server listening on port 8098 Feb 18 23:42:46 volumio volumio[10701]: info: CoreCommandRouter::volumioRetrievevolume Feb 18 23:42:46 volumio volumio[10701]: info: VolumeController:: Volume=100 Mute =false Feb 18 23:42:46 volumio volumio[10701]: info: CoreCommandRouter::volumioGetState Feb 18 23:42:46 volumio volumio[10701]: info: CorePlayQueue::getTrack 0 Feb 18 23:42:46 volumio volumio[10701]: info: CoreStateMachine::pushState Feb 18 23:42:46 volumio volumio[10701]: info: CorePlayQueue::getTrack 0 Feb 18 23:42:46 volumio volumio[10701]: info: CoreCommandRouter::volumioPushState Feb 18 23:42:48 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Feb 18 23:42:48 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 23:42:48 volumio volumio[10701]: info: go-librespot daemon successfully initialized Feb 18 23:42:48 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 23:42:48 volumio go-librespot[11019]: go-librespot daemon starting... Feb 18 23:42:48 volumio go-librespot[11020]: time="2026-02-18T23:42:48+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 23:42:48 volumio go-librespot[11020]: time="2026-02-18T23:42:48+07:00" level=debug msg="app state loaded" Feb 18 23:42:48 volumio go-librespot[11020]: time="2026-02-18T23:42:48+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 23:42:48 volumio mpd[10923]: 2026-02-18T23:42:48 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 18 23:42:48 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 18 23:42:48 volumio sudo[10883]: pam_unix(sudo:session): session closed for user root Feb 18 23:42:48 volumio sudo[10895]: pam_unix(sudo:session): session closed for user root Feb 18 23:42:48 volumio volumio[10701]: error: MPD error: The expression evaluated to a falsy value: Feb 18 23:42:48 volumio volumio[10701]: assert.ok(self.idling) Feb 18 23:42:48 volumio volumio[10701]: error: The expression evaluated to a falsy value: Feb 18 23:42:48 volumio volumio[10701]: assert.ok(self.idling) Feb 18 23:42:48 volumio volumio[10701]: info: MPD running with PID10923 Feb 18 23:42:48 volumio volumio[10701]: ,establishing connection Feb 18 23:42:48 volumio volumio[10701]: error: updateQueue error: null Feb 18 23:42:48 volumio volumio[10701]: info: Completed starting Core Plugins Feb 18 23:42:48 volumio volumio[10701]: info: ------------------------------------------- Feb 18 23:42:48 volumio volumio[10701]: info: ----- MyVolumio plugins startup ---- Feb 18 23:42:48 volumio volumio[10701]: info: ------------------------------------------- Feb 18 23:42:48 volumio volumio[10701]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 18 23:42:48 volumio volumio[10701]: error: updateQueue error: null Feb 18 23:42:48 volumio go-librespot[11020]: time="2026-02-18T23:42:48+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 23:42:48 volumio go-librespot[11020]: time="2026-02-18T23:42:48+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:42:48 volumio go-librespot[11020]: time="2026-02-18T23:42:48+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:42:48 volumio go-librespot[11020]: time="2026-02-18T23:42:48+07:00" level=info msg="zeroconf server listening on port 32847" Feb 18 23:42:48 volumio go-librespot[11020]: time="2026-02-18T23:42:48+07:00" level=debug msg="obtained new client token: AABwdLJf/yuQeRtyu8TAhlKr7uPoVcBsIMdsjb2odxeB+PvayLXcffE6odFrqOCTTDSrKG/pjIIgMZpVVIer5PVoLCBM+lvQ4/IHSHn0piS+RnRKdlOQXOSMCKtTsy7Zk0cjTP95GayxSJ48Kj/A3sHpxwBfDg7ibxoVjtrOtpn7cQ4p/rKIg8z+VlDvEj0lxNbrYJrtc8OYtki9kCOfRI3aX6tpB6w/6dd4sFLxVGWVO0lV88vHLUxw4Q==" Feb 18 23:42:48 volumio go-librespot[11020]: time="2026-02-18T23:42:48+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:42:49 volumio go-librespot[11020]: time="2026-02-18T23:42:49+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Feb 18 23:42:49 volumio go-librespot[11020]: time="2026-02-18T23:42:49+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:42:49 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 23:42:49 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 23:42:51 volumio volumio[10701]: info: Initializing connection to go-librespot Websocket Feb 18 23:42:51 volumio volumio[10701]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 18 23:42:52 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Feb 18 23:42:52 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 23:42:52 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 23:42:52 volumio go-librespot[11032]: go-librespot daemon starting... Feb 18 23:42:52 volumio go-librespot[11033]: time="2026-02-18T23:42:52+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 23:42:52 volumio go-librespot[11033]: time="2026-02-18T23:42:52+07:00" level=debug msg="app state loaded" Feb 18 23:42:52 volumio go-librespot[11033]: time="2026-02-18T23:42:52+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 23:42:52 volumio go-librespot[11033]: time="2026-02-18T23:42:52+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 18 23:42:52 volumio go-librespot[11033]: time="2026-02-18T23:42:52+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 18 23:42:52 volumio go-librespot[11033]: time="2026-02-18T23:42:52+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 18 23:42:52 volumio go-librespot[11033]: time="2026-02-18T23:42:52+07:00" level=info msg="zeroconf server listening on port 39293" Feb 18 23:42:53 volumio go-librespot[11033]: time="2026-02-18T23:42:53+07:00" level=debug msg="obtained new client token: AACr4LwYwVlNqx7tgYq0f8ViO8/UQQmuIZXblrEvkvG/HZiO0Rki9SrEAuz3vHiVQ8S7180ctYUW5vqCK21UWzMHiUphFgamQLpUThSWfGQqZ0wN4MS22BB7dQxoR5iXelG8QxzVyYcW5o7D8b2ft9tfw3wMQSIogxDzGe+kK5cWWTV5w9y1mn1SIg317R1w2gpX8b9839HzAtCMkDRvTDXB+DF+UZQk6K56uKzCFvBuprk9EbtCc5g=" Feb 18 23:42:53 volumio go-librespot[11033]: time="2026-02-18T23:42:53+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 23:42:53 volumio go-librespot[11033]: time="2026-02-18T23:42:53+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:42:53 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 23:42:53 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 23:42:53 volumio volumio[10701]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 18 23:42:54 volumio volumio[10701]: info: Initializing connection to go-librespot Websocket Feb 18 23:42:54 volumio volumio[10701]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 18 23:42:56 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Feb 18 23:42:56 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 23:42:56 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 23:42:56 volumio go-librespot[11040]: go-librespot daemon starting... Feb 18 23:42:56 volumio go-librespot[11041]: time="2026-02-18T23:42:56+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 23:42:56 volumio go-librespot[11041]: time="2026-02-18T23:42:56+07:00" level=debug msg="app state loaded" Feb 18 23:42:56 volumio go-librespot[11041]: time="2026-02-18T23:42:56+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 23:42:56 volumio go-librespot[11041]: time="2026-02-18T23:42:56+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:42:56 volumio go-librespot[11041]: time="2026-02-18T23:42:56+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:42:56 volumio go-librespot[11041]: time="2026-02-18T23:42:56+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:42:56 volumio go-librespot[11041]: time="2026-02-18T23:42:56+07:00" level=info msg="zeroconf server listening on port 43673" Feb 18 23:42:57 volumio go-librespot[11041]: time="2026-02-18T23:42:57+07:00" level=debug msg="obtained new client token: AAB4UgLTdd5Ovb2zBTxiHl7CoS/IUAOLQu4xwm0vExcetr9SJV6TPBYJFh98jvMVBJ5VhceGSmO2LKdv6i6qfXuWJ8Haz9qqdxnKW3jwYKJ55nkMYoS46rv71J/wlyOoIig7PyD4mCT7uiGTsI6ZI7bhyXTFo2wJiuVRCPJRxFzI94NSR6NViOf5E+hqz1dplauYYPX0YeRRrraIGpVmKElvWw+kU6sxR7nSB9WTFWqP5tAf+O8qYI8=" Feb 18 23:42:57 volumio volumio[10701]: info: Initializing connection to go-librespot Websocket Feb 18 23:42:57 volumio go-librespot[11041]: time="2026-02-18T23:42:57+07:00" level=debug msg="new websocket client" Feb 18 23:42:57 volumio volumio[10701]: info: Connection to go-librespot Websocket established Feb 18 23:42:57 volumio go-librespot[11041]: time="2026-02-18T23:42:57+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 23:42:57 volumio volumio[10701]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 18 23:42:57 volumio volumio[10701]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 18 23:42:57 volumio volumio[10701]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 18 23:42:57 volumio volumio[10701]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 18 23:42:57 volumio volumio[10701]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 18 23:42:57 volumio volumio[10701]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 18 23:42:57 volumio volumio[10701]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 18 23:42:57 volumio volumio[10701]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 18 23:42:57 volumio volumio[10701]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 18 23:42:57 volumio volumio[10701]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 18 23:42:57 volumio volumio[10701]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 18 23:42:57 volumio volumio[10701]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 18 23:42:57 volumio volumio[10701]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 18 23:42:57 volumio volumio[10701]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 18 23:42:57 volumio volumio[10701]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 18 23:42:57 volumio volumio[10701]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 18 23:42:57 volumio volumio[10701]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 18 23:42:57 volumio volumio[10701]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 18 23:42:57 volumio volumio[10701]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 18 23:42:57 volumio volumio[10701]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 18 23:42:57 volumio volumio[10701]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 18 23:42:57 volumio volumio[10701]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 18 23:42:57 volumio volumio[10701]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 18 23:42:57 volumio volumio[10701]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 18 23:42:57 volumio go-librespot[11041]: time="2026-02-18T23:42:57+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:42:57 volumio volumio[10701]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 18 23:42:57 volumio volumio[10701]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 18 23:42:57 volumio volumio[10701]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 18 23:42:57 volumio volumio[10701]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 18 23:42:57 volumio volumio[10701]: info: Adding plugin bluetooth to MyMusic Plugins Feb 18 23:42:57 volumio volumio[10701]: info: Adding plugin multiroom to MyMusic Plugins Feb 18 23:42:57 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 23:42:57 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 23:42:57 volumio volumio[10701]: info: Adding plugin metavolumio to MyMusic Plugins Feb 18 23:42:57 volumio volumio[10701]: info: Adding plugin cd_controller to MyMusic Plugins Feb 18 23:42:57 volumio volumio[10701]: info: Adding plugin qobuzconnect to MyMusic Plugins Feb 18 23:42:57 volumio volumio[10701]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 18 23:42:57 volumio volumio[10701]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 18 23:42:57 volumio volumio[10701]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 18 23:42:59 volumio volumio[10701]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 18 23:42:59 volumio volumio[10701]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 18 23:42:59 volumio volumio[10701]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 23:42:59 volumio volumio[10701]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 23:42:59 volumio volumio[10701]: info: Starting MyVolumio Remote Streaming Endpoints Feb 18 23:42:59 volumio volumio[10701]: info: MyVolumio login type: Token Feb 18 23:42:59 volumio volumio[10701]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 18 23:42:59 volumio volumio[10701]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 18 23:43:00 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Feb 18 23:43:00 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 23:43:00 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 23:43:00 volumio go-librespot[11063]: go-librespot daemon starting... Feb 18 23:43:00 volumio go-librespot[11064]: time="2026-02-18T23:43:00+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 23:43:00 volumio go-librespot[11064]: time="2026-02-18T23:43:00+07:00" level=debug msg="app state loaded" Feb 18 23:43:00 volumio go-librespot[11064]: time="2026-02-18T23:43:00+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 23:43:01 volumio volumio[10701]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 18 23:43:01 volumio volumio[10701]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 18 23:43:01 volumio volumio[10701]: info: Streaming services startup Feb 18 23:43:01 volumio volumio[10701]: info: Starting Streaming Daemon Feb 18 23:43:01 volumio sudo[11073]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 18 23:43:01 volumio sudo[11073]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 23:43:01 volumio volumio[10701]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 18 23:43:01 volumio go-librespot[11064]: time="2026-02-18T23:43: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:43:01 volumio go-librespot[11064]: time="2026-02-18T23:43: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:43:01 volumio go-librespot[11064]: time="2026-02-18T23:43: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:43:01 volumio sudo[11073]: pam_unix(sudo:session): session closed for user root Feb 18 23:43:01 volumio go-librespot[11064]: time="2026-02-18T23:43:01+07:00" level=info msg="zeroconf server listening on port 35195" Feb 18 23:43:01 volumio volumio[10701]: info: Getting Spotify volume Feb 18 23:43:01 volumio volumio[10701]: info: Connection to go-librespot Websocket closed Feb 18 23:43:01 volumio volumio[10701]: error: Cannot start Volumio Streaming Daemon Feb 18 23:43:01 volumio volumio[10701]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 18 23:43:01 volumio volumio[10701]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 18 23:43:01 volumio volumio[10701]: 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:43:01 volumio go-librespot[11064]: time="2026-02-18T23:43:01+07:00" level=debug msg="obtained new client token: AABE/7bd+yTHlBR+TnrkR7np6zdasBP8YE2ov0eLmzrTLQCwjLdfpLClHe1ZrtOY/cymUkCSAGSC3TKV2jYWai5TKuCeyeR71YVAq7TcncEMAtdKaoxMLuXhqHpo+Enkh6WkYSpVNYJGE6Ztbo14Egkfln27UpsTjAD+CaVIoWNbjgIcB4j3IubN3nP55XzFYSlHsVL0GbRDQN2nQTCeMVc3lRAbYqdP0WFsWQeluXP5gWfKqk1ZU8EW1A==" Feb 18 23:43:01 volumio go-librespot[11064]: time="2026-02-18T23:43:01+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 23:43:01 volumio volumio[10701]: info: CoreCommandRouter::volumioGetState Feb 18 23:43:01 volumio volumio[10701]: info: CorePlayQueue::getTrack 0 Feb 18 23:43:01 volumio volumio[10701]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Feb 18 23:43:01 volumio volumio[10701]: SPOTIFY: SPOTIFY VOLUME undefined Feb 18 23:43:01 volumio volumio[10701]: SPOTIFY: VOLUMIO VOLUME 100 Feb 18 23:43:01 volumio volumio[10701]: info: Aligning Spotify Volume to Volumio Volume Feb 18 23:43:01 volumio volumio[10701]: info: CoreCommandRouter::volumioGetState Feb 18 23:43:01 volumio volumio[10701]: info: CorePlayQueue::getTrack 0 Feb 18 23:43:01 volumio volumio[10701]: info: Setting Spotify Volume from Volumio: 100 Feb 18 23:43:01 volumio go-librespot[11064]: time="2026-02-18T23:43:01+07:00" level=debug msg="completed keyexchange" Feb 18 23:43:01 volumio go-librespot[11064]: time="2026-02-18T23:43:01+07:00" level=debug msg="completed challenge" Feb 18 23:43:01 volumio go-librespot[11064]: time="2026-02-18T23:43:01+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:43:01 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 23:43:01 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 23:43:01 volumio volumio[10701]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 18 23:43:01 volumio volumio[10701]: Error: socket hang up Feb 18 23:43:01 volumio volumio[10701]: at connResetException (node:internal/errors:720:14) Feb 18 23:43:01 volumio volumio[10701]: at Socket.socketOnEnd (node:_http_client:519:23) Feb 18 23:43:01 volumio volumio[10701]: at Socket.emit (node:events:526:35) Feb 18 23:43:01 volumio volumio[10701]: at endReadableNT (node:internal/streams/readable:1376:12) Feb 18 23:43:01 volumio volumio[10701]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Feb 18 23:43:01 volumio volumio[10701]: code: 'ECONNRESET', Feb 18 23:43:01 volumio volumio[10701]: response: undefined Feb 18 23:43:01 volumio volumio[10701]: } Feb 18 23:43:01 volumio volumio[10701]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 18 23:43:03 volumio sudo[11094]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-18 23:42' Feb 18 23:43:03 volumio sudo[11094]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 23:43:03 volumio sudo[11094]: pam_unix(sudo:session): session closed for user root Feb 18 23:43:03 volumio volumio-remote-updater[25144]: [2026-02-18 23:43:03] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Feb 18 23:43:03 volumio volumio-remote-updater[25144]: [2026-02-18 23:43:03] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Feb 18 23:43:03 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Feb 18 23:43:03 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Feb 18 23:43:03 volumio systemd[1]: volumio.service: Consumed 55.239s CPU time. Feb 18 23:43:03 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 18 23:43:03 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 18 23:43:03 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 22610. Feb 18 23:43:03 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 18 23:43:03 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Feb 18 23:43:03 volumio systemd[1]: volumio.service: Consumed 55.239s CPU time. Feb 18 23:43:03 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Feb 18 23:43:03 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 18 23:43:04 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Feb 18 23:43:04 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 23:43:04 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 23:43:04 volumio go-librespot[11122]: go-librespot daemon starting... Feb 18 23:43:04 volumio go-librespot[11123]: time="2026-02-18T23:43:04+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 23:43:04 volumio go-librespot[11123]: time="2026-02-18T23:43:04+07:00" level=debug msg="app state loaded" Feb 18 23:43:04 volumio go-librespot[11123]: time="2026-02-18T23:43:04+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 23:43:05 volumio go-librespot[11123]: time="2026-02-18T23:43:05+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 18 23:43:05 volumio go-librespot[11123]: time="2026-02-18T23:43:05+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 18 23:43:05 volumio go-librespot[11123]: time="2026-02-18T23:43:05+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 18 23:43:05 volumio go-librespot[11123]: time="2026-02-18T23:43:05+07:00" level=info msg="zeroconf server listening on port 34143" Feb 18 23:43:05 volumio go-librespot[11123]: time="2026-02-18T23:43:05+07:00" level=debug msg="obtained new client token: AADZDnamVosSG2tYcU/Ipvoc0KtAOZyZd5bcqewC2vHy4FQFudJcwgQkybpRR9u513ZyWVCd9aeepdtIDNKitmJmS3B2JsVv8jFIJS82Kir5pIbzbFr7Wka9Cl+zrUkagi14cZTDPCt8r74LFiDaTxIKf+W5hLHS2TXPLZokETytcdeQOxrGtJv2mA/KI6XXf1/J/WssRbBudFH20Mpvs3MFyst8pXXtkoeuXtw+nlpWy2pxPE8vFhQ3ag==" Feb 18 23:43:05 volumio go-librespot[11123]: time="2026-02-18T23:43:05+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 23:43:05 volumio go-librespot[11123]: time="2026-02-18T23:43:05+07:00" level=debug msg="completed keyexchange" Feb 18 23:43:05 volumio go-librespot[11123]: time="2026-02-18T23:43:05+07:00" level=debug msg="completed challenge" Feb 18 23:43:06 volumio go-librespot[11123]: time="2026-02-18T23:43: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:43:06 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 23:43:06 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 23:43:07 volumio volumio[11106]: info: ------------------------------------------- Feb 18 23:43:07 volumio volumio[11106]: info: ----- Volumio3 ---- Feb 18 23:43:07 volumio volumio[11106]: info: ------------------------------------------- Feb 18 23:43:07 volumio volumio[11106]: info: ----- System startup ---- Feb 18 23:43:07 volumio volumio[11106]: info: ------------------------------------------- Feb 18 23:43:08 volumio volumio-remote-updater[25144]: [2026-02-18 23:43:08] [connect] Successful connection Feb 18 23:43:08 volumio volumio[11106]: info: MYVOLUMIO Environment detected Feb 18 23:43:08 volumio volumio[11106]: info: Plugin folders cleanup Feb 18 23:43:08 volumio volumio[11106]: info: Scanning into folder /volumio/app/plugins/ Feb 18 23:43:08 volumio volumio[11106]: info: Scanning category audio_interface Feb 18 23:43:08 volumio volumio[11106]: info: Scanning category miscellanea Feb 18 23:43:08 volumio volumio[11106]: info: Scanning category music_service Feb 18 23:43:08 volumio volumio[11106]: info: Scanning category plugins.json Feb 18 23:43:08 volumio volumio[11106]: info: Scanning category system_controller Feb 18 23:43:08 volumio volumio[11106]: info: Scanning category user_interface Feb 18 23:43:08 volumio volumio[11106]: info: Scanning into folder /data/plugins/ Feb 18 23:43:08 volumio volumio[11106]: info: Scanning category music_service Feb 18 23:43:08 volumio volumio[11106]: info: Plugin folders cleanup completed Feb 18 23:43:08 volumio volumio[11106]: info: ------------------------------------------- Feb 18 23:43:08 volumio volumio[11106]: info: ----- Core plugins startup ---- Feb 18 23:43:08 volumio volumio[11106]: info: ------------------------------------------- Feb 18 23:43:08 volumio volumio[11106]: info: Loading plugins from folder /volumio/app/plugins/ Feb 18 23:43:08 volumio volumio[11106]: info: Adding plugin upnp to MyMusic Plugins Feb 18 23:43:08 volumio volumio[11106]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 18 23:43:08 volumio volumio[11106]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 18 23:43:08 volumio volumio[11106]: info: Loading plugins from folder /data/plugins/ Feb 18 23:43:08 volumio volumio[11106]: info: Loading plugin "system"... Feb 18 23:43:09 volumio volumio[11106]: info: Loading plugin "appearance"... Feb 18 23:43:09 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Feb 18 23:43:09 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 23:43:09 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 23:43:09 volumio go-librespot[11142]: go-librespot daemon starting... Feb 18 23:43:09 volumio go-librespot[11143]: time="2026-02-18T23:43:09+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 23:43:09 volumio go-librespot[11143]: time="2026-02-18T23:43:09+07:00" level=debug msg="app state loaded" Feb 18 23:43:09 volumio go-librespot[11143]: time="2026-02-18T23:43:09+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 23:43:09 volumio go-librespot[11143]: time="2026-02-18T23:43:09+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 23:43:09 volumio go-librespot[11143]: time="2026-02-18T23:43:09+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 18 23:43:09 volumio go-librespot[11143]: time="2026-02-18T23:43:09+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 18 23:43:09 volumio go-librespot[11143]: time="2026-02-18T23:43:09+07:00" level=info msg="zeroconf server listening on port 39633" Feb 18 23:43:10 volumio go-librespot[11143]: time="2026-02-18T23:43:10+07:00" level=debug msg="obtained new client token: AABUDKl2pPAC7Nw88JdtnsLJpz2AcJ2jh4K6hjbKEBfmnuDF6OsAkuk9HH+v2PGhwnco+QCzex1UJq7XBIrYcQ1vHeVNv9R31M46Zm2eFGJ1AFH5TZhvm7QB92cRYQJ/mHav4TER3Jg3ujIzeG6Nf8XWmtj31KN76Sob5mT2s0jp/WnlGCkMQMX2cf39utrQ8UI/bAk0WVsPBsAtDIghrI16tKAhylruMGtkPODVjkCybd/OI4y4Ezg=" Feb 18 23:43:10 volumio go-librespot[11143]: time="2026-02-18T23:43:10+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 23:43:10 volumio go-librespot[11143]: time="2026-02-18T23:43: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:43:10 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 23:43:10 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 23:43:10 volumio volumio[11106]: info: Loading plugin "network"... Feb 18 23:43:11 volumio volumio[11106]: info: Refreshing Cached IP Addresses Feb 18 23:43:11 volumio sudo[11152]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 18 23:43:11 volumio sudo[11152]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 23:43:11 volumio sudo[11154]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 18 23:43:11 volumio sudo[11154]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 23:43:11 volumio volumio[11106]: info: Loading plugin "services"... Feb 18 23:43:11 volumio sudo[11154]: pam_unix(sudo:session): session closed for user root Feb 18 23:43:11 volumio sudo[11152]: pam_unix(sudo:session): session closed for user root Feb 18 23:43:11 volumio volumio[11106]: info: Loading plugin "alsa_controller"... Feb 18 23:43:11 volumio sudo[11161]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 18 23:43:11 volumio sudo[11161]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 23:43:11 volumio volumio[11106]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 18 23:43:11 volumio volumio[11106]: info: Loading plugin "wizard"... Feb 18 23:43:11 volumio volumio[11106]: info: Loading plugin "networkfs"... Feb 18 23:43:11 volumio volumio[11106]: info: Starting Udev Watcher for removable devices Feb 18 23:43:11 volumio volumio[11106]: info: Ignoring mount for partition: boot Feb 18 23:43:11 volumio volumio[11106]: info: Ignoring mount for partition: volumio Feb 18 23:43:11 volumio volumio[11106]: info: Ignoring mount for partition: volumio_data Feb 18 23:43:11 volumio volumio[11106]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 18 23:43:11 volumio volumio[11106]: info: Loading plugin "volumio_command_line_client"... Feb 18 23:43:11 volumio volumio[11106]: info: Loading plugin "upnp"... Feb 18 23:43:11 volumio volumio[11106]: info: [1771432991416] Starting Upmpd Daemon Feb 18 23:43:11 volumio volumio[11106]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 18 23:43:11 volumio volumio[11106]: info: Loading plugin "my_music"... Feb 18 23:43:11 volumio volumio[11106]: info: Loading plugin "mpd"... Feb 18 23:43:12 volumio volumio[11106]: info: Loading plugin "upnp_browser"... Feb 18 23:43:13 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Feb 18 23:43:13 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 23:43:13 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 23:43:13 volumio go-librespot[11185]: go-librespot daemon starting... Feb 18 23:43:13 volumio go-librespot[11186]: time="2026-02-18T23:43:13+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 23:43:13 volumio go-librespot[11186]: time="2026-02-18T23:43:13+07:00" level=debug msg="app state loaded" Feb 18 23:43:13 volumio go-librespot[11186]: time="2026-02-18T23:43:13+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 23:43:13 volumio sudo[11161]: pam_unix(sudo:session): session closed for user root Feb 18 23:43:14 volumio go-librespot[11186]: time="2026-02-18T23:43: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:43:14 volumio go-librespot[11186]: time="2026-02-18T23:43: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:43:14 volumio go-librespot[11186]: time="2026-02-18T23:43: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:43:14 volumio go-librespot[11186]: time="2026-02-18T23:43:14+07:00" level=info msg="zeroconf server listening on port 41511" Feb 18 23:43:14 volumio go-librespot[11186]: time="2026-02-18T23:43:14+07:00" level=debug msg="obtained new client token: AAC6/gWhEtfBFYgjgxgseGckH6Ys2XbrN+O5HXpKKSeIgytlzcu6xz5bQ4dr+SltOzrSBkxi4yLDBKmyb2Qhk9dXyGD5zX5yJQqjoCfwdSIrr3AFSQQPnZxobsrDhXA2lawu15w66aZDvVUjCy1zpv6NM6C2nDNzEmfJz7uot/MOZozB1EE/7DDExtQgNwNL43x8+AOj4aONYUWU6NNiL1SuGgQlvLYOX2gfBuJGYj0d9vqXyG2VaPA3ZA==" Feb 18 23:43:14 volumio go-librespot[11186]: time="2026-02-18T23:43:14+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 23:43:14 volumio go-librespot[11186]: time="2026-02-18T23:43:14+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:43:14 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 23:43:14 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 23:43:15 volumio volumio[11106]: info: Starting UPNP Browser Feb 18 23:43:15 volumio volumio[11106]: info: Loading plugin "alarm-clock"... Feb 18 23:43:15 volumio volumio[11106]: info: Loading plugin "airplay_emulation"... Feb 18 23:43:15 volumio volumio[11106]: info: Starting Shairport Sync Feb 18 23:43:15 volumio volumio[11106]: info: Loading plugin "last_100"... Feb 18 23:43:15 volumio volumio[11106]: info: Loading plugin "webradio"... Feb 18 23:43:15 volumio volumio[11106]: info: Loading plugin "i2s_dacs"... Feb 18 23:43:15 volumio volumio[11106]: info: Loading plugin "volumiodiscovery"... Feb 18 23:43:15 volumio volumio[11106]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 18 23:43:15 volumio volumio[11106]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 18 23:43:15 volumio node[11106]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 18 23:43:15 volumio volumio[11106]: *** WARNING *** For more information see Feb 18 23:43:15 volumio volumio[11106]: *** 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:43:15 volumio volumio[11106]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 18 23:43:15 volumio volumio[11106]: *** WARNING *** For more information see Feb 18 23:43:15 volumio node[11106]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 18 23:43:15 volumio node[11106]: *** WARNING *** For more information see Feb 18 23:43:15 volumio node[11106]: *** 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:43:15 volumio node[11106]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 18 23:43:15 volumio node[11106]: *** WARNING *** For more information see Feb 18 23:43:15 volumio volumio[11106]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 18 23:43:15 volumio volumio[11106]: info: Discovery: Started advertising with name: Volumio Feb 18 23:43:15 volumio volumio[11106]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 18 23:43:15 volumio volumio[11106]: info: Loading plugin "spop"... Feb 18 23:43:17 volumio volumio[11106]: info: Loading plugin "ytcr"... Feb 18 23:43:17 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Feb 18 23:43:17 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 23:43:17 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 23:43:17 volumio go-librespot[11196]: go-librespot daemon starting... Feb 18 23:43:17 volumio go-librespot[11197]: time="2026-02-18T23:43:17+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 23:43:17 volumio go-librespot[11197]: time="2026-02-18T23:43:17+07:00" level=debug msg="app state loaded" Feb 18 23:43:17 volumio go-librespot[11197]: time="2026-02-18T23:43:17+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 23:43:18 volumio go-librespot[11197]: time="2026-02-18T23:43:18+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 23:43:18 volumio go-librespot[11197]: time="2026-02-18T23:43:18+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 18 23:43:18 volumio go-librespot[11197]: time="2026-02-18T23:43:18+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 18 23:43:18 volumio go-librespot[11197]: time="2026-02-18T23:43:18+07:00" level=info msg="zeroconf server listening on port 40897" Feb 18 23:43:18 volumio go-librespot[11197]: time="2026-02-18T23:43:18+07:00" level=debug msg="obtained new client token: AABF/hqeCnSnrkek29sfQ0AfFyX0jvlve+gJh+e9tshLH/a8zWyDI41V8RPwB9i2P+casj3lf43xeUMVA0iQD9eZtyyostK481aea8rA30t8kZzgca0crVbAgQGtPAevTx3sBqCotzEnqAw8AYN+HQGG8LLn8yDmRERZLYDU2zM4pMITNv5Qd79myHKX179iX5L+jx58TERLgWFffT0sp0CNZubslEleWyS3bXamgTFDULEgi2N5Msp+dg==" Feb 18 23:43:18 volumio go-librespot[11197]: time="2026-02-18T23:43:18+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 23:43:18 volumio go-librespot[11197]: time="2026-02-18T23:43:18+07:00" level=debug msg="completed keyexchange" Feb 18 23:43:18 volumio go-librespot[11197]: time="2026-02-18T23:43:18+07:00" level=debug msg="completed challenge" Feb 18 23:43:18 volumio go-librespot[11197]: time="2026-02-18T23:43:18+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 18 23:43:18 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 23:43:18 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 23:43:20 volumio volumio[11106]: info: Loading plugin "ytmusic"... Feb 18 23:43:21 volumio volumio-remote-updater[25144]: [2026-02-18 23:43:21] [connect] Successful connection Feb 18 23:43:21 volumio volumio[11106]: info: Loading plugin "outputs"... Feb 18 23:43:21 volumio volumio[11106]: info: Loading plugin "albumart"... Feb 18 23:43:21 volumio volumio[11106]: info: Plugin example_plugin is not enabled Feb 18 23:43:21 volumio volumio[11106]: info: Loading plugin "inputs"... Feb 18 23:43:21 volumio volumio[11106]: info: Loading plugin "updater_comm"... Feb 18 23:43:21 volumio volumio[11106]: info: Plugin mpdemulation is not enabled Feb 18 23:43:21 volumio volumio[11106]: info: Loading plugin "rest_api"... Feb 18 23:43:21 volumio volumio[11106]: info: Loading plugin "websocket"... Feb 18 23:43:21 volumio volumio[11106]: info: Starting Socket.io Server version 1.7.4 Feb 18 23:43:21 volumio volumio[11106]: info: Loading plugin "RoonBridge"... Feb 18 23:43:22 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Feb 18 23:43:22 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 23:43:22 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 23:43:22 volumio go-librespot[11230]: go-librespot daemon starting... Feb 18 23:43:22 volumio go-librespot[11231]: time="2026-02-18T23:43:22+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 23:43:22 volumio go-librespot[11231]: time="2026-02-18T23:43:22+07:00" level=debug msg="app state loaded" Feb 18 23:43:22 volumio go-librespot[11231]: time="2026-02-18T23:43:22+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 23:43:22 volumio volumio[11106]: info: Applying required configuration parameters for plugin RoonBridge Feb 18 23:43:22 volumio volumio[11106]: info: Loading i18n strings for locale en Feb 18 23:43:22 volumio volumio[11106]: Updating browse sources language Feb 18 23:43:22 volumio volumio[11106]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 23:43:22 volumio volumio[11106]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 18 23:43:22 volumio volumio[11106]: info: CoreCommandRouter::initPlayerControls Feb 18 23:43:22 volumio volumio[11106]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 23:43:22 volumio volumio[11106]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 23:43:22 volumio volumio[11106]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 23:43:22 volumio volumio[11106]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 23:43:22 volumio volumio[11106]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 23:43:22 volumio volumio[11106]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 23:43:22 volumio volumio[11106]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 23:43:22 volumio volumio[11106]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 23:43:22 volumio volumio[11106]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 18 23:43:22 volumio volumio[11220]: Forking 3 albumart workers Feb 18 23:43:22 volumio volumio[11106]: Express server listening on port 3000 Feb 18 23:43:22 volumio volumio[11106]: [Metrics] WebUI: 16s 115.53ms Feb 18 23:43:22 volumio volumio[11106]: info: CoreStateMachine::resetVolumioState Feb 18 23:43:22 volumio volumio[11106]: info: CoreStateMachine::getcurrentVolume Feb 18 23:43:22 volumio volumio[11106]: info: CoreCommandRouter::volumioRetrievevolume Feb 18 23:43:22 volumio go-librespot[11231]: time="2026-02-18T23:43:22+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 23:43:22 volumio go-librespot[11231]: time="2026-02-18T23:43:22+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:43:22 volumio go-librespot[11231]: time="2026-02-18T23:43:22+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:43:22 volumio sudo[11272]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 18 23:43:22 volumio sudo[11272]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 23:43:22 volumio volumio[11106]: info: Volumio Network Manager: Network status updated: 1 Feb 18 23:43:22 volumio go-librespot[11231]: time="2026-02-18T23:43:22+07:00" level=info msg="zeroconf server listening on port 35597" Feb 18 23:43:22 volumio sudo[11272]: pam_unix(sudo:session): session closed for user root Feb 18 23:43:22 volumio sudo[11270]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 18 23:43:22 volumio sudo[11270]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 23:43:22 volumio sudo[11270]: pam_unix(sudo:session): session closed for user root Feb 18 23:43:23 volumio go-librespot[11231]: time="2026-02-18T23:43:23+07:00" level=debug msg="obtained new client token: AABt1lGEGnGGKi++yoGaGS29gPmKjfr4+PdApgNBy6Fl94ziIu8iqcfSLzDbgktzakV2ui/TM3rviY9kQfyGDnuwu/YG/zU9wQ+eQSGvLBaIPeWscMAWwH1QZSxl1ORIoMnUF9fXpcb5dLgJx+aaSsEpngX+qlszot+NxbgQgs9mV8+kB7FMwnjvaIU979+o7404jldIqD40YBfmJ9u5/CNz3x2s4D8Pt3E/Igun1VojtyouWVXzukM=" Feb 18 23:43:23 volumio volumio-remote-updater[25144]: [2026-02-18 23:43:23] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1771433001 101 Feb 18 23:43:23 volumio volumio[11106]: 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:43:23 volumio volumio[11106]: info: VolumeController:: Volume=100 Mute =false Feb 18 23:43:23 volumio volumio[11106]: info: CoreStateMachine::pushState Feb 18 23:43:23 volumio volumio[11106]: info: CorePlayQueue::getTrack 0 Feb 18 23:43:23 volumio volumio[11106]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 18 23:43:23 volumio volumio[11106]: info: CoreCommandRouter::volumioPushState Feb 18 23:43:23 volumio go-librespot[11231]: time="2026-02-18T23:43: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:43:23 volumio volumio[11106]: info: CoreStateMachine::updateTrackBlock Feb 18 23:43:23 volumio volumio[11106]: info: CorePlayQueue::getTrackBlock Feb 18 23:43:23 volumio volumio[11106]: info: CoreCommandRouter::volumioRetrievevolume Feb 18 23:43:23 volumio go-librespot[11231]: time="2026-02-18T23:43:23+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Feb 18 23:43:23 volumio volumio[11106]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 23:43:23 volumio volumio[11106]: info: Reloading queue from file Feb 18 23:43:23 volumio volumio[11106]: info: CoreStateMachine::setRepeat null single undefined Feb 18 23:43:23 volumio volumio[11106]: info: CoreStateMachine::pushState Feb 18 23:43:23 volumio volumio[11106]: info: CorePlayQueue::getTrack 0 Feb 18 23:43:23 volumio volumio[11106]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 18 23:43:23 volumio volumio[11106]: info: CoreCommandRouter::volumioPushState Feb 18 23:43:23 volumio volumio[11106]: info: CoreStateMachine::setRandom null Feb 18 23:43:23 volumio volumio[11106]: info: CoreStateMachine::pushState Feb 18 23:43:23 volumio go-librespot[11231]: time="2026-02-18T23:43:23+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:43:23 volumio volumio[11106]: info: CorePlayQueue::getTrack 0 Feb 18 23:43:23 volumio volumio[11106]: info: CoreCommandRouter::volumioPushState Feb 18 23:43:23 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 23:43:23 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 23:43:23 volumio volumio[11106]: info: Setting Device type: Raspberry PI Feb 18 23:43:23 volumio volumio[11106]: info: Completed loading Core Plugins Feb 18 23:43:23 volumio volumio[11106]: info: Preparing to generate the ALSA configuration file Feb 18 23:43:23 volumio volumio[11106]: info: VolumeController:: Volume=100 Mute =false Feb 18 23:43:23 volumio volumio[11106]: info: CoreStateMachine::pushState Feb 18 23:43:23 volumio volumio[11106]: info: CorePlayQueue::getTrack 0 Feb 18 23:43:23 volumio volumio[11106]: info: CoreCommandRouter::volumioPushState Feb 18 23:43:23 volumio volumio[11106]: info: Asound.conf file unchanged, so no further update is needed Feb 18 23:43:23 volumio volumio[11106]: info: Output device has changed, restarting MPD Feb 18 23:43:23 volumio volumio[11106]: info: Output device has changed, restarting Shairport Sync Feb 18 23:43:23 volumio volumio[11106]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 23:43:23 volumio volumio[11106]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 23:43:23 volumio sudo[11288]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 18 23:43:23 volumio sudo[11288]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 23:43:23 volumio sudo[11292]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 18 23:43:23 volumio sudo[11292]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 23:43:23 volumio sudo[11290]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 18 23:43:23 volumio sudo[11290]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 23:43:23 volumio sudo[11290]: pam_unix(sudo:session): session closed for user root Feb 18 23:43:23 volumio sudo[11288]: pam_unix(sudo:session): session closed for user root Feb 18 23:43:23 volumio volumio[11106]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 18 23:43:23 volumio volumio[11106]: info: ___________ START PLUGINS ___________ Feb 18 23:43:23 volumio volumio[11106]: info: ControllerMpd::onStart: Initializing MPD Feb 18 23:43:23 volumio volumio[11106]: info: Creating MPD Configuration file Feb 18 23:43:23 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 18 23:43:23 volumio sudo[11301]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 18 23:43:23 volumio sudo[11301]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 23:43:23 volumio volumio[11106]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 18 23:43:23 volumio volumio[11106]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 23:43:23 volumio volumio[11106]: info: [1771433003965] CoreMusicLibrary::Adding element Media Servers Feb 18 23:43:23 volumio volumio[11106]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 23:43:24 volumio sudo[11301]: pam_unix(sudo:session): session closed for user root Feb 18 23:43:24 volumio volumio[11106]: info: UPNP Browser: Client initialized successfully Feb 18 23:43:24 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 18 23:43:24 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 18 23:43:24 volumio systemd[1]: mpd.service: Consumed 7.167s CPU time. Feb 18 23:43:24 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 18 23:43:24 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 18 23:43:24 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 18 23:43:24 volumio sudo[11304]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 18 23:43:24 volumio sudo[11304]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 23:43:24 volumio volumio[11106]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 23:43:24 volumio volumio[11106]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 23:43:24 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 18 23:43:24 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 18 23:43:24 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 18 23:43:24 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 18 23:43:24 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 18 23:43:24 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 18 23:43:24 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 18 23:43:24 volumio volumio[11106]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 18 23:43:24 volumio volumio[11106]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 23:43:24 volumio volumio[11106]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 23:43:24 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 18 23:43:24 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 18 23:43:24 volumio volumio[11106]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 18 23:43:24 volumio volumio[11106]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 23:43:24 volumio volumio[11106]: info: [1771433004323] CoreMusicLibrary::Adding element Last_100 Feb 18 23:43:24 volumio volumio[11106]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 23:43:24 volumio volumio[11106]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 23:43:24 volumio volumio[11106]: info: [1771433004348] CoreMusicLibrary::Adding element Webradio Feb 18 23:43:24 volumio volumio[11106]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 23:43:24 volumio volumio[11106]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 18 23:43:24 volumio volumio[11106]: info: Initializing BBC Radios Feb 18 23:43:24 volumio volumio[11106]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 18 23:43:24 volumio volumio[11106]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 23:43:24 volumio volumio[11106]: info: Creating Spotify config file Feb 18 23:43:24 volumio volumio[11106]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 23:43:24 volumio sudo[11317]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 18 23:43:24 volumio sudo[11317]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 18 23:43:24 volumio sudo[11317]: pam_unix(sudo:session): session closed for user root Feb 18 23:43:25 volumio volumio[11243]: Starting albumart workers Feb 18 23:43:25 volumio volumio[11106]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 23:43:25 volumio volumio[11106]: info: [1771433005919] CoreMusicLibrary::Adding element YouTube Music Feb 18 23:43:25 volumio volumio[11106]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 23:43:25 volumio volumio[11106]: Cannot find translation for source YouTube Music Feb 18 23:43:25 volumio volumio[11106]: info: Volumio Calling Home Feb 18 23:43:26 volumio sudo[11334]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Feb 18 23:43:26 volumio sudo[11334]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 23:43:26 volumio volumio[11239]: Starting albumart workers Feb 18 23:43:26 volumio sudo[11334]: pam_unix(sudo:session): session closed for user root Feb 18 23:43:26 volumio volumio[11242]: Starting albumart workers Feb 18 23:43:26 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Feb 18 23:43:26 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 23:43:26 volumio volumio[11106]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Feb 18 23:43:26 volumio volumio[11106]: info: Discovery: Found device Volumio Feb 18 23:43:26 volumio volumio[11106]: info: CoreCommandRouter::volumioGetState Feb 18 23:43:26 volumio volumio[11106]: info: CorePlayQueue::getTrack 0 Feb 18 23:43:26 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 23:43:26 volumio go-librespot[11339]: go-librespot daemon starting... Feb 18 23:43:26 volumio volumio[11106]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Feb 18 23:43:26 volumio volumio[11106]: info: Discovery: Found device Volumio Feb 18 23:43:26 volumio volumio[11106]: info: CoreCommandRouter::volumioGetState Feb 18 23:43:26 volumio volumio[11106]: info: CorePlayQueue::getTrack 0 Feb 18 23:43:26 volumio go-librespot[11340]: time="2026-02-18T23:43:26+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 23:43:26 volumio go-librespot[11340]: time="2026-02-18T23:43:26+07:00" level=debug msg="app state loaded" Feb 18 23:43:26 volumio go-librespot[11340]: time="2026-02-18T23:43:26+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 23:43:26 volumio volumio[11106]: info: MPD Permissions set Feb 18 23:43:26 volumio volumio[11106]: info: MPD Permissions set Feb 18 23:43:26 volumio volumio[11106]: info: Upmpdcli Daemon Started Feb 18 23:43:26 volumio volumio[11106]: info: Volumio called home Feb 18 23:43:26 volumio volumio[11106]: info: Spotify config file written Feb 18 23:43:27 volumio sudo[11347]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 18 23:43:27 volumio sudo[11347]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 23:43:27 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Feb 18 23:43:27 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Feb 18 23:43:27 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 23:43:27 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 23:43:27 volumio go-librespot[11351]: go-librespot daemon starting... Feb 18 23:43:27 volumio sudo[11347]: pam_unix(sudo:session): session closed for user root Feb 18 23:43:27 volumio go-librespot[11352]: time="2026-02-18T23:43:27+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 23:43:27 volumio go-librespot[11352]: time="2026-02-18T23:43:27+07:00" level=debug msg="app state loaded" Feb 18 23:43:27 volumio go-librespot[11352]: time="2026-02-18T23:43:27+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 23:43:27 volumio volumio[11106]: 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:43:27 volumio volumio[11106]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 23:43:27 volumio volumio[11106]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 23:43:27 volumio volumio[11106]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 23:43:27 volumio volumio[11106]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 23:43:27 volumio volumio[11106]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 23:43:27 volumio volumio[11106]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 23:43:27 volumio volumio[11106]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 23:43:27 volumio volumio[11106]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 23:43:27 volumio volumio[11106]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 23:43:27 volumio volumio[11106]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 23:43:27 volumio volumio[11106]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 23:43:27 volumio volumio[11106]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 23:43:27 volumio volumio[11106]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 23:43:27 volumio volumio[11106]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 23:43:27 volumio volumio[11106]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 23:43:27 volumio volumio[11106]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 23:43:27 volumio volumio[11106]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 23:43:27 volumio volumio[11106]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 23:43:27 volumio volumio[11106]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 23:43:27 volumio volumio[11106]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 23:43:27 volumio volumio[11106]: info: No need to fix Spotify hosts Feb 18 23:43:28 volumio go-librespot[11352]: time="2026-02-18T23:43:28+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 23:43:28 volumio go-librespot[11352]: time="2026-02-18T23:43:28+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:43:28 volumio go-librespot[11352]: time="2026-02-18T23:43:28+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:43:28 volumio go-librespot[11352]: time="2026-02-18T23:43:28+07:00" level=info msg="zeroconf server listening on port 35699" Feb 18 23:43:28 volumio go-librespot[11352]: time="2026-02-18T23:43:28+07:00" level=debug msg="obtained new client token: AADq+QGTqZJJRmY+l4J6L9v1wvcn79qKoFpulZ6QdjYCgSmTpmgt14TDI0WCiC+DH1Q6Y5KTADdo/JhgmWQ7qMLslvGeH2CrdFp/GKGsQdlP5T43KRsgZ/pQwxNAs65x9EnPuBdEqRkwQpVSSdb11KZRwYg8D76FpuZidxpp6It6owOUrBKL7GqxmNCXMXQ1YB8SyknbCM3GFd+Yg6qN1Gxw6LDs3Wb7q82rBVwQDGLJYTZKxqMiRo2XJA==" Feb 18 23:43:28 volumio go-librespot[11352]: time="2026-02-18T23:43:28+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 23:43:28 volumio go-librespot[11352]: time="2026-02-18T23:43: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:43:28 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 23:43:28 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 23:43:29 volumio volumio[11106]: info: Starting Shairport Sync Feb 18 23:43:29 volumio volumio[11106]: info: Starting Shairport Sync Feb 18 23:43:29 volumio volumio[11106]: info: Starting Shairport Sync Feb 18 23:43:29 volumio sudo[11389]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 18 23:43:29 volumio sudo[11389]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 23:43:29 volumio sudo[11391]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 18 23:43:29 volumio sudo[11391]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 23:43:29 volumio sudo[11393]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 18 23:43:29 volumio sudo[11393]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 23:43:29 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 18 23:43:29 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 18 23:43:29 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 18 23:43:29 volumio systemd[1]: shairport-sync.service: Consumed 2.343s CPU time. Feb 18 23:43:29 volumio volumio[11106]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 18 23:43:29 volumio volumio[11106]: SPOTIFY: BQDEkrIROURZb5Hj0Jr4RFySre3RVt7ceGBqv22Ea9y9kDJqLuMuYM_F9K-7nXrqA1ZZpWqCxSDX7qOt1-9PY-VHSlt7ygXSZZdWeY26r7nTeuPIXApuEXJlViH-V86shDukACOil_2EKNfMzam6H4cWAtfO6RoojpN3lLxn_9pxKGXBNQttVv6Hpnro7i0rp1jU3zvBfQSEy88KYjHVZxQviLILVRaZqqbIxLn64__yv0irdGCZKyYQCAuZhnaQPr3gijrWSHWlttC89redDHR1-nftMqcGNhXnJ1Nnf1rDtAhkDnH6mbdK Feb 18 23:43:29 volumio volumio[11106]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 18 23:43:29 volumio volumio[11106]: info: New Spotify access token = BQDEkrIROURZb5Hj0Jr4RFySre3RVt7ceGBqv22Ea9y9kDJqLuMuYM_F9K-7nXrqA1ZZpWqCxSDX7qOt1-9PY-VHSlt7ygXSZZdWeY26r7nTeuPIXApuEXJlViH-V86shDukACOil_2EKNfMzam6H4cWAtfO6RoojpN3lLxn_9pxKGXBNQttVv6Hpnro7i0rp1jU3zvBfQSEy88KYjHVZxQviLILVRaZqqbIxLn64__yv0irdGCZKyYQCAuZhnaQPr3gijrWSHWlttC89redDHR1-nftMqcGNhXnJ1Nnf1rDtAhkDnH6mbdK Feb 18 23:43:29 volumio volumio[11106]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 18 23:43:29 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 18 23:43:29 volumio sudo[11393]: pam_unix(sudo:session): session closed for user root Feb 18 23:43:29 volumio sudo[11391]: pam_unix(sudo:session): session closed for user root Feb 18 23:43:29 volumio sudo[11389]: pam_unix(sudo:session): session closed for user root Feb 18 23:43:29 volumio volumio[11106]: info: Shairport-Sync Started Feb 18 23:43:29 volumio volumio[11106]: Error adding Membership: Error: addMembership EINVAL Feb 18 23:43:29 volumio volumio[11106]: info: Shairport-Sync Started Feb 18 23:43:29 volumio volumio[11106]: info: Shairport-Sync Started Feb 18 23:43:29 volumio volumio[11106]: info: CoreCommandRouter::volumioGetState Feb 18 23:43:29 volumio volumio[11106]: info: CorePlayQueue::getTrack 0 Feb 18 23:43:29 volumio volumio[11106]: 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:43:29 volumio volumio[11106]: info: Spotify Successfully logged in Feb 18 23:43:29 volumio volumio[11106]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 23:43:29 volumio volumio[11106]: info: [1771433009970] CoreMusicLibrary::Adding element Spotify Feb 18 23:43:29 volumio volumio[11106]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 23:43:29 volumio volumio[11106]: Cannot find translation for source YouTube Music Feb 18 23:43:29 volumio volumio[11106]: Cannot find translation for source Spotify Feb 18 23:43:30 volumio volumio[11106]: info: [yt-cast-receiver] DIAL server listening on port 8098 Feb 18 23:43:30 volumio volumio[11106]: info: CoreCommandRouter::volumioRetrievevolume Feb 18 23:43:30 volumio volumio[11106]: info: VolumeController:: Volume=100 Mute =false Feb 18 23:43:30 volumio volumio[11106]: info: CoreCommandRouter::volumioGetState Feb 18 23:43:30 volumio volumio[11106]: info: CorePlayQueue::getTrack 0 Feb 18 23:43:30 volumio volumio[11106]: info: CoreStateMachine::pushState Feb 18 23:43:30 volumio volumio[11106]: info: CorePlayQueue::getTrack 0 Feb 18 23:43:30 volumio volumio[11106]: info: CoreCommandRouter::volumioPushState Feb 18 23:43:31 volumio mpd[11332]: 2026-02-18T23:43:31 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 18 23:43:31 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Feb 18 23:43:31 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 18 23:43:31 volumio sudo[11292]: pam_unix(sudo:session): session closed for user root Feb 18 23:43:31 volumio sudo[11304]: pam_unix(sudo:session): session closed for user root Feb 18 23:43:31 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 23:43:31 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 23:43:31 volumio go-librespot[11431]: go-librespot daemon starting... Feb 18 23:43:31 volumio go-librespot[11434]: time="2026-02-18T23:43:31+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 23:43:31 volumio go-librespot[11434]: time="2026-02-18T23:43:31+07:00" level=debug msg="app state loaded" Feb 18 23:43:31 volumio go-librespot[11434]: time="2026-02-18T23:43:31+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 23:43:32 volumio volumio[11106]: error: MPD error: The expression evaluated to a falsy value: Feb 18 23:43:32 volumio volumio[11106]: assert.ok(self.idling) Feb 18 23:43:32 volumio volumio[11106]: error: The expression evaluated to a falsy value: Feb 18 23:43:32 volumio volumio[11106]: assert.ok(self.idling) Feb 18 23:43:32 volumio volumio[11106]: info: go-librespot daemon successfully initialized Feb 18 23:43:32 volumio volumio[11106]: info: MPD running with PID11332 Feb 18 23:43:32 volumio volumio[11106]: ,establishing connection Feb 18 23:43:32 volumio volumio[11106]: error: updateQueue error: null Feb 18 23:43:32 volumio volumio[11106]: info: Completed starting Core Plugins Feb 18 23:43:32 volumio volumio[11106]: info: ------------------------------------------- Feb 18 23:43:32 volumio volumio[11106]: info: ----- MyVolumio plugins startup ---- Feb 18 23:43:32 volumio volumio[11106]: info: ------------------------------------------- Feb 18 23:43:32 volumio volumio[11106]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 18 23:43:32 volumio volumio[11106]: error: updateQueue error: null Feb 18 23:43:32 volumio go-librespot[11434]: time="2026-02-18T23:43:32+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 23:43:32 volumio go-librespot[11434]: time="2026-02-18T23:43:32+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 18 23:43:32 volumio go-librespot[11434]: time="2026-02-18T23:43:32+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 18 23:43:32 volumio go-librespot[11434]: time="2026-02-18T23:43:32+07:00" level=info msg="zeroconf server listening on port 42107" Feb 18 23:43:32 volumio go-librespot[11434]: time="2026-02-18T23:43:32+07:00" level=debug msg="obtained new client token: AADje9AQRFrBqwWjcgJArguxT1zqrN3y2yRjPKZcLu7BNDeFA9QUSfCW8N252zYv4mqOxiAPkkyTIz8EtdeoHKh5Oqz727nIJCzzsxX+Bg2S46oNuDW5F4p0zdL1bTyARyrEyQ/jMpARJt/DHCJrwDFDq3fRVhS4VjwO8DzscKwaDwMbFuRpu/r2VlF9Jj2dD1PpEuZfbTKgnufyDvZkfpHTGf1MGeHuBxKCPVHMvcjihnh1g1/fzLXa4A==" Feb 18 23:43:32 volumio go-librespot[11434]: time="2026-02-18T23:43:32+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 23:43:32 volumio go-librespot[11434]: time="2026-02-18T23:43:32+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:43:32 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 23:43:32 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 23:43:35 volumio volumio[11106]: info: Initializing connection to go-librespot Websocket Feb 18 23:43:35 volumio volumio[11106]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 18 23:43:36 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Feb 18 23:43:36 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 23:43:36 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 23:43:36 volumio go-librespot[11443]: go-librespot daemon starting... Feb 18 23:43:36 volumio go-librespot[11444]: time="2026-02-18T23:43:36+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 23:43:36 volumio go-librespot[11444]: time="2026-02-18T23:43:36+07:00" level=debug msg="app state loaded" Feb 18 23:43:36 volumio go-librespot[11444]: time="2026-02-18T23:43:36+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 23:43:36 volumio go-librespot[11444]: time="2026-02-18T23:43:36+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 18 23:43:36 volumio go-librespot[11444]: time="2026-02-18T23:43:36+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 18 23:43:36 volumio go-librespot[11444]: time="2026-02-18T23:43:36+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 18 23:43:36 volumio go-librespot[11444]: time="2026-02-18T23:43:36+07:00" level=info msg="zeroconf server listening on port 39299" Feb 18 23:43:36 volumio go-librespot[11444]: time="2026-02-18T23:43:36+07:00" level=debug msg="obtained new client token: AAD17S2jDLYMQ2jAXS6T/XFhwhT9C9z2uLt1eG470K+iM3MuvN41c+O8zDpTjLjuSreLnW2N4H+q3aYSXqIXb178dGrOx18BQXAVTnuoazeHGgVvd+0SGlbCNHqRlbVolTuUESWHs8FyYsu06nv78Kn7yU8WZ854nZIeMJ6x9zdLWoPVGbReIm/IAygSJS7s38p5j8r0Lja47BBrROd5tqwXUFS5JSngca276I6yEQX0UJHqlMDMKc37Og==" Feb 18 23:43:36 volumio volumio[11106]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 18 23:43:36 volumio go-librespot[11444]: time="2026-02-18T23:43:36+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 23:43:37 volumio go-librespot[11444]: time="2026-02-18T23:43:37+07:00" level=debug msg="completed keyexchange" Feb 18 23:43:37 volumio go-librespot[11444]: time="2026-02-18T23:43:37+07:00" level=debug msg="completed challenge" Feb 18 23:43:37 volumio go-librespot[11444]: time="2026-02-18T23:43:37+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 18 23:43:37 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 23:43:37 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 23:43:38 volumio volumio[11106]: info: Initializing connection to go-librespot Websocket Feb 18 23:43:38 volumio volumio[11106]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 18 23:43:40 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Feb 18 23:43:40 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 23:43:40 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 23:43:40 volumio go-librespot[11452]: go-librespot daemon starting... Feb 18 23:43:40 volumio go-librespot[11453]: time="2026-02-18T23:43:40+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 23:43:40 volumio go-librespot[11453]: time="2026-02-18T23:43:40+07:00" level=debug msg="app state loaded" Feb 18 23:43:40 volumio go-librespot[11453]: time="2026-02-18T23:43:40+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 23:43:40 volumio go-librespot[11453]: time="2026-02-18T23:43: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-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 23:43:40 volumio go-librespot[11453]: time="2026-02-18T23:43:40+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:43:40 volumio go-librespot[11453]: time="2026-02-18T23:43:40+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:43:40 volumio go-librespot[11453]: time="2026-02-18T23:43:40+07:00" level=info msg="zeroconf server listening on port 39325" Feb 18 23:43:40 volumio volumio[11106]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 18 23:43:40 volumio volumio[11106]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 18 23:43:40 volumio volumio[11106]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 18 23:43:40 volumio volumio[11106]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 18 23:43:40 volumio volumio[11106]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 18 23:43:40 volumio volumio[11106]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 18 23:43:40 volumio volumio[11106]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 18 23:43:40 volumio volumio[11106]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 18 23:43:40 volumio volumio[11106]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 18 23:43:40 volumio volumio[11106]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 18 23:43:40 volumio volumio[11106]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 18 23:43:40 volumio volumio[11106]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 18 23:43:40 volumio volumio[11106]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 18 23:43:40 volumio volumio[11106]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 18 23:43:40 volumio volumio[11106]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 18 23:43:40 volumio volumio[11106]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 18 23:43:40 volumio volumio[11106]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 18 23:43:40 volumio volumio[11106]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 18 23:43:40 volumio volumio[11106]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 18 23:43:40 volumio volumio[11106]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 18 23:43:40 volumio volumio[11106]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 18 23:43:40 volumio volumio[11106]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 18 23:43:40 volumio volumio[11106]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 18 23:43:40 volumio volumio[11106]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 18 23:43:40 volumio volumio[11106]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 18 23:43:40 volumio volumio[11106]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 18 23:43:40 volumio volumio[11106]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 18 23:43:40 volumio volumio[11106]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 18 23:43:40 volumio volumio[11106]: info: Adding plugin bluetooth to MyMusic Plugins Feb 18 23:43:41 volumio volumio[11106]: info: Adding plugin multiroom to MyMusic Plugins Feb 18 23:43:41 volumio volumio[11106]: info: Adding plugin metavolumio to MyMusic Plugins Feb 18 23:43:41 volumio volumio[11106]: info: Adding plugin cd_controller to MyMusic Plugins Feb 18 23:43:41 volumio volumio[11106]: info: Adding plugin qobuzconnect to MyMusic Plugins Feb 18 23:43:41 volumio volumio[11106]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 18 23:43:41 volumio volumio[11106]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 18 23:43:41 volumio volumio[11106]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 18 23:43:41 volumio go-librespot[11453]: time="2026-02-18T23:43:41+07:00" level=debug msg="obtained new client token: AAAjMEMm4vcJXROGeUMvVYi5GLQEtWs/v/kR1oZwE4h7So5qxevYMEPfsLgsBsTtMKQ+akMvsv7uCqJP4X+Dqvfow2vrkM1g8ryssQWAQRiCU0CFQDurkAx06T4leIL6Q2GlmjqiJ56+ADGzjv85W8bdhpwnx1nXezFKW6Sc6WToA5tQ3jN3sa+I6SwCNbOfiy/95NG2xsR/b/IImpO7B1MYu/Na1XyZzXrrD/y8i4s57CiS7EuOTqY=" Feb 18 23:43:41 volumio go-librespot[11453]: time="2026-02-18T23:43:41+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 23:43:41 volumio go-librespot[11453]: time="2026-02-18T23:43:41+07:00" level=debug msg="completed keyexchange" Feb 18 23:43:41 volumio go-librespot[11453]: time="2026-02-18T23:43:41+07:00" level=debug msg="completed challenge" Feb 18 23:43:41 volumio go-librespot[11453]: time="2026-02-18T23:43:41+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 18 23:43:41 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 23:43:41 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 23:43:42 volumio volumio[11106]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 18 23:43:42 volumio volumio[11106]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 18 23:43:42 volumio volumio[11106]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 23:43:42 volumio volumio[11106]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 23:43:42 volumio volumio[11106]: info: Starting MyVolumio Remote Streaming Endpoints Feb 18 23:43:42 volumio volumio[11106]: info: MyVolumio login type: Token Feb 18 23:43:42 volumio volumio[11106]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 18 23:43:42 volumio volumio[11106]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 18 23:43:44 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Feb 18 23:43:44 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 23:43:44 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 23:43:44 volumio go-librespot[11474]: go-librespot daemon starting... Feb 18 23:43:44 volumio go-librespot[11475]: time="2026-02-18T23:43:44+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 23:43:44 volumio go-librespot[11475]: time="2026-02-18T23:43:44+07:00" level=debug msg="app state loaded" Feb 18 23:43:44 volumio go-librespot[11475]: time="2026-02-18T23:43:44+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 23:43:44 volumio volumio[11106]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 18 23:43:44 volumio volumio[11106]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 18 23:43:44 volumio volumio[11106]: info: Streaming services startup Feb 18 23:43:44 volumio volumio[11106]: info: Starting Streaming Daemon Feb 18 23:43:44 volumio sudo[11482]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 18 23:43:44 volumio sudo[11482]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 23:43:44 volumio volumio[11106]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 18 23:43:44 volumio sudo[11482]: pam_unix(sudo:session): session closed for user root Feb 18 23:43:44 volumio volumio[11106]: info: Initializing connection to go-librespot Websocket Feb 18 23:43:44 volumio volumio[11106]: error: Cannot start Volumio Streaming Daemon Feb 18 23:43:44 volumio volumio[11106]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 18 23:43:44 volumio volumio[11106]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 18 23:43:44 volumio go-librespot[11475]: time="2026-02-18T23:43:44+07:00" level=debug msg="new websocket client" Feb 18 23:43:44 volumio volumio[11106]: info: Connection to go-librespot Websocket established Feb 18 23:43:45 volumio go-librespot[11475]: time="2026-02-18T23:43:45+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 23:43:45 volumio go-librespot[11475]: time="2026-02-18T23:43:45+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:43:45 volumio go-librespot[11475]: time="2026-02-18T23:43:45+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:43:45 volumio go-librespot[11475]: time="2026-02-18T23:43:45+07:00" level=info msg="zeroconf server listening on port 42887" Feb 18 23:43:45 volumio go-librespot[11475]: time="2026-02-18T23:43:45+07:00" level=debug msg="obtained new client token: AADRH0oQcCQNyQ5gvIzFVBIVtIJnLSoWKh3Vk2c1b1nPtqbg/RBb6POjtIn5wDbnangW+90isU3qXy17P+CrwmjQAnxtzgM0TXjamu79Ontw2yPUYOfZ0jaFpYtaf7DNYqKCmfy6C3uQxspfG+T7IfaVgU9dU83GGdM4J8ipLB/AFbj4LWIqOqu7Mb0f8Q2k1oQjGBPkt69ukdeHU6CPWbsmi8eOxc3USe7f/qPqQ93Jfe9C5wk9YP9y6Q==" Feb 18 23:43:45 volumio go-librespot[11475]: time="2026-02-18T23:43:45+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 23:43:45 volumio go-librespot[11475]: time="2026-02-18T23:43: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:43:45 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 23:43:45 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 23:43:45 volumio volumio[11106]: info: Connection to go-librespot Websocket closed Feb 18 23:43:45 volumio volumio[11106]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Feb 18 23:43:47 volumio volumio[11106]: info: MyVolumio token set successfully Feb 18 23:43:47 volumio volumio[11106]: info: MYVOLUMIO: Adding device Feb 18 23:43:47 volumio volumio[11106]: info: MYVOLUMIO: Evaluating Server Feb 18 23:43:47 volumio volumio[11106]: info: MyVolumio status changed Feb 18 23:43:47 volumio volumio[11106]: info: Streaming services startup Feb 18 23:43:47 volumio volumio[11106]: info: Starting Streaming Daemon Feb 18 23:43:47 volumio volumio[11106]: info: Removing browser output: myVolumio user plan is not superstar Feb 18 23:43:47 volumio volumio[11106]: info: Removing audio output: Feb 18 23:43:47 volumio volumio[11106]: info: Stoppping Tunnel 1 Feb 18 23:43:47 volumio sudo[11510]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 18 23:43:47 volumio sudo[11510]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 23:43:47 volumio sudo[11510]: pam_unix(sudo:session): session closed for user root Feb 18 23:43:47 volumio sudo[11513]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Feb 18 23:43:47 volumio sudo[11513]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 23:43:47 volumio volumio[11106]: error: Cannot start Volumio Streaming Daemon Feb 18 23:43:47 volumio volumio[11106]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 18 23:43:47 volumio volumio[11106]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 18 23:43:47 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:43:47 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:43:47 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:43:47 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:43:47 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:43:47 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:43:47 volumio volumio[11106]: info: Setting Geolocation for MyVolumio to as1 Feb 18 23:43:47 volumio volumio[11106]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 23:43:47 volumio volumio[11106]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 23:43:47 volumio volumio[11106]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 23:43:47 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:43:47 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:43:47 volumio sudo[11513]: pam_unix(sudo:session): session closed for user root Feb 18 23:43:47 volumio volumio[11106]: info: Remote SSH Stopped Feb 18 23:43:48 volumio volumio[11106]: info: Getting Spotify volume Feb 18 23:43:48 volumio volumio[11106]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 18 23:43:48 volumio volumio[11106]: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 18 23:43:48 volumio volumio[11106]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Feb 18 23:43:48 volumio volumio[11106]: errno: -111, Feb 18 23:43:48 volumio volumio[11106]: code: 'ECONNREFUSED', Feb 18 23:43:48 volumio volumio[11106]: syscall: 'connect', Feb 18 23:43:48 volumio volumio[11106]: address: '127.0.0.1', Feb 18 23:43:48 volumio volumio[11106]: port: 9879, Feb 18 23:43:48 volumio volumio[11106]: response: undefined Feb 18 23:43:48 volumio volumio[11106]: } Feb 18 23:43:48 volumio volumio[11106]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 18 23:43:48 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Feb 18 23:43:48 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 23:43:48 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 23:43:48 volumio go-librespot[11527]: go-librespot daemon starting... Feb 18 23:43:48 volumio go-librespot[11528]: time="2026-02-18T23:43:48+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 23:43:48 volumio go-librespot[11528]: time="2026-02-18T23:43:48+07:00" level=debug msg="app state loaded" Feb 18 23:43:48 volumio go-librespot[11528]: time="2026-02-18T23:43:48+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 23:43:49 volumio go-librespot[11528]: time="2026-02-18T23:43:49+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 23:43:49 volumio go-librespot[11528]: time="2026-02-18T23:43:49+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 18 23:43:49 volumio go-librespot[11528]: time="2026-02-18T23:43:49+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 18 23:43:49 volumio go-librespot[11528]: time="2026-02-18T23:43:49+07:00" level=info msg="zeroconf server listening on port 41963" Feb 18 23:43:49 volumio sudo[11537]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-18 23:42' Feb 18 23:43:49 volumio sudo[11537]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 23:43:49 volumio go-librespot[11528]: time="2026-02-18T23:43:49+07:00" level=debug msg="obtained new client token: AACP8/v2BLVlVzcmMmJiqTAe3bU51D2sAmDRpSQGk03aESX2MUQCbgydfWvCp3wLakP+1OFFRT3k8PV0+I1u1M3rm5osl/cadMdEyLOtqmermYIgZNwxNzA1xZtusJxXnq/Voq3N0FQOUMgaOGzQWxzGtLsAowNIQVyl8pB/U5C9QRqjcB5BbFFn+T2IaoN+QGdQGrYdfvU1DItsYSighwt1gkiOW8WR+hWfGavZBWv4vO1tCtfIM3jdFw==" Feb 18 23:43:49 volumio go-librespot[11528]: time="2026-02-18T23:43:49+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" 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"