Feb 12 01:02:00 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Feb 12 01:02:00 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 01:02:00 volumio volumio[14768]: 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 12 01:02:00 volumio volumio[14768]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 01:02:00 volumio volumio[14768]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 01:02:00 volumio volumio[14768]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 01:02:00 volumio volumio[14768]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 01:02:00 volumio volumio[14768]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 01:02:00 volumio volumio[14768]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 01:02:00 volumio volumio[14768]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 01:02:00 volumio volumio[14768]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 01:02:00 volumio volumio[14768]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 01:02:00 volumio volumio[14768]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 01:02:00 volumio volumio[14768]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 01:02:00 volumio volumio[14768]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 01:02:00 volumio volumio[14768]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 01:02:00 volumio volumio[14768]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 01:02:00 volumio volumio[14768]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 01:02:00 volumio volumio[14768]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 01:02:00 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 01:02:00 volumio volumio[14768]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 01:02:00 volumio volumio[14768]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 01:02:00 volumio go-librespot[15012]: go-librespot daemon starting... Feb 12 01:02:00 volumio sudo[15010]: pam_unix(sudo:session): session closed for user root Feb 12 01:02:00 volumio volumio[14768]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 01:02:00 volumio volumio[14768]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 01:02:00 volumio volumio[14768]: info: No need to fix Spotify hosts Feb 12 01:02:00 volumio go-librespot[15019]: time="2026-02-12T01:02:00+07:00" level=info msg="running go-librespot 0.4.0" Feb 12 01:02:00 volumio go-librespot[15019]: time="2026-02-12T01:02:00+07:00" level=debug msg="app state loaded" Feb 12 01:02:00 volumio go-librespot[15019]: time="2026-02-12T01:02:00+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 01:02:00 volumio go-librespot[15019]: time="2026-02-12T01:02: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-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 12 01:02:00 volumio go-librespot[15019]: time="2026-02-12T01:02:00+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 12 01:02:00 volumio go-librespot[15019]: time="2026-02-12T01:02:00+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 12 01:02:00 volumio go-librespot[15019]: time="2026-02-12T01:02:00+07:00" level=info msg="zeroconf server listening on port 36623" Feb 12 01:02:01 volumio volumio[14768]: info: Volumio called home Feb 12 01:02:01 volumio volumio[14768]: info: Starting Shairport Sync Feb 12 01:02:01 volumio volumio[14768]: info: Starting Shairport Sync Feb 12 01:02:01 volumio volumio[14768]: info: Starting Shairport Sync Feb 12 01:02:01 volumio go-librespot[15019]: time="2026-02-12T01:02:01+07:00" level=debug msg="obtained new client token: AACYQ7K0KULZQlgLQpgR8sV7JqRMwwd5/rw6KdFl8FDrUeFkI1LpHgxYqGDZwUiiEx5QEwJjLNCreE2GxBneSrnxwifsGdiqVkgaVnQDBIwEVDkqe7+YzTIVQ7VyF3CpLLX7lRN4a/X6tJ4GguOFLNLlhn2m2DRoMcDCBnH8QSacuG+O3MEp3IYwal8CJy4WTR+L2C1kAqWMbT7Njs4RV25CuMZ7zQ9/zEzuMZVR6KUlJYuLA4JoXIo=" Feb 12 01:02:01 volumio sudo[15044]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 12 01:02:01 volumio sudo[15044]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 01:02:01 volumio sudo[15046]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 12 01:02:01 volumio sudo[15046]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 01:02:01 volumio go-librespot[15019]: time="2026-02-12T01:02:01+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 12 01:02:01 volumio sudo[15048]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 12 01:02:01 volumio sudo[15048]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 01:02:01 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 12 01:02:01 volumio go-librespot[15019]: time="2026-02-12T01:02:01+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Feb 12 01:02:01 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 12 01:02:01 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 12 01:02:01 volumio systemd[1]: shairport-sync.service: Consumed 2.309s CPU time. Feb 12 01:02:01 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 12 01:02:01 volumio volumio[14768]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 12 01:02:01 volumio volumio[14768]: SPOTIFY: BQBZSwe72T5em2Y3lSfO99vD4djr2k6W8zHzI-Tg0XKehAbHH8X-ARpCDDctSFenfs1ZOFSnP4r4sGH58gInaWAXN0B4lnuWlVBwhN93TGXi3E3gHBKWLp96HCH_y_kgZUrYN50TWVVMa1VLNazi1vm8c_pW37fd_TzY-2H7rUlLJMMCQ7H-fyxi9fgDncyS_4qYF9KzYaiq96_Dm_wrstqXtd1GXHB8EK3LzXJ5NQ3vQUoFALj-TX0LPX_CresRi8o4bKqULXrzWd04aMbP13-w11oAmqYhSi4RurTSRfV1b1-1Ov1jQBf4 Feb 12 01:02:01 volumio volumio[14768]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 12 01:02:01 volumio volumio[14768]: info: New Spotify access token = BQBZSwe72T5em2Y3lSfO99vD4djr2k6W8zHzI-Tg0XKehAbHH8X-ARpCDDctSFenfs1ZOFSnP4r4sGH58gInaWAXN0B4lnuWlVBwhN93TGXi3E3gHBKWLp96HCH_y_kgZUrYN50TWVVMa1VLNazi1vm8c_pW37fd_TzY-2H7rUlLJMMCQ7H-fyxi9fgDncyS_4qYF9KzYaiq96_Dm_wrstqXtd1GXHB8EK3LzXJ5NQ3vQUoFALj-TX0LPX_CresRi8o4bKqULXrzWd04aMbP13-w11oAmqYhSi4RurTSRfV1b1-1Ov1jQBf4 Feb 12 01:02:01 volumio volumio[14768]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 12 01:02:01 volumio go-librespot[15019]: time="2026-02-12T01:02:01+07:00" level=debug msg="completed keyexchange" Feb 12 01:02:01 volumio go-librespot[15019]: time="2026-02-12T01:02:01+07:00" level=debug msg="completed challenge" Feb 12 01:02:01 volumio sudo[15044]: pam_unix(sudo:session): session closed for user root Feb 12 01:02:01 volumio go-librespot[15019]: time="2026-02-12T01:02: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 12 01:02:01 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 12 01:02:01 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 12 01:02:01 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 12 01:02:01 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 12 01:02:01 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 12 01:02:01 volumio volumio[14768]: info: Shairport-Sync Started Feb 12 01:02:01 volumio volumio[14768]: Error adding Membership: Error: addMembership EINVAL Feb 12 01:02:01 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 12 01:02:01 volumio volumio[14768]: info: CoreCommandRouter::volumioGetState Feb 12 01:02:01 volumio volumio[14768]: info: CorePlayQueue::getTrack 0 Feb 12 01:02:01 volumio sudo[15046]: pam_unix(sudo:session): session closed for user root Feb 12 01:02:01 volumio sudo[15048]: pam_unix(sudo:session): session closed for user root Feb 12 01:02:02 volumio volumio[14768]: info: Shairport-Sync Started Feb 12 01:02:02 volumio volumio[14768]: info: Shairport-Sync Started Feb 12 01:02:02 volumio volumio[14768]: 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 12 01:02:02 volumio volumio[14768]: info: Spotify Successfully logged in Feb 12 01:02:02 volumio volumio[14768]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 12 01:02:02 volumio volumio[14768]: info: [1770832922260] CoreMusicLibrary::Adding element Spotify Feb 12 01:02:02 volumio volumio[14768]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 12 01:02:02 volumio volumio[14768]: Cannot find translation for source YouTube Music Feb 12 01:02:02 volumio volumio[14768]: Cannot find translation for source Spotify Feb 12 01:02:02 volumio volumio[14768]: info: [yt-cast-receiver] DIAL server listening on port 8098 Feb 12 01:02:02 volumio volumio[14768]: info: CoreCommandRouter::volumioRetrievevolume Feb 12 01:02:03 volumio volumio[14768]: info: VolumeController:: Volume=100 Mute =false Feb 12 01:02:03 volumio volumio[14768]: info: CoreCommandRouter::volumioGetState Feb 12 01:02:03 volumio volumio[14768]: info: CorePlayQueue::getTrack 0 Feb 12 01:02:03 volumio volumio[14768]: info: CoreStateMachine::pushState Feb 12 01:02:03 volumio volumio[14768]: info: CorePlayQueue::getTrack 0 Feb 12 01:02:03 volumio volumio[14768]: info: CoreCommandRouter::volumioPushState Feb 12 01:02:04 volumio volumio[14768]: info: go-librespot daemon successfully initialized Feb 12 01:02:04 volumio mpd[14994]: 2026-02-12T01:02:04 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 12 01:02:04 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 12 01:02:04 volumio sudo[14947]: pam_unix(sudo:session): session closed for user root Feb 12 01:02:04 volumio sudo[14957]: pam_unix(sudo:session): session closed for user root Feb 12 01:02:04 volumio volumio[14768]: error: MPD error: The expression evaluated to a falsy value: Feb 12 01:02:04 volumio volumio[14768]: assert.ok(self.idling) Feb 12 01:02:04 volumio volumio[14768]: error: The expression evaluated to a falsy value: Feb 12 01:02:04 volumio volumio[14768]: assert.ok(self.idling) Feb 12 01:02:04 volumio volumio[14768]: error: updateQueue error: null Feb 12 01:02:04 volumio volumio[14768]: info: MPD running with PID14994 Feb 12 01:02:04 volumio volumio[14768]: ,establishing connection Feb 12 01:02:04 volumio volumio[14768]: info: Completed starting Core Plugins Feb 12 01:02:04 volumio volumio[14768]: info: ------------------------------------------- Feb 12 01:02:04 volumio volumio[14768]: info: ----- MyVolumio plugins startup ---- Feb 12 01:02:04 volumio volumio[14768]: info: ------------------------------------------- Feb 12 01:02:04 volumio volumio[14768]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 12 01:02:04 volumio volumio[14768]: error: updateQueue error: null Feb 12 01:02:04 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Feb 12 01:02:04 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 01:02:04 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 01:02:04 volumio go-librespot[15101]: go-librespot daemon starting... Feb 12 01:02:04 volumio go-librespot[15102]: time="2026-02-12T01:02:04+07:00" level=info msg="running go-librespot 0.4.0" Feb 12 01:02:04 volumio go-librespot[15102]: time="2026-02-12T01:02:04+07:00" level=debug msg="app state loaded" Feb 12 01:02:04 volumio go-librespot[15102]: time="2026-02-12T01:02:04+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 01:02:05 volumio go-librespot[15102]: time="2026-02-12T01:02:05+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 12 01:02:05 volumio go-librespot[15102]: time="2026-02-12T01:02:05+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 12 01:02:05 volumio go-librespot[15102]: time="2026-02-12T01:02:05+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 12 01:02:05 volumio go-librespot[15102]: time="2026-02-12T01:02:05+07:00" level=info msg="zeroconf server listening on port 40593" Feb 12 01:02:05 volumio go-librespot[15102]: time="2026-02-12T01:02:05+07:00" level=debug msg="obtained new client token: AADbTBadkatdWKLoyory2QG35yrzyuXNq2fwOIxY50V2l6TUXmrCRPYuFO+MgRqsUujAC1WGLdh442GtF7jOdPW0uHbRYSwPo6hcemyevx4cFcfOS7D+127R/q62dgMG/KrJTrxKK1PbpBFKsWiZpvKWe86foDa/avj7tDpq1vfZ57Oq+2hcW3v9p28+Nu+UqnIaYdygAmNBtTo4OcJi/HduIN6skM/9+N4Uf82PI+d5tp/GsjCwvFHoqQ==" Feb 12 01:02:05 volumio go-librespot[15102]: time="2026-02-12T01:02:05+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 12 01:02:05 volumio go-librespot[15102]: time="2026-02-12T01:02: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 12 01:02:05 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 12 01:02:05 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 12 01:02:07 volumio volumio[14768]: info: Initializing connection to go-librespot Websocket Feb 12 01:02:07 volumio volumio[14768]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 12 01:02:08 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Feb 12 01:02:08 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 01:02:08 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 01:02:08 volumio go-librespot[15110]: go-librespot daemon starting... Feb 12 01:02:08 volumio go-librespot[15111]: time="2026-02-12T01:02:08+07:00" level=info msg="running go-librespot 0.4.0" Feb 12 01:02:08 volumio go-librespot[15111]: time="2026-02-12T01:02:08+07:00" level=debug msg="app state loaded" Feb 12 01:02:08 volumio go-librespot[15111]: time="2026-02-12T01:02:08+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 01:02:09 volumio go-librespot[15111]: time="2026-02-12T01:02: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-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 12 01:02:09 volumio go-librespot[15111]: time="2026-02-12T01:02:09+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 12 01:02:09 volumio go-librespot[15111]: time="2026-02-12T01:02:09+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 12 01:02:09 volumio go-librespot[15111]: time="2026-02-12T01:02:09+07:00" level=info msg="zeroconf server listening on port 44721" Feb 12 01:02:09 volumio volumio[14768]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 12 01:02:09 volumio go-librespot[15111]: time="2026-02-12T01:02:09+07:00" level=debug msg="obtained new client token: AAAOFxuKSIPsryG9VneF677mmIlkP9qSX/mRsi6WxvQEsIEhAdWWJlik0KkityKqb+0F4CtGY0o9Mx8lxiLsqejtHMAC2e0MThIU23W7eFHxWGNumcOHE4o1SWRCGXT3K7mmoDsj7DbsQEz0xzxCEiaCUJbVrCXNk1BdqXTPlMon/dxey0xdEwIiiNNET8pVW1JOu58VyvtlbsSrVEqGIodbazJ0qzZHYhElh5yovpl6dt86PEb7SwZAcg==" Feb 12 01:02:09 volumio go-librespot[15111]: time="2026-02-12T01:02:09+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 12 01:02:09 volumio go-librespot[15111]: time="2026-02-12T01:02:09+07:00" level=debug msg="completed keyexchange" Feb 12 01:02:09 volumio go-librespot[15111]: time="2026-02-12T01:02:09+07:00" level=debug msg="completed challenge" Feb 12 01:02:09 volumio go-librespot[15111]: time="2026-02-12T01:02: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 12 01:02:10 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 12 01:02:10 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 12 01:02:10 volumio volumio[14768]: info: Initializing connection to go-librespot Websocket Feb 12 01:02:10 volumio volumio[14768]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 12 01:02:13 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Feb 12 01:02:13 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 01:02:13 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 01:02:13 volumio go-librespot[15118]: go-librespot daemon starting... Feb 12 01:02:13 volumio go-librespot[15119]: time="2026-02-12T01:02:13+07:00" level=info msg="running go-librespot 0.4.0" Feb 12 01:02:13 volumio go-librespot[15119]: time="2026-02-12T01:02:13+07:00" level=debug msg="app state loaded" Feb 12 01:02:13 volumio go-librespot[15119]: time="2026-02-12T01:02:13+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 01:02:13 volumio volumio[14768]: info: Initializing connection to go-librespot Websocket Feb 12 01:02:13 volumio go-librespot[15119]: time="2026-02-12T01:02:13+07:00" level=debug msg="new websocket client" Feb 12 01:02:13 volumio volumio[14768]: info: Connection to go-librespot Websocket established Feb 12 01:02:13 volumio go-librespot[15119]: time="2026-02-12T01:02: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 12 01:02:13 volumio go-librespot[15119]: time="2026-02-12T01:02: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 12 01:02:13 volumio go-librespot[15119]: time="2026-02-12T01:02: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 12 01:02:13 volumio volumio[14768]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 12 01:02:13 volumio volumio[14768]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 12 01:02:13 volumio volumio[14768]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 12 01:02:13 volumio volumio[14768]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 12 01:02:13 volumio volumio[14768]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 12 01:02:13 volumio volumio[14768]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 12 01:02:13 volumio volumio[14768]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 12 01:02:13 volumio volumio[14768]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 12 01:02:13 volumio volumio[14768]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 12 01:02:13 volumio volumio[14768]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 12 01:02:13 volumio volumio[14768]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 12 01:02:13 volumio volumio[14768]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 12 01:02:13 volumio volumio[14768]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 12 01:02:13 volumio volumio[14768]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 12 01:02:13 volumio volumio[14768]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 12 01:02:13 volumio volumio[14768]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 12 01:02:13 volumio volumio[14768]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 12 01:02:13 volumio go-librespot[15119]: time="2026-02-12T01:02:13+07:00" level=info msg="zeroconf server listening on port 44265" Feb 12 01:02:13 volumio volumio[14768]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 12 01:02:13 volumio volumio[14768]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 12 01:02:13 volumio volumio[14768]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 12 01:02:13 volumio volumio[14768]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 12 01:02:13 volumio volumio[14768]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 12 01:02:13 volumio volumio[14768]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 12 01:02:13 volumio volumio[14768]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 12 01:02:13 volumio volumio[14768]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 12 01:02:13 volumio volumio[14768]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 12 01:02:13 volumio volumio[14768]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 12 01:02:13 volumio volumio[14768]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 12 01:02:13 volumio volumio[14768]: info: Adding plugin bluetooth to MyMusic Plugins Feb 12 01:02:13 volumio volumio[14768]: info: Adding plugin multiroom to MyMusic Plugins Feb 12 01:02:13 volumio volumio[14768]: info: Adding plugin metavolumio to MyMusic Plugins Feb 12 01:02:13 volumio volumio[14768]: info: Adding plugin cd_controller to MyMusic Plugins Feb 12 01:02:13 volumio volumio[14768]: info: Adding plugin qobuzconnect to MyMusic Plugins Feb 12 01:02:13 volumio volumio[14768]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 12 01:02:13 volumio volumio[14768]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 12 01:02:13 volumio volumio[14768]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 12 01:02:13 volumio go-librespot[15119]: time="2026-02-12T01:02:13+07:00" level=debug msg="obtained new client token: AAD63pd+2Bong+Kcc5Lvu8EEDHWKWb48D8SLgd1XRPAaBs4Ou3Z3MJwAG/POfpWtBivQdBCp5ewNRrN3/YNdpahTceQqDTY4NkulkC/HpAttg0g1qGnKX/LECgXj+ZrLdVasfRIEbzS2/SUCbtfboLXQt/V15gkZy4K/uA6To3VXyU6lKxzLt1FH3DCwyQh9sjTAE0578jmgG8WzO+Do3+TFU2hmlSIp4Xz0qa5iE8UAoQnOoULjXqdIDw==" Feb 12 01:02:14 volumio go-librespot[15119]: time="2026-02-12T01:02:14+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 12 01:02:14 volumio go-librespot[15119]: time="2026-02-12T01:02:14+07:00" level=debug msg="completed keyexchange" Feb 12 01:02:14 volumio go-librespot[15119]: time="2026-02-12T01:02:14+07:00" level=debug msg="completed challenge" Feb 12 01:02:14 volumio go-librespot[15119]: time="2026-02-12T01:02:14+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 12 01:02:14 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 12 01:02:14 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 12 01:02:15 volumio volumio[14768]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 12 01:02:15 volumio volumio[14768]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 12 01:02:15 volumio volumio[14768]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 01:02:15 volumio volumio[14768]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 01:02:15 volumio volumio[14768]: info: Starting MyVolumio Remote Streaming Endpoints Feb 12 01:02:15 volumio volumio[14768]: info: MyVolumio login type: Token Feb 12 01:02:15 volumio volumio[14768]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 12 01:02:15 volumio volumio[14768]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 12 01:02:17 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Feb 12 01:02:17 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 01:02:17 volumio volumio[14768]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 12 01:02:17 volumio volumio[14768]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 12 01:02:17 volumio volumio[14768]: info: Streaming services startup Feb 12 01:02:17 volumio volumio[14768]: info: Starting Streaming Daemon Feb 12 01:02:17 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 01:02:17 volumio go-librespot[15142]: go-librespot daemon starting... Feb 12 01:02:17 volumio sudo[15144]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 12 01:02:17 volumio sudo[15144]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 01:02:17 volumio volumio[14768]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 12 01:02:17 volumio go-librespot[15146]: time="2026-02-12T01:02:17+07:00" level=info msg="running go-librespot 0.4.0" Feb 12 01:02:17 volumio go-librespot[15146]: time="2026-02-12T01:02:17+07:00" level=debug msg="app state loaded" Feb 12 01:02:17 volumio go-librespot[15146]: time="2026-02-12T01:02:17+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 01:02:17 volumio sudo[15144]: pam_unix(sudo:session): session closed for user root Feb 12 01:02:17 volumio volumio[14768]: info: Getting Spotify volume Feb 12 01:02:17 volumio volumio[14768]: info: Connection to go-librespot Websocket closed Feb 12 01:02:17 volumio volumio[14768]: error: Cannot start Volumio Streaming Daemon Feb 12 01:02:17 volumio volumio[14768]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 12 01:02:17 volumio volumio[14768]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 12 01:02:17 volumio volumio[14768]: 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 12 01:02:17 volumio volumio[14768]: info: CoreCommandRouter::volumioGetState Feb 12 01:02:17 volumio volumio[14768]: info: CorePlayQueue::getTrack 0 Feb 12 01:02:17 volumio volumio[14768]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Feb 12 01:02:17 volumio volumio[14768]: SPOTIFY: SPOTIFY VOLUME undefined Feb 12 01:02:17 volumio volumio[14768]: SPOTIFY: VOLUMIO VOLUME 100 Feb 12 01:02:17 volumio volumio[14768]: info: Aligning Spotify Volume to Volumio Volume Feb 12 01:02:17 volumio volumio[14768]: info: CoreCommandRouter::volumioGetState Feb 12 01:02:17 volumio volumio[14768]: info: CorePlayQueue::getTrack 0 Feb 12 01:02:17 volumio volumio[14768]: info: Setting Spotify Volume from Volumio: 100 Feb 12 01:02:18 volumio go-librespot[15146]: time="2026-02-12T01:02:18+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 12 01:02:18 volumio go-librespot[15146]: time="2026-02-12T01:02:18+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 12 01:02:18 volumio go-librespot[15146]: time="2026-02-12T01:02:18+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 12 01:02:18 volumio go-librespot[15146]: time="2026-02-12T01:02:18+07:00" level=info msg="zeroconf server listening on port 35569" Feb 12 01:02:18 volumio go-librespot[15146]: time="2026-02-12T01:02:18+07:00" level=debug msg="obtained new client token: AABraJQgjNz1dJ7Y+hOdOXZcBT53rVS+WfOGuiH5YMtihfTcrdYYm4KG7LPschh1jR8CAkQenzAxTRSY/fqNXKJjz+QpNrTp3rYDyUWHwxyI4T26ezCdu4g+R8flUSq4LlNsQFd094XgnFptgLl/2h9Od9WZvxaZR56kKawvjj32gioSCuzN7IaD8F2RheGU9ROBDdaz5QQEdXgeSYXUzaJk4joD9Ju8Lvyslz22oi0kmvIHutKGW4M=" Feb 12 01:02:18 volumio go-librespot[15146]: time="2026-02-12T01:02:18+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 12 01:02:18 volumio go-librespot[15146]: time="2026-02-12T01:02:18+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 12 01:02:18 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 12 01:02:18 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 12 01:02:18 volumio volumio[14768]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 12 01:02:18 volumio volumio[14768]: Error: socket hang up Feb 12 01:02:18 volumio volumio[14768]: at connResetException (node:internal/errors:720:14) Feb 12 01:02:18 volumio volumio[14768]: at Socket.socketOnEnd (node:_http_client:519:23) Feb 12 01:02:18 volumio volumio[14768]: at Socket.emit (node:events:526:35) Feb 12 01:02:18 volumio volumio[14768]: at endReadableNT (node:internal/streams/readable:1376:12) Feb 12 01:02:18 volumio volumio[14768]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Feb 12 01:02:18 volumio volumio[14768]: code: 'ECONNRESET', Feb 12 01:02:18 volumio volumio[14768]: response: undefined Feb 12 01:02:18 volumio volumio[14768]: } Feb 12 01:02:18 volumio volumio[14768]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 12 01:02:19 volumio sudo[15173]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-12 01:01' Feb 12 01:02:19 volumio sudo[15173]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 01:02:20 volumio sudo[15173]: pam_unix(sudo:session): session closed for user root Feb 12 01:02:20 volumio volumio-remote-updater[643]: [2026-02-12 01:02:20] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Feb 12 01:02:20 volumio volumio-remote-updater[643]: [2026-02-12 01:02:20] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Feb 12 01:02:20 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Feb 12 01:02:20 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Feb 12 01:02:20 volumio systemd[1]: volumio.service: Consumed 55.622s CPU time. Feb 12 01:02:20 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 12 01:02:20 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 12 01:02:20 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 12460. Feb 12 01:02:20 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 12 01:02:20 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Feb 12 01:02:20 volumio systemd[1]: volumio.service: Consumed 55.622s CPU time. Feb 12 01:02:20 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Feb 12 01:02:20 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 12 01:02:21 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Feb 12 01:02:21 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 01:02:21 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 01:02:21 volumio go-librespot[15200]: go-librespot daemon starting... Feb 12 01:02:21 volumio go-librespot[15201]: time="2026-02-12T01:02:21+07:00" level=info msg="running go-librespot 0.4.0" Feb 12 01:02:21 volumio go-librespot[15201]: time="2026-02-12T01:02:21+07:00" level=debug msg="app state loaded" Feb 12 01:02:21 volumio go-librespot[15201]: time="2026-02-12T01:02:21+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 01:02:22 volumio go-librespot[15201]: time="2026-02-12T01:02: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 12 01:02:22 volumio go-librespot[15201]: time="2026-02-12T01:02:22+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 12 01:02:22 volumio go-librespot[15201]: time="2026-02-12T01:02:22+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 12 01:02:22 volumio go-librespot[15201]: time="2026-02-12T01:02:22+07:00" level=info msg="zeroconf server listening on port 43341" Feb 12 01:02:22 volumio go-librespot[15201]: time="2026-02-12T01:02:22+07:00" level=debug msg="obtained new client token: AAATOHtyPA0oMq+LcedowvbqfI3PkeZhsLezZ0QkjYYH20DeXWdcfvkPnOHkLiM50qmqbtE4g+7Z5yph2WoNt5h73R6EG6mRHIgOoNcyNBSHu5f4pDnHsRFibaCUjUhekNShDgwbKCZRZ3IhREgVwYiCt70rp2T+15ZGASBw/3lIJmF6qoaVwOSK7H3W+hT71ESasbPWd2CP9LijhARdS5RGA+nnI3UfsO+809a3LzOUic8GDhBB71rG6A==" Feb 12 01:02:22 volumio go-librespot[15201]: time="2026-02-12T01:02:22+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 12 01:02:22 volumio go-librespot[15201]: time="2026-02-12T01:02:22+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 12 01:02:22 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 12 01:02:22 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 12 01:02:24 volumio volumio[15185]: info: ------------------------------------------- Feb 12 01:02:24 volumio volumio[15185]: info: ----- Volumio3 ---- Feb 12 01:02:24 volumio volumio[15185]: info: ------------------------------------------- Feb 12 01:02:24 volumio volumio[15185]: info: ----- System startup ---- Feb 12 01:02:24 volumio volumio[15185]: info: ------------------------------------------- Feb 12 01:02:25 volumio volumio-remote-updater[643]: [2026-02-12 01:02:25] [connect] Successful connection Feb 12 01:02:25 volumio volumio[15185]: info: MYVOLUMIO Environment detected Feb 12 01:02:25 volumio volumio[15185]: info: Plugin folders cleanup Feb 12 01:02:25 volumio volumio[15185]: info: Scanning into folder /volumio/app/plugins/ Feb 12 01:02:25 volumio volumio[15185]: info: Scanning category audio_interface Feb 12 01:02:25 volumio volumio[15185]: info: Scanning category miscellanea Feb 12 01:02:25 volumio volumio[15185]: info: Scanning category music_service Feb 12 01:02:25 volumio volumio[15185]: info: Scanning category plugins.json Feb 12 01:02:25 volumio volumio[15185]: info: Scanning category system_controller Feb 12 01:02:25 volumio volumio[15185]: info: Scanning category user_interface Feb 12 01:02:25 volumio volumio[15185]: info: Scanning into folder /data/plugins/ Feb 12 01:02:25 volumio volumio[15185]: info: Scanning category music_service Feb 12 01:02:25 volumio volumio[15185]: info: Plugin folders cleanup completed Feb 12 01:02:25 volumio volumio[15185]: info: ------------------------------------------- Feb 12 01:02:25 volumio volumio[15185]: info: ----- Core plugins startup ---- Feb 12 01:02:25 volumio volumio[15185]: info: ------------------------------------------- Feb 12 01:02:25 volumio volumio[15185]: info: Loading plugins from folder /volumio/app/plugins/ Feb 12 01:02:25 volumio volumio[15185]: info: Adding plugin upnp to MyMusic Plugins Feb 12 01:02:25 volumio volumio[15185]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 12 01:02:25 volumio volumio[15185]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 12 01:02:25 volumio volumio[15185]: info: Loading plugins from folder /data/plugins/ Feb 12 01:02:25 volumio volumio[15185]: info: Loading plugin "system"... Feb 12 01:02:25 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Feb 12 01:02:25 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 01:02:25 volumio volumio[15185]: info: Loading plugin "appearance"... Feb 12 01:02:25 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 01:02:25 volumio go-librespot[15217]: go-librespot daemon starting... Feb 12 01:02:25 volumio go-librespot[15221]: time="2026-02-12T01:02:25+07:00" level=info msg="running go-librespot 0.4.0" Feb 12 01:02:25 volumio go-librespot[15221]: time="2026-02-12T01:02:25+07:00" level=debug msg="app state loaded" Feb 12 01:02:25 volumio go-librespot[15221]: time="2026-02-12T01:02:25+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 01:02:26 volumio go-librespot[15221]: time="2026-02-12T01:02: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 12 01:02:26 volumio go-librespot[15221]: time="2026-02-12T01:02:26+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 12 01:02:26 volumio go-librespot[15221]: time="2026-02-12T01:02:26+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 12 01:02:26 volumio go-librespot[15221]: time="2026-02-12T01:02:26+07:00" level=info msg="zeroconf server listening on port 43583" Feb 12 01:02:26 volumio go-librespot[15221]: time="2026-02-12T01:02:26+07:00" level=debug msg="obtained new client token: AABFkoPtwgIdXmcN8zAUDBIE3ip61ulkFcNPhQ8/UOG2KrqGN/fhD04xp6ZCkJyWgx+ADDI6QCQSuMJusu8AtUmeb4U5Du2Aq1d1lURtfdqfjafikwGMKrytJ05RJGXSMsfqHF++/GFcBpZ4Zx1K2tQRi9ueqMSr8MmAsWBb1Yn+dLAYO9VmKyJn+zKbb8M983e/x9CvLS6Uc112nscKgB4nlGk2dO6CS4aIBs896kbbmZacQSWscwuNEA==" Feb 12 01:02:26 volumio go-librespot[15221]: time="2026-02-12T01:02:26+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 12 01:02:26 volumio go-librespot[15221]: time="2026-02-12T01:02:26+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Feb 12 01:02:26 volumio go-librespot[15221]: time="2026-02-12T01:02:26+07:00" level=debug msg="completed keyexchange" Feb 12 01:02:26 volumio go-librespot[15221]: time="2026-02-12T01:02:26+07:00" level=debug msg="completed challenge" Feb 12 01:02:27 volumio go-librespot[15221]: time="2026-02-12T01:02:27+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 12 01:02:27 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 12 01:02:27 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 12 01:02:27 volumio volumio[15185]: info: Loading plugin "network"... Feb 12 01:02:27 volumio volumio[15185]: info: Refreshing Cached IP Addresses Feb 12 01:02:27 volumio sudo[15229]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 12 01:02:27 volumio sudo[15229]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 01:02:27 volumio sudo[15231]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 12 01:02:27 volumio sudo[15231]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 01:02:27 volumio volumio[15185]: info: Loading plugin "services"... Feb 12 01:02:27 volumio sudo[15229]: pam_unix(sudo:session): session closed for user root Feb 12 01:02:27 volumio volumio[15185]: info: Loading plugin "alsa_controller"... Feb 12 01:02:27 volumio sudo[15231]: pam_unix(sudo:session): session closed for user root Feb 12 01:02:27 volumio sudo[15238]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 12 01:02:28 volumio sudo[15238]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 01:02:28 volumio volumio[15185]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 12 01:02:28 volumio volumio[15185]: info: Loading plugin "wizard"... Feb 12 01:02:28 volumio volumio[15185]: info: Loading plugin "networkfs"... Feb 12 01:02:28 volumio volumio[15185]: info: Starting Udev Watcher for removable devices Feb 12 01:02:28 volumio volumio[15185]: info: Ignoring mount for partition: boot Feb 12 01:02:28 volumio volumio[15185]: info: Ignoring mount for partition: volumio Feb 12 01:02:28 volumio volumio[15185]: info: Ignoring mount for partition: volumio_data Feb 12 01:02:28 volumio volumio[15185]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 12 01:02:28 volumio volumio[15185]: info: Loading plugin "volumio_command_line_client"... Feb 12 01:02:28 volumio volumio[15185]: info: Loading plugin "upnp"... Feb 12 01:02:28 volumio volumio[15185]: info: [1770832948272] Starting Upmpd Daemon Feb 12 01:02:28 volumio volumio[15185]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 12 01:02:28 volumio volumio[15185]: info: Loading plugin "my_music"... Feb 12 01:02:28 volumio volumio[15185]: info: Loading plugin "mpd"... Feb 12 01:02:28 volumio volumio[15185]: info: Loading plugin "upnp_browser"... Feb 12 01:02:30 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Feb 12 01:02:30 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 01:02:30 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 01:02:30 volumio go-librespot[15262]: go-librespot daemon starting... Feb 12 01:02:30 volumio go-librespot[15263]: time="2026-02-12T01:02:30+07:00" level=info msg="running go-librespot 0.4.0" Feb 12 01:02:30 volumio go-librespot[15263]: time="2026-02-12T01:02:30+07:00" level=debug msg="app state loaded" Feb 12 01:02:30 volumio go-librespot[15263]: time="2026-02-12T01:02:30+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 01:02:30 volumio sudo[15238]: pam_unix(sudo:session): session closed for user root Feb 12 01:02:30 volumio go-librespot[15263]: time="2026-02-12T01:02: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 12 01:02:30 volumio go-librespot[15263]: time="2026-02-12T01:02: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 12 01:02:30 volumio go-librespot[15263]: time="2026-02-12T01:02: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 12 01:02:30 volumio go-librespot[15263]: time="2026-02-12T01:02:30+07:00" level=info msg="zeroconf server listening on port 45841" Feb 12 01:02:31 volumio go-librespot[15263]: time="2026-02-12T01:02:31+07:00" level=debug msg="obtained new client token: AABkxnKQuZRhymow5xuP16Eb2ixzJU2Mpj7qGAQmVfH1e9Ctkbr/eQfHpqr08XMPQTjE3PKPbXWdSo/ezpB+CoQvTfm+5wb2kKdJFDJeSQoA9vXMzYKH5pZg3KehA9YAU24voZ1iNG0YM7tcG9anEeOxq6+pt8JdV5prFsDAXXrtye9v4s5S99Fm3Kh+Cs220Dy112wQHDUrBx8PsAwbuL1tbCP+qSYBBc9ycbION+xGrnekjPVXP1I=" Feb 12 01:02:31 volumio go-librespot[15263]: time="2026-02-12T01:02:31+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 12 01:02:31 volumio go-librespot[15263]: time="2026-02-12T01:02:31+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 12 01:02:31 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 12 01:02:31 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 12 01:02:31 volumio volumio[15185]: info: Starting UPNP Browser Feb 12 01:02:31 volumio volumio[15185]: info: Loading plugin "alarm-clock"... Feb 12 01:02:32 volumio volumio[15185]: info: Loading plugin "airplay_emulation"... Feb 12 01:02:32 volumio volumio[15185]: info: Starting Shairport Sync Feb 12 01:02:32 volumio volumio[15185]: info: Loading plugin "last_100"... Feb 12 01:02:32 volumio volumio[15185]: info: Loading plugin "webradio"... Feb 12 01:02:32 volumio volumio[15185]: info: Loading plugin "i2s_dacs"... Feb 12 01:02:32 volumio volumio[15185]: info: Loading plugin "volumiodiscovery"... Feb 12 01:02:32 volumio volumio[15185]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 12 01:02:32 volumio volumio[15185]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 12 01:02:32 volumio node[15185]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 12 01:02:32 volumio volumio[15185]: *** WARNING *** For more information see Feb 12 01:02:32 volumio volumio[15185]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 12 01:02:32 volumio volumio[15185]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 12 01:02:32 volumio volumio[15185]: *** WARNING *** For more information see Feb 12 01:02:32 volumio node[15185]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 12 01:02:32 volumio node[15185]: *** WARNING *** For more information see Feb 12 01:02:32 volumio node[15185]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 12 01:02:32 volumio node[15185]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 12 01:02:32 volumio node[15185]: *** WARNING *** For more information see Feb 12 01:02:32 volumio volumio[15185]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 12 01:02:32 volumio volumio[15185]: info: Discovery: Started advertising with name: Volumio Feb 12 01:02:32 volumio volumio[15185]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 12 01:02:32 volumio volumio[15185]: info: Loading plugin "spop"... Feb 12 01:02:34 volumio volumio[15185]: info: Loading plugin "ytcr"... Feb 12 01:02:34 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Feb 12 01:02:34 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 01:02:34 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 01:02:34 volumio go-librespot[15273]: go-librespot daemon starting... Feb 12 01:02:34 volumio go-librespot[15274]: time="2026-02-12T01:02:34+07:00" level=info msg="running go-librespot 0.4.0" Feb 12 01:02:34 volumio go-librespot[15274]: time="2026-02-12T01:02:34+07:00" level=debug msg="app state loaded" Feb 12 01:02:34 volumio go-librespot[15274]: time="2026-02-12T01:02:34+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 01:02:35 volumio go-librespot[15274]: time="2026-02-12T01:02:35+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 12 01:02:35 volumio go-librespot[15274]: time="2026-02-12T01:02:35+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 12 01:02:35 volumio go-librespot[15274]: time="2026-02-12T01:02:35+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 12 01:02:35 volumio go-librespot[15274]: time="2026-02-12T01:02:35+07:00" level=info msg="zeroconf server listening on port 45531" Feb 12 01:02:35 volumio go-librespot[15274]: time="2026-02-12T01:02:35+07:00" level=debug msg="obtained new client token: AACCWBzEfQK+4LOqZTeFb/ByZjSI5O/nAnN2meuCnNteEVO5LQEVPKZZRDyay9pd6EHL1H07Ay7a4yspLUQM73BonNr35Zl9voJxNEmsKCqFUOIH+UjeRTqraXPj5YeHKUmVpQOs+KwCvstxucnQ/VxsvdO8v2O0PcN6Rp2plmHJp85kSo7TaxHCicQ3hwiHb0lQnz08n8wGMDkxphbEIF5Kt0ZJ+wZa5X9F8PhYMYTM9wGX64zIgcIIDw==" Feb 12 01:02:35 volumio go-librespot[15274]: time="2026-02-12T01:02:35+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 12 01:02:35 volumio go-librespot[15274]: time="2026-02-12T01:02:35+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 12 01:02:35 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 12 01:02:35 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 12 01:02:37 volumio volumio[15185]: info: Loading plugin "ytmusic"... Feb 12 01:02:37 volumio volumio-remote-updater[643]: [2026-02-12 01:02:37] [connect] Successful connection Feb 12 01:02:38 volumio volumio[15185]: info: Loading plugin "outputs"... Feb 12 01:02:38 volumio volumio[15185]: info: Loading plugin "albumart"... Feb 12 01:02:38 volumio volumio[15185]: info: Plugin example_plugin is not enabled Feb 12 01:02:38 volumio volumio[15185]: info: Loading plugin "inputs"... Feb 12 01:02:38 volumio volumio[15185]: info: Loading plugin "updater_comm"... Feb 12 01:02:38 volumio volumio[15185]: info: Plugin mpdemulation is not enabled Feb 12 01:02:38 volumio volumio[15185]: info: Loading plugin "rest_api"... Feb 12 01:02:38 volumio volumio[15185]: info: Loading plugin "websocket"... Feb 12 01:02:38 volumio volumio[15185]: info: Starting Socket.io Server version 1.7.4 Feb 12 01:02:38 volumio volumio[15185]: info: Loading plugin "RoonBridge"... Feb 12 01:02:38 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Feb 12 01:02:38 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 01:02:38 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 01:02:38 volumio go-librespot[15308]: go-librespot daemon starting... Feb 12 01:02:38 volumio go-librespot[15309]: time="2026-02-12T01:02:38+07:00" level=info msg="running go-librespot 0.4.0" Feb 12 01:02:38 volumio go-librespot[15309]: time="2026-02-12T01:02:38+07:00" level=debug msg="app state loaded" Feb 12 01:02:38 volumio go-librespot[15309]: time="2026-02-12T01:02:38+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 01:02:38 volumio volumio[15185]: info: Applying required configuration parameters for plugin RoonBridge Feb 12 01:02:39 volumio volumio[15185]: info: Loading i18n strings for locale en Feb 12 01:02:39 volumio volumio[15185]: Updating browse sources language Feb 12 01:02:39 volumio volumio[15185]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 12 01:02:39 volumio volumio[15185]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 12 01:02:39 volumio volumio[15185]: info: CoreCommandRouter::initPlayerControls Feb 12 01:02:39 volumio volumio[15185]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 01:02:39 volumio volumio[15185]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 01:02:39 volumio volumio[15185]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 01:02:39 volumio volumio[15185]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 01:02:39 volumio volumio[15185]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 01:02:39 volumio volumio[15185]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 01:02:39 volumio volumio[15185]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 01:02:39 volumio volumio[15185]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 01:02:39 volumio volumio[15185]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 12 01:02:39 volumio volumio[15185]: Express server listening on port 3000 Feb 12 01:02:39 volumio volumio[15185]: [Metrics] WebUI: 16s 44.68ms Feb 12 01:02:39 volumio volumio[15298]: Forking 3 albumart workers Feb 12 01:02:39 volumio volumio[15185]: info: CoreStateMachine::resetVolumioState Feb 12 01:02:39 volumio volumio[15185]: info: CoreStateMachine::getcurrentVolume Feb 12 01:02:39 volumio volumio[15185]: info: CoreCommandRouter::volumioRetrievevolume Feb 12 01:02:39 volumio go-librespot[15309]: time="2026-02-12T01:02: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-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 12 01:02:39 volumio go-librespot[15309]: time="2026-02-12T01:02:39+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 12 01:02:39 volumio go-librespot[15309]: time="2026-02-12T01:02:39+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 12 01:02:39 volumio go-librespot[15309]: time="2026-02-12T01:02:39+07:00" level=info msg="zeroconf server listening on port 34623" Feb 12 01:02:39 volumio sudo[15347]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 12 01:02:39 volumio sudo[15347]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 01:02:39 volumio sudo[15347]: pam_unix(sudo:session): session closed for user root Feb 12 01:02:39 volumio sudo[15350]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 12 01:02:39 volumio sudo[15350]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 01:02:39 volumio sudo[15350]: pam_unix(sudo:session): session closed for user root Feb 12 01:02:39 volumio volumio[15185]: info: Volumio Network Manager: Network status updated: 1 Feb 12 01:02:39 volumio go-librespot[15309]: time="2026-02-12T01:02:39+07:00" level=debug msg="obtained new client token: AAD6aSnOjcoWHfszymhgWJokzxTX8ZdbhyO/kTamDvsRmX6aK0QZG5kgQhBKQP5TBZwD5UYLSEiDFia8Am2CaGuHnxA6HXwsCPsmLOsOqHk4KWyySQfA6DWmvFSbdqN/9TX9bhCGKZHqjdNDJ0T5J9BXYScSqymOoAZLQrDyirYPhRSD3c7X7deQOim5ZbutkRBU7RdSe0k6quhrQtCm1TFN3tu9g5tucOkMmg6tPSHivyqsaY9TeAmayw==" Feb 12 01:02:39 volumio go-librespot[15309]: time="2026-02-12T01:02:39+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 12 01:02:39 volumio go-librespot[15309]: time="2026-02-12T01:02:39+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 12 01:02:39 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 12 01:02:39 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 12 01:02:40 volumio volumio[15185]: info: VolumeController:: Volume=100 Mute =false Feb 12 01:02:40 volumio volumio[15185]: info: CoreStateMachine::pushState Feb 12 01:02:40 volumio volumio[15185]: info: CorePlayQueue::getTrack 0 Feb 12 01:02:40 volumio volumio[15185]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 12 01:02:40 volumio volumio[15185]: info: CoreCommandRouter::volumioPushState Feb 12 01:02:40 volumio volumio[15185]: info: CoreStateMachine::updateTrackBlock Feb 12 01:02:40 volumio volumio[15185]: info: CorePlayQueue::getTrackBlock Feb 12 01:02:40 volumio volumio[15185]: info: CoreCommandRouter::volumioRetrievevolume Feb 12 01:02:40 volumio volumio-remote-updater[643]: [2026-02-12 01:02:40] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1770832957 101 Feb 12 01:02:40 volumio volumio[15185]: 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 12 01:02:40 volumio volumio[15185]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 01:02:40 volumio volumio[15185]: info: Reloading queue from file Feb 12 01:02:40 volumio volumio[15185]: info: CoreStateMachine::setRepeat null single undefined Feb 12 01:02:40 volumio volumio[15185]: info: CoreStateMachine::pushState Feb 12 01:02:40 volumio volumio[15185]: info: CorePlayQueue::getTrack 0 Feb 12 01:02:40 volumio volumio[15185]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 12 01:02:40 volumio volumio[15185]: info: CoreCommandRouter::volumioPushState Feb 12 01:02:40 volumio volumio[15185]: info: CoreStateMachine::setRandom null Feb 12 01:02:40 volumio volumio[15185]: info: CoreStateMachine::pushState Feb 12 01:02:40 volumio volumio[15185]: info: CorePlayQueue::getTrack 0 Feb 12 01:02:40 volumio volumio[15185]: info: CoreCommandRouter::volumioPushState Feb 12 01:02:40 volumio volumio[15185]: info: Setting Device type: Raspberry PI Feb 12 01:02:40 volumio volumio[15185]: info: Completed loading Core Plugins Feb 12 01:02:40 volumio volumio[15185]: info: Preparing to generate the ALSA configuration file Feb 12 01:02:40 volumio volumio[15185]: info: VolumeController:: Volume=100 Mute =false Feb 12 01:02:40 volumio volumio[15185]: info: CoreStateMachine::pushState Feb 12 01:02:40 volumio volumio[15185]: info: CorePlayQueue::getTrack 0 Feb 12 01:02:40 volumio volumio[15185]: info: CoreCommandRouter::volumioPushState Feb 12 01:02:40 volumio volumio[15185]: info: Asound.conf file unchanged, so no further update is needed Feb 12 01:02:40 volumio volumio[15185]: info: Output device has changed, restarting MPD Feb 12 01:02:40 volumio volumio[15185]: info: Output device has changed, restarting Shairport Sync Feb 12 01:02:40 volumio volumio[15185]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 01:02:40 volumio volumio[15185]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 01:02:40 volumio sudo[15367]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 12 01:02:40 volumio sudo[15367]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 01:02:40 volumio sudo[15369]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 12 01:02:40 volumio volumio[15185]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 12 01:02:40 volumio sudo[15369]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 01:02:40 volumio volumio[15185]: info: ___________ START PLUGINS ___________ Feb 12 01:02:40 volumio sudo[15371]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 12 01:02:40 volumio sudo[15369]: pam_unix(sudo:session): session closed for user root Feb 12 01:02:40 volumio volumio[15185]: info: ControllerMpd::onStart: Initializing MPD Feb 12 01:02:40 volumio volumio[15185]: info: Creating MPD Configuration file Feb 12 01:02:40 volumio sudo[15371]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 01:02:40 volumio volumio[15185]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 12 01:02:40 volumio sudo[15380]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 12 01:02:40 volumio sudo[15380]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 01:02:40 volumio volumio[15185]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 12 01:02:40 volumio volumio[15185]: info: [1770832960827] CoreMusicLibrary::Adding element Media Servers Feb 12 01:02:40 volumio volumio[15185]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 12 01:02:40 volumio sudo[15380]: pam_unix(sudo:session): session closed for user root Feb 12 01:02:40 volumio sudo[15382]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 12 01:02:40 volumio volumio[15185]: info: UPNP Browser: Client initialized successfully Feb 12 01:02:40 volumio sudo[15382]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 01:02:40 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 12 01:02:40 volumio sudo[15367]: pam_unix(sudo:session): session closed for user root Feb 12 01:02:41 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 12 01:02:41 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 12 01:02:41 volumio systemd[1]: mpd.service: Consumed 7.158s CPU time. Feb 12 01:02:41 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 12 01:02:41 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 12 01:02:41 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 12 01:02:41 volumio volumio[15185]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 01:02:41 volumio volumio[15185]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 01:02:41 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 12 01:02:41 volumio volumio[15185]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 12 01:02:41 volumio volumio[15185]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 01:02:41 volumio volumio[15185]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 01:02:41 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 12 01:02:41 volumio volumio[15185]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 12 01:02:41 volumio volumio[15185]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 12 01:02:41 volumio volumio[15185]: info: [1770832961212] CoreMusicLibrary::Adding element Last_100 Feb 12 01:02:41 volumio volumio[15185]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 12 01:02:41 volumio volumio[15185]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 12 01:02:41 volumio volumio[15185]: info: [1770832961235] CoreMusicLibrary::Adding element Webradio Feb 12 01:02:41 volumio volumio[15185]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 12 01:02:41 volumio volumio[15185]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 12 01:02:41 volumio volumio[15185]: info: Initializing BBC Radios Feb 12 01:02:41 volumio volumio[15185]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 12 01:02:41 volumio volumio[15185]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 01:02:41 volumio volumio[15185]: info: Creating Spotify config file Feb 12 01:02:41 volumio volumio[15185]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 01:02:41 volumio sudo[15390]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 12 01:02:41 volumio sudo[15390]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 12 01:02:41 volumio sudo[15390]: pam_unix(sudo:session): session closed for user root Feb 12 01:02:42 volumio volumio[15320]: Starting albumart workers Feb 12 01:02:42 volumio volumio[15185]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 12 01:02:42 volumio volumio[15185]: info: [1770832962599] CoreMusicLibrary::Adding element YouTube Music Feb 12 01:02:42 volumio volumio[15185]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 12 01:02:42 volumio volumio[15185]: Cannot find translation for source YouTube Music Feb 12 01:02:42 volumio volumio[15185]: info: Volumio Calling Home Feb 12 01:02:42 volumio sudo[15411]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Feb 12 01:02:42 volumio sudo[15411]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 01:02:42 volumio volumio[15321]: Starting albumart workers Feb 12 01:02:42 volumio sudo[15411]: pam_unix(sudo:session): session closed for user root Feb 12 01:02:43 volumio volumio[15319]: Starting albumart workers Feb 12 01:02:43 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Feb 12 01:02:43 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 01:02:43 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 01:02:43 volumio go-librespot[15416]: go-librespot daemon starting... Feb 12 01:02:43 volumio go-librespot[15417]: time="2026-02-12T01:02:43+07:00" level=info msg="running go-librespot 0.4.0" Feb 12 01:02:43 volumio volumio[15185]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Feb 12 01:02:43 volumio volumio[15185]: info: Discovery: Found device Volumio Feb 12 01:02:43 volumio volumio[15185]: info: CoreCommandRouter::volumioGetState Feb 12 01:02:43 volumio volumio[15185]: info: CorePlayQueue::getTrack 0 Feb 12 01:02:43 volumio volumio[15185]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Feb 12 01:02:43 volumio volumio[15185]: info: Discovery: Found device Volumio Feb 12 01:02:43 volumio volumio[15185]: info: CoreCommandRouter::volumioGetState Feb 12 01:02:43 volumio volumio[15185]: info: CorePlayQueue::getTrack 0 Feb 12 01:02:43 volumio volumio[15185]: info: MPD Permissions set Feb 12 01:02:43 volumio volumio[15185]: info: MPD Permissions set Feb 12 01:02:43 volumio volumio[15185]: info: Upmpdcli Daemon Started Feb 12 01:02:43 volumio volumio[15185]: info: Spotify config file written Feb 12 01:02:43 volumio sudo[15424]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 12 01:02:43 volumio sudo[15424]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 01:02:43 volumio go-librespot[15417]: time="2026-02-12T01:02:43+07:00" level=info msg="zeroconf server listening on port 41935" Feb 12 01:02:44 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Feb 12 01:02:44 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Feb 12 01:02:44 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 01:02:44 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 01:02:44 volumio go-librespot[15429]: go-librespot daemon starting... Feb 12 01:02:44 volumio sudo[15424]: pam_unix(sudo:session): session closed for user root Feb 12 01:02:44 volumio go-librespot[15430]: time="2026-02-12T01:02:44+07:00" level=info msg="running go-librespot 0.4.0" Feb 12 01:02:44 volumio go-librespot[15430]: time="2026-02-12T01:02:44+07:00" level=debug msg="app state loaded" Feb 12 01:02:44 volumio go-librespot[15430]: time="2026-02-12T01:02:44+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 01:02:44 volumio volumio[15185]: 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 12 01:02:44 volumio volumio[15185]: info: Volumio called home Feb 12 01:02:44 volumio volumio[15185]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 01:02:44 volumio volumio[15185]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 01:02:44 volumio volumio[15185]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 01:02:44 volumio volumio[15185]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 01:02:44 volumio volumio[15185]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 01:02:44 volumio volumio[15185]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 01:02:44 volumio volumio[15185]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 01:02:44 volumio volumio[15185]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 01:02:44 volumio volumio[15185]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 01:02:44 volumio volumio[15185]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 01:02:44 volumio volumio[15185]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 01:02:44 volumio volumio[15185]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 01:02:44 volumio volumio[15185]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 01:02:44 volumio volumio[15185]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 01:02:44 volumio volumio[15185]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 01:02:44 volumio volumio[15185]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 01:02:44 volumio volumio[15185]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 01:02:44 volumio volumio[15185]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 01:02:44 volumio volumio[15185]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 01:02:44 volumio volumio[15185]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 01:02:44 volumio volumio[15185]: info: No need to fix Spotify hosts Feb 12 01:02:44 volumio go-librespot[15430]: time="2026-02-12T01:02:44+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 12 01:02:44 volumio go-librespot[15430]: time="2026-02-12T01:02:44+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 12 01:02:44 volumio go-librespot[15430]: time="2026-02-12T01:02:44+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 12 01:02:44 volumio go-librespot[15430]: time="2026-02-12T01:02:44+07:00" level=info msg="zeroconf server listening on port 39135" Feb 12 01:02:45 volumio go-librespot[15430]: time="2026-02-12T01:02:45+07:00" level=debug msg="obtained new client token: AADaKtaRQIbTeeEulJGn1b/gWR/CpcYTcR6VkPSqZq6RJM5fAqilUApaOvvxdQCUDHtdQW6CQPc6v/KdTI1Qu1HeHVdgnnDh3hgLIpgv4JeRTW9cgACZWUhneWtkuxPCnAo3NiuPjScksK21N1Y2MxCFS8ZKz3BXP678jZ0xaTxkkcR6cYwjGCdI9YmWf8jQx0e4Zt1YNgnHI/o0l03POB9dAgZRM0saJU/X9PI5z4/gysElp/QmhyA=" Feb 12 01:02:45 volumio go-librespot[15430]: time="2026-02-12T01:02:45+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 12 01:02:45 volumio go-librespot[15430]: time="2026-02-12T01:02:45+07:00" level=debug msg="completed keyexchange" Feb 12 01:02:45 volumio go-librespot[15430]: time="2026-02-12T01:02:45+07:00" level=debug msg="completed challenge" Feb 12 01:02:45 volumio go-librespot[15430]: time="2026-02-12T01:02:45+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 12 01:02:45 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 12 01:02:45 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 12 01:02:45 volumio volumio[15185]: info: Starting Shairport Sync Feb 12 01:02:45 volumio volumio[15185]: info: Starting Shairport Sync Feb 12 01:02:45 volumio volumio[15185]: info: Starting Shairport Sync Feb 12 01:02:45 volumio sudo[15467]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 12 01:02:45 volumio sudo[15467]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 01:02:45 volumio sudo[15469]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 12 01:02:45 volumio sudo[15469]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 01:02:45 volumio sudo[15471]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 12 01:02:45 volumio sudo[15471]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 01:02:45 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 12 01:02:45 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 12 01:02:45 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 12 01:02:45 volumio systemd[1]: shairport-sync.service: Consumed 2.237s CPU time. Feb 12 01:02:46 volumio volumio[15185]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 12 01:02:46 volumio volumio[15185]: SPOTIFY: BQB7U2tfKCf6Njb6FDcJzcze_FMmXPVRJcra_kxIfwOis7ORR2BwIrFjq5QJoXiiGG3w0Anozv6HCIgmvhrhxfjs49luBxSUt6dnOjkHuz5wPgxvZ-Kyfp08fy_AYvkUyED6DzLfAU4X7zVOwgLz6axfG6AflQlBHI6k8kQTx85vY7h886rp657GVkKKiVyq8JUMhaO0835FkCakab1Za5PM6nfdXHikimfhDO_kDViipixlWIGhYkFjGe8Z4wQhB5a_Zv5w9xhG_49YkOXDzCfcdGdD9hW0XNCTrvXH9Kz1s6Fowkl--r_q Feb 12 01:02:46 volumio volumio[15185]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 12 01:02:46 volumio volumio[15185]: info: New Spotify access token = BQB7U2tfKCf6Njb6FDcJzcze_FMmXPVRJcra_kxIfwOis7ORR2BwIrFjq5QJoXiiGG3w0Anozv6HCIgmvhrhxfjs49luBxSUt6dnOjkHuz5wPgxvZ-Kyfp08fy_AYvkUyED6DzLfAU4X7zVOwgLz6axfG6AflQlBHI6k8kQTx85vY7h886rp657GVkKKiVyq8JUMhaO0835FkCakab1Za5PM6nfdXHikimfhDO_kDViipixlWIGhYkFjGe8Z4wQhB5a_Zv5w9xhG_49YkOXDzCfcdGdD9hW0XNCTrvXH9Kz1s6Fowkl--r_q Feb 12 01:02:46 volumio volumio[15185]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 12 01:02:46 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 12 01:02:46 volumio sudo[15467]: pam_unix(sudo:session): session closed for user root Feb 12 01:02:46 volumio sudo[15469]: pam_unix(sudo:session): session closed for user root Feb 12 01:02:46 volumio sudo[15471]: pam_unix(sudo:session): session closed for user root Feb 12 01:02:46 volumio volumio[15185]: info: Shairport-Sync Started Feb 12 01:02:46 volumio volumio[15185]: Error adding Membership: Error: addMembership EINVAL Feb 12 01:02:46 volumio volumio[15185]: info: Shairport-Sync Started Feb 12 01:02:46 volumio volumio[15185]: info: Shairport-Sync Started Feb 12 01:02:46 volumio volumio[15185]: info: CoreCommandRouter::volumioGetState Feb 12 01:02:46 volumio volumio[15185]: info: CorePlayQueue::getTrack 0 Feb 12 01:02:46 volumio volumio[15185]: 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 12 01:02:46 volumio volumio[15185]: info: Spotify Successfully logged in Feb 12 01:02:46 volumio volumio[15185]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 12 01:02:46 volumio volumio[15185]: info: [1770832966548] CoreMusicLibrary::Adding element Spotify Feb 12 01:02:46 volumio volumio[15185]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 12 01:02:46 volumio volumio[15185]: Cannot find translation for source YouTube Music Feb 12 01:02:46 volumio volumio[15185]: Cannot find translation for source Spotify Feb 12 01:02:46 volumio volumio[15185]: info: [yt-cast-receiver] DIAL server listening on port 8098 Feb 12 01:02:47 volumio volumio[15185]: info: CoreCommandRouter::volumioRetrievevolume Feb 12 01:02:47 volumio volumio[15185]: info: VolumeController:: Volume=100 Mute =false Feb 12 01:02:47 volumio volumio[15185]: info: CoreCommandRouter::volumioGetState Feb 12 01:02:47 volumio volumio[15185]: info: CorePlayQueue::getTrack 0 Feb 12 01:02:47 volumio volumio[15185]: info: CoreStateMachine::pushState Feb 12 01:02:47 volumio volumio[15185]: info: CorePlayQueue::getTrack 0 Feb 12 01:02:47 volumio volumio[15185]: info: CoreCommandRouter::volumioPushState Feb 12 01:02:48 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Feb 12 01:02:48 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 01:02:48 volumio volumio[15185]: info: go-librespot daemon successfully initialized Feb 12 01:02:48 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 01:02:48 volumio go-librespot[15508]: go-librespot daemon starting... Feb 12 01:02:48 volumio go-librespot[15509]: time="2026-02-12T01:02:48+07:00" level=info msg="running go-librespot 0.4.0" Feb 12 01:02:48 volumio go-librespot[15509]: time="2026-02-12T01:02:48+07:00" level=debug msg="app state loaded" Feb 12 01:02:48 volumio go-librespot[15509]: time="2026-02-12T01:02:48+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 01:02:48 volumio mpd[15409]: 2026-02-12T01:02:48 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 12 01:02:48 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 12 01:02:48 volumio sudo[15382]: pam_unix(sudo:session): session closed for user root Feb 12 01:02:48 volumio sudo[15371]: pam_unix(sudo:session): session closed for user root Feb 12 01:02:49 volumio volumio[15185]: error: MPD error: The expression evaluated to a falsy value: Feb 12 01:02:49 volumio volumio[15185]: assert.ok(self.idling) Feb 12 01:02:49 volumio volumio[15185]: error: The expression evaluated to a falsy value: Feb 12 01:02:49 volumio volumio[15185]: assert.ok(self.idling) Feb 12 01:02:49 volumio volumio[15185]: info: MPD running with PID15409 Feb 12 01:02:49 volumio volumio[15185]: ,establishing connection Feb 12 01:02:49 volumio volumio[15185]: error: updateQueue error: null Feb 12 01:02:49 volumio go-librespot[15509]: time="2026-02-12T01:02:49+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 12 01:02:49 volumio go-librespot[15509]: time="2026-02-12T01:02:49+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 12 01:02:49 volumio go-librespot[15509]: time="2026-02-12T01:02:49+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 12 01:02:49 volumio volumio[15185]: info: Completed starting Core Plugins Feb 12 01:02:49 volumio volumio[15185]: info: ------------------------------------------- Feb 12 01:02:49 volumio volumio[15185]: info: ----- MyVolumio plugins startup ---- Feb 12 01:02:49 volumio volumio[15185]: info: ------------------------------------------- Feb 12 01:02:49 volumio volumio[15185]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 12 01:02:49 volumio volumio[15185]: error: updateQueue error: null Feb 12 01:02:49 volumio go-librespot[15509]: time="2026-02-12T01:02:49+07:00" level=info msg="zeroconf server listening on port 33805" Feb 12 01:02:49 volumio go-librespot[15509]: time="2026-02-12T01:02:49+07:00" level=debug msg="obtained new client token: AADShGgWkff0z/z/sMOhtDgYS9Ms3sG4t+voKdZwEZqp7UyoasM5frckw5pX5NljsZYp0ZqowZQV6FPoXfk6lXqSJM7WsQmbYvy81Lh7PVrv468HD2j9dEa0+Xn+ttQ5JJ1sua9Lx940MgKtnDlSgpU7QspIFhHwnFZzkPahL17m/yP7PFLPYjgTIhPlQWgSbb7+3C7uArDVSOQ32G34VGpen7fKFSOkDAO7dkwlJnoSi5Eaydqche/VRw==" Feb 12 01:02:49 volumio go-librespot[15509]: time="2026-02-12T01:02:49+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 12 01:02:49 volumio go-librespot[15509]: time="2026-02-12T01:02:49+07:00" level=debug msg="completed keyexchange" Feb 12 01:02:49 volumio go-librespot[15509]: time="2026-02-12T01:02:49+07:00" level=debug msg="completed challenge" Feb 12 01:02:49 volumio go-librespot[15509]: time="2026-02-12T01:02:49+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 12 01:02:49 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 12 01:02:49 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 12 01:02:51 volumio volumio[15185]: info: Initializing connection to go-librespot Websocket Feb 12 01:02:51 volumio volumio[15185]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 12 01:02:52 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Feb 12 01:02:52 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 01:02:52 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 01:02:52 volumio go-librespot[15521]: go-librespot daemon starting... Feb 12 01:02:52 volumio go-librespot[15522]: time="2026-02-12T01:02:52+07:00" level=info msg="running go-librespot 0.4.0" Feb 12 01:02:52 volumio go-librespot[15522]: time="2026-02-12T01:02:52+07:00" level=debug msg="app state loaded" Feb 12 01:02:52 volumio go-librespot[15522]: time="2026-02-12T01:02:52+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 01:02:53 volumio go-librespot[15522]: time="2026-02-12T01:02:53+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 12 01:02:53 volumio go-librespot[15522]: time="2026-02-12T01:02:53+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 12 01:02:53 volumio go-librespot[15522]: time="2026-02-12T01:02:53+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 12 01:02:53 volumio go-librespot[15522]: time="2026-02-12T01:02:53+07:00" level=info msg="zeroconf server listening on port 41937" Feb 12 01:02:53 volumio go-librespot[15522]: time="2026-02-12T01:02:53+07:00" level=debug msg="obtained new client token: AABKYcGWwlB6jsQnP37weHmOHnXq6TFfrJzCcoNuGxbHvw+cXN2wdJcvbzes6QqtiFiR/JWZRKqfepQSp+IrjFFB3Dul01l4n5rWI+aWJGzdDzNkKiv0A50i7fJIbFHKU/EXv/jO/VQbIy73+NXJg6IQSJ1ojJV1k/PEy6DIxcZb2am9SwNx4TsXk48PqK9G40omZPt/rK6iBDQyHZTmHP/aSl8PtM53y3+4ccEay9o2uWdrvjIh41VynQ==" Feb 12 01:02:53 volumio go-librespot[15522]: time="2026-02-12T01:02:53+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 12 01:02:53 volumio go-librespot[15522]: time="2026-02-12T01:02: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 12 01:02:53 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 12 01:02:53 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 12 01:02:53 volumio volumio[15185]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 12 01:02:54 volumio volumio[15185]: info: Initializing connection to go-librespot Websocket Feb 12 01:02:54 volumio volumio[15185]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 12 01:02:56 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Feb 12 01:02:56 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 01:02:56 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 01:02:56 volumio go-librespot[15530]: go-librespot daemon starting... Feb 12 01:02:56 volumio go-librespot[15531]: time="2026-02-12T01:02:56+07:00" level=info msg="running go-librespot 0.4.0" Feb 12 01:02:56 volumio go-librespot[15531]: time="2026-02-12T01:02:56+07:00" level=debug msg="app state loaded" Feb 12 01:02:56 volumio go-librespot[15531]: time="2026-02-12T01:02:56+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 01:02:57 volumio go-librespot[15531]: time="2026-02-12T01:02:57+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 12 01:02:57 volumio go-librespot[15531]: time="2026-02-12T01:02:57+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 12 01:02:57 volumio go-librespot[15531]: time="2026-02-12T01:02:57+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 12 01:02:57 volumio go-librespot[15531]: time="2026-02-12T01:02:57+07:00" level=info msg="zeroconf server listening on port 43985" Feb 12 01:02:57 volumio go-librespot[15531]: time="2026-02-12T01:02:57+07:00" level=debug msg="obtained new client token: AACGeItEusVlnGT4qpBtxZhF32b2OwP6TbpbHgTtxAhdDWX4G60U0YsDBcM4IxRUqwUKY3E1gdkbYMqeAX20+x/L0hPIZGyosyTTO94wMiw1vjdLCIhP3XnMn1KFneHNH7D1nqh0veF/4uxvTnY4ra3zMfsNAyTD7u+xz2QKwAeZjHPHW4fJJG18KIN7FTQJ/dj4azeiDQq/yh6nVUq8sikFtzKymSOmrefq3Cw1RPCwS4GkAgG64Zy2oA==" Feb 12 01:02:57 volumio volumio[15185]: info: Initializing connection to go-librespot Websocket Feb 12 01:02:57 volumio go-librespot[15531]: time="2026-02-12T01:02:57+07:00" level=debug msg="new websocket client" Feb 12 01:02:57 volumio volumio[15185]: info: Connection to go-librespot Websocket established Feb 12 01:02:57 volumio go-librespot[15531]: time="2026-02-12T01:02:57+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 12 01:02:57 volumio go-librespot[15531]: time="2026-02-12T01:02:57+07:00" level=debug msg="completed keyexchange" Feb 12 01:02:57 volumio go-librespot[15531]: time="2026-02-12T01:02:57+07:00" level=debug msg="completed challenge" Feb 12 01:02:57 volumio go-librespot[15531]: time="2026-02-12T01:02:57+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 12 01:02:57 volumio volumio[15185]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 12 01:02:57 volumio volumio[15185]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 12 01:02:57 volumio volumio[15185]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 12 01:02:57 volumio volumio[15185]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 12 01:02:57 volumio volumio[15185]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 12 01:02:57 volumio volumio[15185]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 12 01:02:57 volumio volumio[15185]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 12 01:02:57 volumio volumio[15185]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 12 01:02:57 volumio volumio[15185]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 12 01:02:57 volumio volumio[15185]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 12 01:02:57 volumio volumio[15185]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 12 01:02:57 volumio volumio[15185]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 12 01:02:57 volumio volumio[15185]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 12 01:02:57 volumio volumio[15185]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 12 01:02:57 volumio volumio[15185]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 12 01:02:57 volumio volumio[15185]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 12 01:02:57 volumio volumio[15185]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 12 01:02:57 volumio volumio[15185]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 12 01:02:57 volumio volumio[15185]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 12 01:02:57 volumio volumio[15185]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 12 01:02:57 volumio volumio[15185]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 12 01:02:57 volumio volumio[15185]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 12 01:02:57 volumio volumio[15185]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 12 01:02:57 volumio volumio[15185]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 12 01:02:57 volumio volumio[15185]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 12 01:02:57 volumio volumio[15185]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 12 01:02:57 volumio volumio[15185]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 12 01:02:57 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 12 01:02:57 volumio volumio[15185]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 12 01:02:57 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 12 01:02:57 volumio volumio[15185]: info: Adding plugin bluetooth to MyMusic Plugins Feb 12 01:02:57 volumio volumio[15185]: info: Adding plugin multiroom to MyMusic Plugins Feb 12 01:02:57 volumio volumio[15185]: info: Adding plugin metavolumio to MyMusic Plugins Feb 12 01:02:57 volumio volumio[15185]: info: Adding plugin cd_controller to MyMusic Plugins Feb 12 01:02:57 volumio volumio[15185]: info: Adding plugin qobuzconnect to MyMusic Plugins Feb 12 01:02:57 volumio volumio[15185]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 12 01:02:57 volumio volumio[15185]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 12 01:02:58 volumio volumio[15185]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 12 01:02:59 volumio volumio[15185]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 12 01:02:59 volumio volumio[15185]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 12 01:02:59 volumio volumio[15185]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 01:02:59 volumio volumio[15185]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 01:02:59 volumio volumio[15185]: info: Starting MyVolumio Remote Streaming Endpoints Feb 12 01:02:59 volumio volumio[15185]: info: MyVolumio login type: Token Feb 12 01:02:59 volumio volumio[15185]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 12 01:02:59 volumio volumio[15185]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 12 01:03:01 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Feb 12 01:03:01 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 01:03:01 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 01:03:01 volumio go-librespot[15552]: go-librespot daemon starting... Feb 12 01:03:01 volumio go-librespot[15553]: time="2026-02-12T01:03:01+07:00" level=info msg="running go-librespot 0.4.0" Feb 12 01:03:01 volumio go-librespot[15553]: time="2026-02-12T01:03:01+07:00" level=debug msg="app state loaded" Feb 12 01:03:01 volumio go-librespot[15553]: time="2026-02-12T01:03:01+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 01:03:01 volumio go-librespot[15553]: time="2026-02-12T01:03:01+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 12 01:03:01 volumio go-librespot[15553]: time="2026-02-12T01:03:01+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 12 01:03:01 volumio go-librespot[15553]: time="2026-02-12T01:03:01+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 12 01:03:01 volumio volumio[15185]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 12 01:03:01 volumio volumio[15185]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 12 01:03:01 volumio volumio[15185]: info: Streaming services startup Feb 12 01:03:01 volumio volumio[15185]: info: Starting Streaming Daemon Feb 12 01:03:01 volumio go-librespot[15553]: time="2026-02-12T01:03:01+07:00" level=info msg="zeroconf server listening on port 44603" Feb 12 01:03:01 volumio sudo[15562]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 12 01:03:01 volumio sudo[15562]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 01:03:01 volumio volumio[15185]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 12 01:03:01 volumio sudo[15562]: pam_unix(sudo:session): session closed for user root Feb 12 01:03:01 volumio volumio[15185]: info: Getting Spotify volume Feb 12 01:03:01 volumio go-librespot[15553]: time="2026-02-12T01:03:01+07:00" level=debug msg="obtained new client token: AABdyB/ReUoRo+WXCaDQxiCqz+1nL+HV7kjWl6xsDzp10ejtHlVYO45ZXURhZb3HPx+exXMZut1F1IVQwoUawHrfCjmWLV0q8cmAnMukNNonOI4J3kmc8A6ExNTySvsHb+Fnh7yHiKe/FEEdUdKPwaYptSUR+eDfNO1FO/Q0jT40oRSLN+1ZnE6X75tHpDDSzyc39UVvddt6KFIYBM6IByzKp37N79UZFSMKTRw2T18JQ9u79morNmb/Bw==" Feb 12 01:03:02 volumio volumio[15185]: info: Connection to go-librespot Websocket closed Feb 12 01:03:02 volumio volumio[15185]: error: Cannot start Volumio Streaming Daemon Feb 12 01:03:02 volumio volumio[15185]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 12 01:03:02 volumio volumio[15185]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 12 01:03:02 volumio volumio[15185]: 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 12 01:03:02 volumio go-librespot[15553]: time="2026-02-12T01:03:02+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 12 01:03:02 volumio go-librespot[15553]: time="2026-02-12T01:03:02+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 12 01:03:02 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 12 01:03:02 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 12 01:03:02 volumio volumio[15185]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 12 01:03:02 volumio volumio[15185]: Error: socket hang up Feb 12 01:03:02 volumio volumio[15185]: at connResetException (node:internal/errors:720:14) Feb 12 01:03:02 volumio volumio[15185]: at Socket.socketOnEnd (node:_http_client:519:23) Feb 12 01:03:02 volumio volumio[15185]: at Socket.emit (node:events:526:35) Feb 12 01:03:02 volumio volumio[15185]: at endReadableNT (node:internal/streams/readable:1376:12) Feb 12 01:03:02 volumio volumio[15185]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Feb 12 01:03:02 volumio volumio[15185]: code: 'ECONNRESET', Feb 12 01:03:02 volumio volumio[15185]: response: undefined Feb 12 01:03:02 volumio volumio[15185]: } Feb 12 01:03:02 volumio volumio[15185]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 12 01:03:03 volumio sudo[15582]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-12 01:02' Feb 12 01:03:03 volumio sudo[15582]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 01:03:03 volumio sudo[15582]: pam_unix(sudo:session): session closed for user root Feb 12 01:03:04 volumio volumio-remote-updater[643]: [2026-02-12 01:03:04] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Feb 12 01:03:04 volumio volumio-remote-updater[643]: [2026-02-12 01:03:04] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Feb 12 01:03:04 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Feb 12 01:03:04 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Feb 12 01:03:04 volumio systemd[1]: volumio.service: Consumed 55.304s CPU time. Feb 12 01:03:04 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 12 01:03:04 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 12 01:03:04 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 12461. Feb 12 01:03:04 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 12 01:03:04 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Feb 12 01:03:04 volumio systemd[1]: volumio.service: Consumed 55.304s CPU time. Feb 12 01:03:04 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Feb 12 01:03:04 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 12 01:03:05 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Feb 12 01:03:05 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 01:03:05 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 01:03:05 volumio go-librespot[15613]: go-librespot daemon starting... Feb 12 01:03:05 volumio go-librespot[15614]: time="2026-02-12T01:03:05+07:00" level=info msg="running go-librespot 0.4.0" Feb 12 01:03:05 volumio go-librespot[15614]: time="2026-02-12T01:03:05+07:00" level=debug msg="app state loaded" Feb 12 01:03:05 volumio go-librespot[15614]: time="2026-02-12T01:03:05+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 01:03:06 volumio go-librespot[15614]: time="2026-02-12T01:03:06+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 12 01:03:06 volumio go-librespot[15614]: time="2026-02-12T01:03:06+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 12 01:03:06 volumio go-librespot[15614]: time="2026-02-12T01:03:06+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 12 01:03:06 volumio go-librespot[15614]: time="2026-02-12T01:03:06+07:00" level=info msg="zeroconf server listening on port 36179" Feb 12 01:03:06 volumio go-librespot[15614]: time="2026-02-12T01:03:06+07:00" level=debug msg="obtained new client token: AADjeoEYj1pUp1OV8HH9cUoq22LmyOETyJAyhOXFxHH0rhJNFO/pwrTuxaHU5l0pEl0HrNrwR9aPjgx2WfmSXHcsyXDUQQy+XkyUOVDkGS4muH1zV1nETapD2hyPwsVwJFucqx0LGhO+kIZAJlp9uIEHvxNlGr1byX24M2jObD8T6xKqBOd35X1wLW2TARQJokOs+IlgZz0VcN2cI3N4Qenik93BBjjRDeRlbZZnryGSjXMi5yd4BXQ=" Feb 12 01:03:06 volumio go-librespot[15614]: time="2026-02-12T01:03:06+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 12 01:03:06 volumio go-librespot[15614]: time="2026-02-12T01:03:06+07:00" level=debug msg="completed keyexchange" Feb 12 01:03:06 volumio go-librespot[15614]: time="2026-02-12T01:03:06+07:00" level=debug msg="completed challenge" Feb 12 01:03:06 volumio go-librespot[15614]: time="2026-02-12T01:03: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 12 01:03:06 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 12 01:03:06 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 12 01:03:07 volumio volumio[15598]: info: ------------------------------------------- Feb 12 01:03:07 volumio volumio[15598]: info: ----- Volumio3 ---- Feb 12 01:03:07 volumio volumio[15598]: info: ------------------------------------------- Feb 12 01:03:07 volumio volumio[15598]: info: ----- System startup ---- Feb 12 01:03:07 volumio volumio[15598]: info: ------------------------------------------- Feb 12 01:03:09 volumio volumio-remote-updater[643]: [2026-02-12 01:03:09] [connect] Successful connection Feb 12 01:03:09 volumio volumio[15598]: info: MYVOLUMIO Environment detected Feb 12 01:03:09 volumio volumio[15598]: info: Plugin folders cleanup Feb 12 01:03:09 volumio volumio[15598]: info: Scanning into folder /volumio/app/plugins/ Feb 12 01:03:09 volumio volumio[15598]: info: Scanning category audio_interface Feb 12 01:03:09 volumio volumio[15598]: info: Scanning category miscellanea Feb 12 01:03:09 volumio volumio[15598]: info: Scanning category music_service Feb 12 01:03:09 volumio volumio[15598]: info: Scanning category plugins.json Feb 12 01:03:09 volumio volumio[15598]: info: Scanning category system_controller Feb 12 01:03:09 volumio volumio[15598]: info: Scanning category user_interface Feb 12 01:03:09 volumio volumio[15598]: info: Scanning into folder /data/plugins/ Feb 12 01:03:09 volumio volumio[15598]: info: Scanning category music_service Feb 12 01:03:09 volumio volumio[15598]: info: Plugin folders cleanup completed Feb 12 01:03:09 volumio volumio[15598]: info: ------------------------------------------- Feb 12 01:03:09 volumio volumio[15598]: info: ----- Core plugins startup ---- Feb 12 01:03:09 volumio volumio[15598]: info: ------------------------------------------- Feb 12 01:03:09 volumio volumio[15598]: info: Loading plugins from folder /volumio/app/plugins/ Feb 12 01:03:09 volumio volumio[15598]: info: Adding plugin upnp to MyMusic Plugins Feb 12 01:03:09 volumio volumio[15598]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 12 01:03:09 volumio volumio[15598]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 12 01:03:09 volumio volumio[15598]: info: Loading plugins from folder /data/plugins/ Feb 12 01:03:09 volumio volumio[15598]: info: Loading plugin "system"... Feb 12 01:03:09 volumio volumio[15598]: info: Loading plugin "appearance"... Feb 12 01:03:09 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Feb 12 01:03:09 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 01:03:09 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 01:03:09 volumio go-librespot[15635]: go-librespot daemon starting... Feb 12 01:03:09 volumio go-librespot[15636]: time="2026-02-12T01:03:09+07:00" level=info msg="running go-librespot 0.4.0" Feb 12 01:03:09 volumio go-librespot[15636]: time="2026-02-12T01:03:09+07:00" level=debug msg="app state loaded" Feb 12 01:03:09 volumio go-librespot[15636]: time="2026-02-12T01:03:09+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 01:03:10 volumio go-librespot[15636]: time="2026-02-12T01:03:10+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 12 01:03:10 volumio go-librespot[15636]: time="2026-02-12T01:03:10+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 12 01:03:10 volumio go-librespot[15636]: time="2026-02-12T01:03:10+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 12 01:03:10 volumio go-librespot[15636]: time="2026-02-12T01:03:10+07:00" level=info msg="zeroconf server listening on port 41237" Feb 12 01:03:10 volumio go-librespot[15636]: time="2026-02-12T01:03:10+07:00" level=debug msg="obtained new client token: AAAlnmB4r6Nf3Lmvs1HrbBIeUVMbxYNnTR5ag0bYvIC1EJqgKsFFspmTFeJHhQ+OUt/G+gX0jaUQ13JD7bKM0fACI9LlVc91f619N1Yb81kMNvuSHxWf0kIt1RRDbFftzWUBJxBT/rn3WhSOImgJWJ4KBQfkGeaIFEWrE1mkU0kPzmQ/nPJ3kjPPXGc4nYRK4K5Hib2ao69RQEm6K2lWaVR3/XHqiKlatzAJBBjClc1/SFOkGbIW+RHyWw==" Feb 12 01:03:10 volumio go-librespot[15636]: time="2026-02-12T01:03:10+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 12 01:03:10 volumio go-librespot[15636]: time="2026-02-12T01:03:10+07:00" level=debug msg="completed keyexchange" Feb 12 01:03:10 volumio go-librespot[15636]: time="2026-02-12T01:03:10+07:00" level=debug msg="completed challenge" Feb 12 01:03:10 volumio go-librespot[15636]: time="2026-02-12T01:03:10+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 12 01:03:10 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 12 01:03:10 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 12 01:03:11 volumio volumio[15598]: info: Loading plugin "network"... Feb 12 01:03:11 volumio volumio[15598]: info: Refreshing Cached IP Addresses Feb 12 01:03:11 volumio sudo[15645]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 12 01:03:11 volumio sudo[15645]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 01:03:11 volumio sudo[15647]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 12 01:03:11 volumio sudo[15647]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 01:03:11 volumio sudo[15645]: pam_unix(sudo:session): session closed for user root Feb 12 01:03:11 volumio volumio[15598]: info: Loading plugin "services"... Feb 12 01:03:11 volumio volumio[15598]: info: Loading plugin "alsa_controller"... Feb 12 01:03:11 volumio sudo[15647]: pam_unix(sudo:session): session closed for user root Feb 12 01:03:11 volumio sudo[15655]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 12 01:03:11 volumio sudo[15655]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 01:03:11 volumio volumio[15598]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 12 01:03:11 volumio volumio[15598]: info: Loading plugin "wizard"... Feb 12 01:03:11 volumio volumio[15598]: info: Loading plugin "networkfs"... Feb 12 01:03:11 volumio volumio[15598]: info: Starting Udev Watcher for removable devices Feb 12 01:03:11 volumio volumio[15598]: info: Ignoring mount for partition: boot Feb 12 01:03:11 volumio volumio[15598]: info: Ignoring mount for partition: volumio Feb 12 01:03:11 volumio volumio[15598]: info: Ignoring mount for partition: volumio_data Feb 12 01:03:11 volumio volumio[15598]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 12 01:03:11 volumio volumio[15598]: info: Loading plugin "volumio_command_line_client"... Feb 12 01:03:11 volumio volumio[15598]: info: Loading plugin "upnp"... Feb 12 01:03:11 volumio volumio[15598]: info: [1770832991826] Starting Upmpd Daemon Feb 12 01:03:11 volumio volumio[15598]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 12 01:03:11 volumio volumio[15598]: info: Loading plugin "my_music"... Feb 12 01:03:11 volumio volumio[15598]: info: Loading plugin "mpd"... Feb 12 01:03:12 volumio volumio[15598]: info: Loading plugin "upnp_browser"... Feb 12 01:03:14 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Feb 12 01:03:14 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 01:03:14 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 01:03:14 volumio go-librespot[15679]: go-librespot daemon starting... Feb 12 01:03:14 volumio go-librespot[15680]: time="2026-02-12T01:03:14+07:00" level=info msg="running go-librespot 0.4.0" Feb 12 01:03:14 volumio go-librespot[15680]: time="2026-02-12T01:03:14+07:00" level=debug msg="app state loaded" Feb 12 01:03:14 volumio go-librespot[15680]: time="2026-02-12T01:03:14+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 01:03:14 volumio sudo[15655]: pam_unix(sudo:session): session closed for user root Feb 12 01:03:14 volumio go-librespot[15680]: time="2026-02-12T01:03: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-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 12 01:03:14 volumio go-librespot[15680]: time="2026-02-12T01:03:14+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 12 01:03:14 volumio go-librespot[15680]: time="2026-02-12T01:03:14+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 12 01:03:14 volumio go-librespot[15680]: time="2026-02-12T01:03:14+07:00" level=info msg="zeroconf server listening on port 33277" Feb 12 01:03:14 volumio go-librespot[15680]: time="2026-02-12T01:03:14+07:00" level=debug msg="obtained new client token: AAC+1tIbQPTn6OG2+Jrwxae+LJ8DW4CEUsjUdvldd2QvuSk0dsnMHomwQ3ovDOR30281NrtcGR3UAxrxVkWAWYoQN3cliAx36AQHB5eVyuY4rOAs4oIT9+5D9qSiPQtbj3CbsAIASTuw1EYd5DW2NsGppCxM2KAtlt9qpAsUP5qVvMIWWl6wYGLtyYnFBEJHzO2sWEkbbZpPticnbjC1L+eH+EYyyP8jAb2jIXlftiSYR7ASCNwEiK3Iow==" Feb 12 01:03:14 volumio go-librespot[15680]: time="2026-02-12T01:03:14+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 12 01:03:15 volumio go-librespot[15680]: time="2026-02-12T01:03:15+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 12 01:03:15 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 12 01:03:15 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 12 01:03:15 volumio volumio[15598]: info: Starting UPNP Browser Feb 12 01:03:15 volumio volumio[15598]: info: Loading plugin "alarm-clock"... Feb 12 01:03:15 volumio volumio[15598]: info: Loading plugin "airplay_emulation"... Feb 12 01:03:15 volumio volumio[15598]: info: Starting Shairport Sync Feb 12 01:03:15 volumio volumio[15598]: info: Loading plugin "last_100"... Feb 12 01:03:15 volumio volumio[15598]: info: Loading plugin "webradio"... Feb 12 01:03:16 volumio volumio[15598]: info: Loading plugin "i2s_dacs"... Feb 12 01:03:16 volumio volumio[15598]: info: Loading plugin "volumiodiscovery"... Feb 12 01:03:16 volumio volumio[15598]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 12 01:03:16 volumio volumio[15598]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 12 01:03:16 volumio volumio[15598]: *** WARNING *** For more information see Feb 12 01:03:16 volumio volumio[15598]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 12 01:03:16 volumio volumio[15598]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 12 01:03:16 volumio volumio[15598]: *** WARNING *** For more information see Feb 12 01:03:16 volumio node[15598]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 12 01:03:16 volumio node[15598]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 12 01:03:16 volumio node[15598]: *** WARNING *** For more information see Feb 12 01:03:16 volumio node[15598]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 12 01:03:16 volumio node[15598]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 12 01:03:16 volumio node[15598]: *** WARNING *** For more information see Feb 12 01:03:16 volumio volumio[15598]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 12 01:03:16 volumio volumio[15598]: info: Discovery: Started advertising with name: Volumio Feb 12 01:03:16 volumio volumio[15598]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 12 01:03:16 volumio volumio[15598]: info: Loading plugin "spop"... Feb 12 01:03:18 volumio volumio[15598]: info: Loading plugin "ytcr"... Feb 12 01:03:18 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Feb 12 01:03:18 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 01:03:18 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 01:03:18 volumio go-librespot[15689]: go-librespot daemon starting... Feb 12 01:03:18 volumio go-librespot[15690]: time="2026-02-12T01:03:18+07:00" level=info msg="running go-librespot 0.4.0" Feb 12 01:03:18 volumio go-librespot[15690]: time="2026-02-12T01:03:18+07:00" level=debug msg="app state loaded" Feb 12 01:03:18 volumio go-librespot[15690]: time="2026-02-12T01:03:18+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 01:03:18 volumio go-librespot[15690]: time="2026-02-12T01:03:18+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 12 01:03:18 volumio go-librespot[15690]: time="2026-02-12T01:03:18+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 12 01:03:18 volumio go-librespot[15690]: time="2026-02-12T01:03:18+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 12 01:03:18 volumio go-librespot[15690]: time="2026-02-12T01:03:18+07:00" level=info msg="zeroconf server listening on port 34745" Feb 12 01:03:19 volumio go-librespot[15690]: time="2026-02-12T01:03:19+07:00" level=debug msg="obtained new client token: AAA8JhEc5veb/dYQA1j9xPnSXjz5ddO1LXnfE6glmu9ipKfXdMqKFysmnF8uLvAGVvuHR/zImpmuDu50eTseQkU8xW9m5nDBn9nLtjLZro3UC7Q8wCZd/cbt+xhVgNJZWHnC6Yo3BMKM35nHnmRsEXOwe4pe5fk/T2YGHJEv8Q3ltClCY4xOwGxscY7zO5DdH86geJX+6cjRka03SyImjw1icGNXg75z9wYEUfDbxQbC1MH6mSKK/HI=" Feb 12 01:03:19 volumio go-librespot[15690]: time="2026-02-12T01:03:19+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 12 01:03:19 volumio go-librespot[15690]: time="2026-02-12T01:03:19+07:00" level=debug msg="completed keyexchange" Feb 12 01:03:19 volumio go-librespot[15690]: time="2026-02-12T01:03:19+07:00" level=debug msg="completed challenge" Feb 12 01:03:19 volumio go-librespot[15690]: time="2026-02-12T01:03:19+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 12 01:03:19 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 12 01:03:19 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 12 01:03:20 volumio volumio[15598]: info: Loading plugin "ytmusic"... Feb 12 01:03:21 volumio volumio-remote-updater[643]: [2026-02-12 01:03:21] [connect] Successful connection Feb 12 01:03:21 volumio volumio[15598]: info: Loading plugin "outputs"... Feb 12 01:03:21 volumio volumio[15598]: info: Loading plugin "albumart"... Feb 12 01:03:21 volumio volumio[15598]: info: Plugin example_plugin is not enabled Feb 12 01:03:21 volumio volumio[15598]: info: Loading plugin "inputs"... Feb 12 01:03:21 volumio volumio[15598]: info: Loading plugin "updater_comm"... Feb 12 01:03:22 volumio volumio[15598]: info: Plugin mpdemulation is not enabled Feb 12 01:03:22 volumio volumio[15598]: info: Loading plugin "rest_api"... Feb 12 01:03:22 volumio volumio[15598]: info: Loading plugin "websocket"... Feb 12 01:03:22 volumio volumio[15598]: info: Starting Socket.io Server version 1.7.4 Feb 12 01:03:22 volumio volumio[15598]: info: Loading plugin "RoonBridge"... Feb 12 01:03:22 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Feb 12 01:03:22 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 01:03:22 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 01:03:22 volumio go-librespot[15722]: go-librespot daemon starting... Feb 12 01:03:22 volumio go-librespot[15723]: time="2026-02-12T01:03:22+07:00" level=info msg="running go-librespot 0.4.0" Feb 12 01:03:22 volumio go-librespot[15723]: time="2026-02-12T01:03:22+07:00" level=debug msg="app state loaded" Feb 12 01:03:22 volumio go-librespot[15723]: time="2026-02-12T01:03:22+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 01:03:22 volumio volumio[15598]: info: Applying required configuration parameters for plugin RoonBridge Feb 12 01:03:22 volumio volumio[15598]: info: Loading i18n strings for locale en Feb 12 01:03:22 volumio volumio[15598]: Updating browse sources language Feb 12 01:03:22 volumio volumio[15598]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 12 01:03:22 volumio volumio[15712]: Forking 3 albumart workers Feb 12 01:03:23 volumio volumio[15598]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 12 01:03:23 volumio volumio[15598]: info: CoreCommandRouter::initPlayerControls Feb 12 01:03:23 volumio volumio[15598]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 01:03:23 volumio volumio[15598]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 01:03:23 volumio volumio[15598]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 01:03:23 volumio volumio[15598]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 01:03:23 volumio volumio[15598]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 01:03:23 volumio volumio[15598]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 01:03:23 volumio volumio[15598]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 01:03:23 volumio volumio[15598]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 01:03:23 volumio volumio[15598]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 12 01:03:23 volumio volumio[15598]: Express server listening on port 3000 Feb 12 01:03:23 volumio volumio[15598]: [Metrics] WebUI: 16s 204.70ms Feb 12 01:03:23 volumio volumio[15598]: info: CoreStateMachine::resetVolumioState Feb 12 01:03:23 volumio volumio[15598]: info: CoreStateMachine::getcurrentVolume Feb 12 01:03:23 volumio volumio[15598]: info: CoreCommandRouter::volumioRetrievevolume Feb 12 01:03:23 volumio go-librespot[15723]: time="2026-02-12T01:03:23+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 12 01:03:23 volumio go-librespot[15723]: time="2026-02-12T01:03:23+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 12 01:03:23 volumio go-librespot[15723]: time="2026-02-12T01:03:23+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 12 01:03:23 volumio go-librespot[15723]: time="2026-02-12T01:03:23+07:00" level=info msg="zeroconf server listening on port 37513" Feb 12 01:03:23 volumio sudo[15766]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 12 01:03:23 volumio sudo[15766]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 01:03:23 volumio sudo[15766]: pam_unix(sudo:session): session closed for user root Feb 12 01:03:23 volumio sudo[15764]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 12 01:03:23 volumio sudo[15764]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 01:03:23 volumio sudo[15764]: pam_unix(sudo:session): session closed for user root Feb 12 01:03:23 volumio volumio[15598]: info: Volumio Network Manager: Network status updated: 1 Feb 12 01:03:23 volumio go-librespot[15723]: time="2026-02-12T01:03:23+07:00" level=debug msg="obtained new client token: AAAaRGKd/uIZedPgWsfqTxChVeNqJxSSznIgn98HMRp5og3hjQ8WO4CnjQq1lG/RFTXAC31mvwAm7r3DRxy++FNL/J75KTShP77V8ZUw6yAc67mn+Bxv47NHaW4hyHV0Jmid12R4V6fdibdQCj7udXOj6Qngcmf9Dwp9guAad1curXwNCjfW0hk0mXsjQSn+PQW4ZrwbNPlsYWtoOQnJXc8SykdhnKE83r8OV/jGF4e/yWpyoiInVbyOqA==" Feb 12 01:03:23 volumio go-librespot[15723]: time="2026-02-12T01:03:23+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 12 01:03:23 volumio go-librespot[15723]: time="2026-02-12T01:03:23+07:00" level=debug msg="completed keyexchange" Feb 12 01:03:23 volumio go-librespot[15723]: time="2026-02-12T01:03:23+07:00" level=debug msg="completed challenge" Feb 12 01:03:23 volumio volumio[15598]: info: VolumeController:: Volume=100 Mute =false Feb 12 01:03:23 volumio volumio[15598]: info: CoreStateMachine::pushState Feb 12 01:03:23 volumio volumio[15598]: info: CorePlayQueue::getTrack 0 Feb 12 01:03:23 volumio volumio[15598]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 12 01:03:23 volumio volumio[15598]: info: CoreCommandRouter::volumioPushState Feb 12 01:03:23 volumio go-librespot[15723]: time="2026-02-12T01:03:23+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 12 01:03:23 volumio volumio[15598]: info: CoreStateMachine::updateTrackBlock Feb 12 01:03:23 volumio volumio[15598]: info: CorePlayQueue::getTrackBlock Feb 12 01:03:23 volumio volumio[15598]: info: CoreCommandRouter::volumioRetrievevolume Feb 12 01:03:23 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 12 01:03:23 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 12 01:03:23 volumio volumio-remote-updater[643]: [2026-02-12 01:03:23] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1770833001 101 Feb 12 01:03:23 volumio volumio[15598]: 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 12 01:03:24 volumio volumio[15598]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 01:03:24 volumio volumio[15598]: info: Reloading queue from file Feb 12 01:03:24 volumio volumio[15598]: info: CoreStateMachine::setRepeat null single undefined Feb 12 01:03:24 volumio volumio[15598]: info: CoreStateMachine::pushState Feb 12 01:03:24 volumio volumio[15598]: info: CorePlayQueue::getTrack 0 Feb 12 01:03:24 volumio volumio[15598]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 12 01:03:24 volumio volumio[15598]: info: CoreCommandRouter::volumioPushState Feb 12 01:03:24 volumio volumio[15598]: info: CoreStateMachine::setRandom null Feb 12 01:03:24 volumio volumio[15598]: info: CoreStateMachine::pushState Feb 12 01:03:24 volumio volumio[15598]: info: CorePlayQueue::getTrack 0 Feb 12 01:03:24 volumio volumio[15598]: info: CoreCommandRouter::volumioPushState Feb 12 01:03:24 volumio volumio[15598]: info: Setting Device type: Raspberry PI Feb 12 01:03:24 volumio volumio[15598]: info: Completed loading Core Plugins Feb 12 01:03:24 volumio volumio[15598]: info: Preparing to generate the ALSA configuration file Feb 12 01:03:24 volumio volumio[15598]: info: VolumeController:: Volume=100 Mute =false Feb 12 01:03:24 volumio volumio[15598]: info: CoreStateMachine::pushState Feb 12 01:03:24 volumio volumio[15598]: info: CorePlayQueue::getTrack 0 Feb 12 01:03:24 volumio volumio[15598]: info: CoreCommandRouter::volumioPushState Feb 12 01:03:24 volumio volumio[15598]: info: Asound.conf file unchanged, so no further update is needed Feb 12 01:03:24 volumio volumio[15598]: info: Output device has changed, restarting MPD Feb 12 01:03:24 volumio sudo[15780]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 12 01:03:24 volumio sudo[15780]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 01:03:24 volumio volumio[15598]: info: Output device has changed, restarting Shairport Sync Feb 12 01:03:24 volumio volumio[15598]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 01:03:24 volumio volumio[15598]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 01:03:24 volumio sudo[15782]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 12 01:03:24 volumio sudo[15782]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 01:03:24 volumio sudo[15784]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 12 01:03:24 volumio sudo[15784]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 01:03:24 volumio sudo[15782]: pam_unix(sudo:session): session closed for user root Feb 12 01:03:24 volumio volumio[15598]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 12 01:03:24 volumio volumio[15598]: info: ___________ START PLUGINS ___________ Feb 12 01:03:24 volumio volumio[15598]: info: ControllerMpd::onStart: Initializing MPD Feb 12 01:03:24 volumio volumio[15598]: info: Creating MPD Configuration file Feb 12 01:03:24 volumio sudo[15780]: pam_unix(sudo:session): session closed for user root Feb 12 01:03:24 volumio volumio[15598]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 12 01:03:24 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 12 01:03:24 volumio volumio[15598]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 12 01:03:24 volumio volumio[15598]: info: [1770833004768] CoreMusicLibrary::Adding element Media Servers Feb 12 01:03:24 volumio volumio[15598]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 12 01:03:24 volumio sudo[15793]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 12 01:03:24 volumio sudo[15793]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 01:03:24 volumio sudo[15795]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 12 01:03:24 volumio sudo[15793]: pam_unix(sudo:session): session closed for user root Feb 12 01:03:24 volumio sudo[15795]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 01:03:24 volumio volumio[15598]: info: UPNP Browser: Client initialized successfully Feb 12 01:03:24 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 12 01:03:24 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 12 01:03:24 volumio systemd[1]: mpd.service: Consumed 7.154s CPU time. Feb 12 01:03:24 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 12 01:03:24 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 12 01:03:24 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 12 01:03:24 volumio volumio[15598]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 01:03:24 volumio volumio[15598]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 01:03:25 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 12 01:03:25 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 12 01:03:25 volumio volumio[15598]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 12 01:03:25 volumio volumio[15598]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 01:03:25 volumio volumio[15598]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 01:03:25 volumio volumio[15598]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 12 01:03:25 volumio volumio[15598]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 12 01:03:25 volumio volumio[15598]: info: [1770833005210] CoreMusicLibrary::Adding element Last_100 Feb 12 01:03:25 volumio volumio[15598]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 12 01:03:25 volumio volumio[15598]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 12 01:03:25 volumio volumio[15598]: info: [1770833005235] CoreMusicLibrary::Adding element Webradio Feb 12 01:03:25 volumio volumio[15598]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 12 01:03:25 volumio volumio[15598]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 12 01:03:25 volumio volumio[15598]: info: Initializing BBC Radios Feb 12 01:03:25 volumio volumio[15598]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 12 01:03:25 volumio volumio[15598]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 01:03:25 volumio sudo[15803]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 12 01:03:25 volumio sudo[15803]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 12 01:03:25 volumio volumio[15598]: info: Creating Spotify config file Feb 12 01:03:25 volumio volumio[15598]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 01:03:25 volumio sudo[15803]: pam_unix(sudo:session): session closed for user root Feb 12 01:03:25 volumio volumio[15732]: Starting albumart workers Feb 12 01:03:26 volumio volumio[15730]: Starting albumart workers Feb 12 01:03:26 volumio volumio[15731]: Starting albumart workers Feb 12 01:03:26 volumio volumio[15598]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 12 01:03:26 volumio volumio[15598]: info: [1770833006566] CoreMusicLibrary::Adding element YouTube Music Feb 12 01:03:26 volumio volumio[15598]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 12 01:03:26 volumio volumio[15598]: Cannot find translation for source YouTube Music Feb 12 01:03:26 volumio volumio[15598]: info: Volumio Calling Home Feb 12 01:03:26 volumio sudo[15824]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Feb 12 01:03:26 volumio sudo[15824]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 01:03:26 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Feb 12 01:03:26 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 01:03:27 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 01:03:27 volumio go-librespot[15829]: go-librespot daemon starting... Feb 12 01:03:27 volumio sudo[15824]: pam_unix(sudo:session): session closed for user root Feb 12 01:03:27 volumio go-librespot[15830]: time="2026-02-12T01:03:27+07:00" level=info msg="running go-librespot 0.4.0" Feb 12 01:03:27 volumio volumio[15598]: info: MPD Permissions set Feb 12 01:03:27 volumio volumio[15598]: info: MPD Permissions set Feb 12 01:03:27 volumio volumio[15598]: info: Upmpdcli Daemon Started Feb 12 01:03:27 volumio volumio[15598]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Feb 12 01:03:27 volumio volumio[15598]: info: Discovery: Found device Volumio Feb 12 01:03:27 volumio volumio[15598]: info: CoreCommandRouter::volumioGetState Feb 12 01:03:27 volumio volumio[15598]: info: CorePlayQueue::getTrack 0 Feb 12 01:03:27 volumio volumio[15598]: info: Volumio called home Feb 12 01:03:27 volumio volumio[15598]: info: Spotify config file written Feb 12 01:03:27 volumio volumio[15598]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Feb 12 01:03:27 volumio volumio[15598]: info: Discovery: Found device Volumio Feb 12 01:03:27 volumio volumio[15598]: info: CoreCommandRouter::volumioGetState Feb 12 01:03:27 volumio volumio[15598]: info: CorePlayQueue::getTrack 0 Feb 12 01:03:27 volumio sudo[15840]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 12 01:03:27 volumio sudo[15840]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 01:03:27 volumio go-librespot[15830]: time="2026-02-12T01:03:27+07:00" level=info msg="zeroconf server listening on port 45371" Feb 12 01:03:28 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Feb 12 01:03:28 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Feb 12 01:03:28 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 01:03:28 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 01:03:28 volumio go-librespot[15842]: go-librespot daemon starting... Feb 12 01:03:28 volumio sudo[15840]: pam_unix(sudo:session): session closed for user root Feb 12 01:03:28 volumio go-librespot[15849]: time="2026-02-12T01:03:28+07:00" level=info msg="running go-librespot 0.4.0" Feb 12 01:03:28 volumio go-librespot[15849]: time="2026-02-12T01:03:28+07:00" level=debug msg="app state loaded" Feb 12 01:03:28 volumio go-librespot[15849]: time="2026-02-12T01:03:28+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 01:03:28 volumio volumio[15598]: 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 12 01:03:28 volumio volumio[15598]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 01:03:28 volumio volumio[15598]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 01:03:28 volumio volumio[15598]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 01:03:28 volumio volumio[15598]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 01:03:28 volumio volumio[15598]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 01:03:28 volumio volumio[15598]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 01:03:28 volumio volumio[15598]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 01:03:28 volumio volumio[15598]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 01:03:28 volumio volumio[15598]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 01:03:28 volumio volumio[15598]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 01:03:28 volumio volumio[15598]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 01:03:28 volumio volumio[15598]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 01:03:28 volumio volumio[15598]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 01:03:28 volumio volumio[15598]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 01:03:28 volumio volumio[15598]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 01:03:28 volumio volumio[15598]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 01:03:28 volumio volumio[15598]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 01:03:28 volumio volumio[15598]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 01:03:28 volumio volumio[15598]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 01:03:28 volumio volumio[15598]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 01:03:28 volumio volumio[15598]: info: No need to fix Spotify hosts Feb 12 01:03:28 volumio go-librespot[15849]: time="2026-02-12T01:03:28+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 12 01:03:28 volumio go-librespot[15849]: time="2026-02-12T01:03:28+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 12 01:03:28 volumio go-librespot[15849]: time="2026-02-12T01:03:28+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 12 01:03:28 volumio go-librespot[15849]: time="2026-02-12T01:03:28+07:00" level=info msg="zeroconf server listening on port 46875" Feb 12 01:03:29 volumio go-librespot[15849]: time="2026-02-12T01:03:29+07:00" level=debug msg="obtained new client token: AADcrZyxZAJIAJrPct0IbMtI963BGmWkNl9Qyzbi1TQU/W4LTuJwPcU3d4FekkQAkfuVYvPcow8hKZtXLrJUmhmNpd5oTcr5FL13BqxliUo5iYgDigsjSs+90e4CVBQcZ9D4E5Xy1cBcCOKhgwG2zlpT768pvBFvw4oJScNRHrnMvbR1HYdPz0V3UBNInk5x2DbH0UDINL3o9jCreT3V45JxnBTRgWu5JjdkQBDN+waUKFWlGDnO72s=" Feb 12 01:03:29 volumio go-librespot[15849]: time="2026-02-12T01:03:29+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 12 01:03:29 volumio go-librespot[15849]: time="2026-02-12T01:03:29+07:00" level=debug msg="completed keyexchange" Feb 12 01:03:29 volumio go-librespot[15849]: time="2026-02-12T01:03:29+07:00" level=debug msg="completed challenge" Feb 12 01:03:29 volumio go-librespot[15849]: time="2026-02-12T01:03:29+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 12 01:03:29 volumio volumio[15598]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 12 01:03:29 volumio volumio[15598]: SPOTIFY: BQBHqy1QujbQUq1ynDoMec8IodVlWhFtF3nEq5wLquN6fILycczrFugSxqttPEoa8xd-nnJHR7WXNxg3XEZvhX6zHduSbAR_oKBfzmGfoyDjTvTt0UtSiqYHO_TlpPuGb1HAixyB800Gj_q_2sRPJZO606sBblIYnUk5mLt2OapleS9VlomHgHGdYpBZrWqRR7aDGv5Dsn-a3M2GYx2gU_2QAGspYIsvweFfsKoZ0x4KWVD_KfzNEv7-7F9K_rv_JOBRYUlxJl3rawC5gquJqLMMc4G1E32xFnLyyxlDobJ4v-IlayREe021 Feb 12 01:03:29 volumio volumio[15598]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 12 01:03:29 volumio volumio[15598]: info: New Spotify access token = BQBHqy1QujbQUq1ynDoMec8IodVlWhFtF3nEq5wLquN6fILycczrFugSxqttPEoa8xd-nnJHR7WXNxg3XEZvhX6zHduSbAR_oKBfzmGfoyDjTvTt0UtSiqYHO_TlpPuGb1HAixyB800Gj_q_2sRPJZO606sBblIYnUk5mLt2OapleS9VlomHgHGdYpBZrWqRR7aDGv5Dsn-a3M2GYx2gU_2QAGspYIsvweFfsKoZ0x4KWVD_KfzNEv7-7F9K_rv_JOBRYUlxJl3rawC5gquJqLMMc4G1E32xFnLyyxlDobJ4v-IlayREe021 Feb 12 01:03:29 volumio volumio[15598]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 12 01:03:29 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 12 01:03:29 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 12 01:03:29 volumio volumio[15598]: info: Starting Shairport Sync Feb 12 01:03:29 volumio volumio[15598]: info: Starting Shairport Sync Feb 12 01:03:29 volumio volumio[15598]: info: Starting Shairport Sync Feb 12 01:03:29 volumio sudo[15880]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 12 01:03:29 volumio sudo[15880]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 01:03:29 volumio sudo[15882]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 12 01:03:29 volumio sudo[15882]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 01:03:29 volumio sudo[15885]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 12 01:03:29 volumio sudo[15885]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 01:03:29 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 12 01:03:29 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 12 01:03:29 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 12 01:03:29 volumio systemd[1]: shairport-sync.service: Consumed 2.368s CPU time. Feb 12 01:03:29 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 12 01:03:29 volumio sudo[15880]: pam_unix(sudo:session): session closed for user root Feb 12 01:03:29 volumio sudo[15885]: pam_unix(sudo:session): session closed for user root Feb 12 01:03:29 volumio volumio[15598]: info: Shairport-Sync Started Feb 12 01:03:29 volumio volumio[15598]: Error adding Membership: Error: addMembership EINVAL Feb 12 01:03:29 volumio sudo[15882]: pam_unix(sudo:session): session closed for user root Feb 12 01:03:29 volumio volumio[15598]: info: CoreCommandRouter::volumioGetState Feb 12 01:03:29 volumio volumio[15598]: info: CorePlayQueue::getTrack 0 Feb 12 01:03:30 volumio volumio[15598]: info: Shairport-Sync Started Feb 12 01:03:30 volumio volumio[15598]: info: Shairport-Sync Started Feb 12 01:03:30 volumio volumio[15598]: 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 12 01:03:30 volumio volumio[15598]: info: Spotify Successfully logged in Feb 12 01:03:30 volumio volumio[15598]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 12 01:03:30 volumio volumio[15598]: info: [1770833010302] CoreMusicLibrary::Adding element Spotify Feb 12 01:03:30 volumio volumio[15598]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 12 01:03:30 volumio volumio[15598]: Cannot find translation for source YouTube Music Feb 12 01:03:30 volumio volumio[15598]: Cannot find translation for source Spotify Feb 12 01:03:31 volumio volumio[15598]: info: [yt-cast-receiver] DIAL server listening on port 8098 Feb 12 01:03:31 volumio volumio[15598]: info: CoreCommandRouter::volumioRetrievevolume Feb 12 01:03:31 volumio volumio[15598]: info: VolumeController:: Volume=100 Mute =false Feb 12 01:03:31 volumio volumio[15598]: info: CoreCommandRouter::volumioGetState Feb 12 01:03:31 volumio volumio[15598]: info: CorePlayQueue::getTrack 0 Feb 12 01:03:31 volumio volumio[15598]: info: CoreStateMachine::pushState Feb 12 01:03:31 volumio volumio[15598]: info: CorePlayQueue::getTrack 0 Feb 12 01:03:31 volumio volumio[15598]: info: CoreCommandRouter::volumioPushState Feb 12 01:03:32 volumio volumio[15598]: info: go-librespot daemon successfully initialized Feb 12 01:03:32 volumio mpd[15822]: 2026-02-12T01:03:32 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 12 01:03:32 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 12 01:03:32 volumio sudo[15784]: pam_unix(sudo:session): session closed for user root Feb 12 01:03:32 volumio sudo[15795]: pam_unix(sudo:session): session closed for user root Feb 12 01:03:32 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Feb 12 01:03:32 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 01:03:32 volumio volumio[15598]: error: MPD error: The expression evaluated to a falsy value: Feb 12 01:03:32 volumio volumio[15598]: assert.ok(self.idling) Feb 12 01:03:32 volumio volumio[15598]: error: The expression evaluated to a falsy value: Feb 12 01:03:32 volumio volumio[15598]: assert.ok(self.idling) Feb 12 01:03:32 volumio volumio[15598]: info: MPD running with PID15822 Feb 12 01:03:32 volumio volumio[15598]: ,establishing connection Feb 12 01:03:32 volumio volumio[15598]: error: updateQueue error: null Feb 12 01:03:32 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 01:03:32 volumio go-librespot[15924]: go-librespot daemon starting... Feb 12 01:03:32 volumio volumio[15598]: info: Completed starting Core Plugins Feb 12 01:03:32 volumio volumio[15598]: info: ------------------------------------------- Feb 12 01:03:32 volumio volumio[15598]: info: ----- MyVolumio plugins startup ---- Feb 12 01:03:32 volumio volumio[15598]: info: ------------------------------------------- Feb 12 01:03:32 volumio volumio[15598]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 12 01:03:32 volumio go-librespot[15925]: time="2026-02-12T01:03:32+07:00" level=info msg="running go-librespot 0.4.0" Feb 12 01:03:32 volumio go-librespot[15925]: time="2026-02-12T01:03:32+07:00" level=debug msg="app state loaded" Feb 12 01:03:32 volumio go-librespot[15925]: time="2026-02-12T01:03:32+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 01:03:32 volumio volumio[15598]: error: updateQueue error: null Feb 12 01:03:33 volumio go-librespot[15925]: time="2026-02-12T01:03:33+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 12 01:03:33 volumio go-librespot[15925]: time="2026-02-12T01:03:33+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 12 01:03:33 volumio go-librespot[15925]: time="2026-02-12T01:03:33+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 12 01:03:33 volumio go-librespot[15925]: time="2026-02-12T01:03:33+07:00" level=info msg="zeroconf server listening on port 38293" Feb 12 01:03:33 volumio go-librespot[15925]: time="2026-02-12T01:03:33+07:00" level=debug msg="obtained new client token: AACYBgmWaOD5S/J+MS0UWcaZk9P1vPjAK/8t4hDA4q+bDIlB7la59gZUhRVPzVQ4ScSKn6yXq49IYzF3uP8OmsAfzeQP28z01b6JTTg709WKvSsz8ylyUuMky3htfolhW0zAkoes6k61/hJVMjclppevfzjKdBAWp7h3Ok2BjLLE3slVgIn3wgXOVw23doEyestemtqAKM9mKa3LcOw2z/8m2Te5cHopIXjLhjfqY1QR8764AaGSNRC3tA==" Feb 12 01:03:33 volumio go-librespot[15925]: time="2026-02-12T01:03:33+07:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:4070, retrying with a different AP" error="dial tcp 104.199.241.202:4070: connect: connection refused" Feb 12 01:03:33 volumio go-librespot[15925]: time="2026-02-12T01:03:33+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Feb 12 01:03:33 volumio go-librespot[15925]: time="2026-02-12T01:03:33+07:00" level=debug msg="completed keyexchange" Feb 12 01:03:33 volumio go-librespot[15925]: time="2026-02-12T01:03:33+07:00" level=debug msg="completed challenge" Feb 12 01:03:33 volumio go-librespot[15925]: time="2026-02-12T01:03:33+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 12 01:03:33 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 12 01:03:33 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 12 01:03:35 volumio volumio[15598]: info: Initializing connection to go-librespot Websocket Feb 12 01:03:35 volumio volumio[15598]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 12 01:03:36 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Feb 12 01:03:36 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 01:03:36 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 01:03:36 volumio go-librespot[15935]: go-librespot daemon starting... Feb 12 01:03:36 volumio go-librespot[15936]: time="2026-02-12T01:03:36+07:00" level=info msg="running go-librespot 0.4.0" Feb 12 01:03:36 volumio go-librespot[15936]: time="2026-02-12T01:03:36+07:00" level=debug msg="app state loaded" Feb 12 01:03:36 volumio go-librespot[15936]: time="2026-02-12T01:03:36+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 01:03:37 volumio go-librespot[15936]: time="2026-02-12T01:03:37+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 12 01:03:37 volumio go-librespot[15936]: time="2026-02-12T01:03:37+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 12 01:03:37 volumio go-librespot[15936]: time="2026-02-12T01:03:37+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 12 01:03:37 volumio go-librespot[15936]: time="2026-02-12T01:03:37+07:00" level=info msg="zeroconf server listening on port 33189" Feb 12 01:03:37 volumio volumio[15598]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 12 01:03:37 volumio go-librespot[15936]: time="2026-02-12T01:03:37+07:00" level=debug msg="obtained new client token: AACB2xhxkp+ulOvGH10/gOZ9qn9DbEj/VJPfxPsDoep7OkuyCw/mWqzEkuQzNlUeGUDl0tNsstRMmVOm/2i1+WcswT7+fPUnl4xCf/16RnnGUxTkvDbdNIjkrRD5Bmn8oOvNgF5lKQVGGQBlXOBtJLy/QLeKJ5jZobpydIAGbokKu55y/kuwPJsugC0VsZOwxlJGVFBZkt/UKfqR/MRh9VN0dYLCp+DUyO7HCphHSdH+lXPtN+COgk0OOA==" Feb 12 01:03:37 volumio go-librespot[15936]: time="2026-02-12T01:03:37+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 12 01:03:37 volumio go-librespot[15936]: time="2026-02-12T01:03:37+07:00" level=debug msg="completed keyexchange" Feb 12 01:03:37 volumio go-librespot[15936]: time="2026-02-12T01:03:37+07:00" level=debug msg="completed challenge" Feb 12 01:03:37 volumio go-librespot[15936]: time="2026-02-12T01:03: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 12 01:03:37 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 12 01:03:37 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 12 01:03:38 volumio volumio[15598]: info: Initializing connection to go-librespot Websocket Feb 12 01:03:38 volumio volumio[15598]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 12 01:03:41 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Feb 12 01:03:41 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 01:03:41 volumio volumio[15598]: info: Initializing connection to go-librespot Websocket Feb 12 01:03:41 volumio volumio[15598]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 12 01:03:41 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 01:03:41 volumio go-librespot[15943]: go-librespot daemon starting... Feb 12 01:03:41 volumio go-librespot[15944]: time="2026-02-12T01:03:41+07:00" level=info msg="running go-librespot 0.4.0" Feb 12 01:03:41 volumio go-librespot[15944]: time="2026-02-12T01:03:41+07:00" level=debug msg="app state loaded" Feb 12 01:03:41 volumio go-librespot[15944]: time="2026-02-12T01:03:41+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 01:03:41 volumio volumio[15598]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 12 01:03:41 volumio volumio[15598]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 12 01:03:41 volumio volumio[15598]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 12 01:03:41 volumio volumio[15598]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 12 01:03:41 volumio volumio[15598]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 12 01:03:41 volumio volumio[15598]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 12 01:03:41 volumio volumio[15598]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 12 01:03:41 volumio volumio[15598]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 12 01:03:41 volumio volumio[15598]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 12 01:03:41 volumio volumio[15598]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 12 01:03:41 volumio volumio[15598]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 12 01:03:41 volumio volumio[15598]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 12 01:03:41 volumio volumio[15598]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 12 01:03:41 volumio volumio[15598]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 12 01:03:41 volumio volumio[15598]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 12 01:03:41 volumio volumio[15598]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 12 01:03:41 volumio volumio[15598]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 12 01:03:41 volumio volumio[15598]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 12 01:03:41 volumio volumio[15598]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 12 01:03:41 volumio volumio[15598]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 12 01:03:41 volumio volumio[15598]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 12 01:03:41 volumio volumio[15598]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 12 01:03:41 volumio volumio[15598]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 12 01:03:41 volumio volumio[15598]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 12 01:03:41 volumio volumio[15598]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 12 01:03:41 volumio volumio[15598]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 12 01:03:41 volumio volumio[15598]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 12 01:03:41 volumio volumio[15598]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 12 01:03:41 volumio volumio[15598]: info: Adding plugin bluetooth to MyMusic Plugins Feb 12 01:03:41 volumio volumio[15598]: info: Adding plugin multiroom to MyMusic Plugins Feb 12 01:03:41 volumio volumio[15598]: info: Adding plugin metavolumio to MyMusic Plugins Feb 12 01:03:41 volumio volumio[15598]: info: Adding plugin cd_controller to MyMusic Plugins Feb 12 01:03:41 volumio volumio[15598]: info: Adding plugin qobuzconnect to MyMusic Plugins Feb 12 01:03:41 volumio volumio[15598]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 12 01:03:41 volumio volumio[15598]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 12 01:03:41 volumio volumio[15598]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 12 01:03:41 volumio go-librespot[15944]: time="2026-02-12T01:03:41+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 12 01:03:41 volumio go-librespot[15944]: time="2026-02-12T01:03:41+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 12 01:03:41 volumio go-librespot[15944]: time="2026-02-12T01:03:41+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 12 01:03:41 volumio go-librespot[15944]: time="2026-02-12T01:03:41+07:00" level=info msg="zeroconf server listening on port 40437" Feb 12 01:03:41 volumio go-librespot[15944]: time="2026-02-12T01:03:41+07:00" level=debug msg="obtained new client token: AACY4bTtmtgRpXuSLvTdjfa7FQ91bPOJRWcMuxN/DLh5B2nIWPrp0ZntHJ5sMkdHfB/3swPGZZlidJyKOdL1hVyNL3Dk4/h4gnmEP8t8m42uWQx9VstJsDE2LF3M6mz8oqMX5zo9PRpgJyhhA46REn35v6d2jSgGC7g+QibGWaUa1fWZ4jUjq0dBmfrWE9DO4BWNvZj0TooiQlDrp7YEdDlH/hIEwgbiXlrrX/If0LbXvDUC3z5ui2WX3A==" Feb 12 01:03:41 volumio go-librespot[15944]: time="2026-02-12T01:03:41+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 12 01:03:42 volumio go-librespot[15944]: time="2026-02-12T01:03:42+07:00" level=debug msg="completed keyexchange" Feb 12 01:03:42 volumio go-librespot[15944]: time="2026-02-12T01:03:42+07:00" level=debug msg="completed challenge" Feb 12 01:03:42 volumio go-librespot[15944]: time="2026-02-12T01:03:42+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 12 01:03:42 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 12 01:03:42 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 12 01:03:43 volumio volumio[15598]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 12 01:03:43 volumio volumio[15598]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 12 01:03:43 volumio volumio[15598]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 01:03:43 volumio volumio[15598]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 01:03:43 volumio volumio[15598]: info: Starting MyVolumio Remote Streaming Endpoints Feb 12 01:03:43 volumio volumio[15598]: info: MyVolumio login type: Token Feb 12 01:03:43 volumio volumio[15598]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 12 01:03:43 volumio volumio[15598]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 12 01:03:45 volumio volumio[15598]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 12 01:03:45 volumio volumio[15598]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 12 01:03:45 volumio volumio[15598]: info: Streaming services startup Feb 12 01:03:45 volumio volumio[15598]: info: Starting Streaming Daemon Feb 12 01:03:45 volumio sudo[15966]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 12 01:03:45 volumio sudo[15966]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 01:03:45 volumio volumio[15598]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 12 01:03:45 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Feb 12 01:03:45 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 01:03:45 volumio volumio[15598]: info: Initializing connection to go-librespot Websocket Feb 12 01:03:45 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 01:03:45 volumio go-librespot[15972]: go-librespot daemon starting... Feb 12 01:03:45 volumio sudo[15966]: pam_unix(sudo:session): session closed for user root Feb 12 01:03:45 volumio volumio[15598]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 12 01:03:45 volumio volumio[15598]: error: Cannot start Volumio Streaming Daemon Feb 12 01:03:45 volumio volumio[15598]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 12 01:03:45 volumio volumio[15598]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 12 01:03:45 volumio go-librespot[15973]: time="2026-02-12T01:03:45+07:00" level=info msg="running go-librespot 0.4.0" Feb 12 01:03:45 volumio go-librespot[15973]: time="2026-02-12T01:03:45+07:00" level=debug msg="app state loaded" Feb 12 01:03:45 volumio go-librespot[15973]: time="2026-02-12T01:03:45+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 01:03:45 volumio go-librespot[15973]: time="2026-02-12T01:03: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 12 01:03:45 volumio go-librespot[15973]: time="2026-02-12T01:03:45+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 12 01:03:45 volumio go-librespot[15973]: time="2026-02-12T01:03:45+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 12 01:03:46 volumio go-librespot[15973]: time="2026-02-12T01:03:46+07:00" level=info msg="zeroconf server listening on port 39885" Feb 12 01:03:46 volumio go-librespot[15973]: time="2026-02-12T01:03:46+07:00" level=debug msg="obtained new client token: AADknmIUymq+ZjyxzApB3DktVBU4+PWpC3wqUpBJNjzsF9WkOrbw4FKWMbInIQp8xjN43rKD+ajzb5B0NcgO9vTe5xp9brxzudArqEomk53orCsWo+XOWAqnZ6VjsxNCO0qA5h5iBLhH6ARuKF0eLTR0XmBhgoEH4pcDqt5NCYYfSSZKf+p4wYR/G0Dtg7+E8kHX1NY/m4Bka0abOMpCAnbTK55wNTZFPc1U57Q74oYtXl9nurhtNwI=" Feb 12 01:03:46 volumio volumio[15598]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Feb 12 01:03:46 volumio go-librespot[15973]: time="2026-02-12T01:03:46+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 12 01:03:46 volumio go-librespot[15973]: time="2026-02-12T01:03:46+07:00" level=debug msg="completed keyexchange" Feb 12 01:03:46 volumio go-librespot[15973]: time="2026-02-12T01:03:46+07:00" level=debug msg="completed challenge" Feb 12 01:03:46 volumio go-librespot[15973]: time="2026-02-12T01:03:46+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 12 01:03:46 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 12 01:03:46 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 12 01:03:47 volumio volumio[15598]: info: MyVolumio token set successfully Feb 12 01:03:47 volumio volumio[15598]: info: MYVOLUMIO: Adding device Feb 12 01:03:47 volumio volumio[15598]: info: MYVOLUMIO: Evaluating Server Feb 12 01:03:48 volumio volumio[15598]: info: MyVolumio status changed Feb 12 01:03:48 volumio volumio[15598]: info: Streaming services startup Feb 12 01:03:48 volumio volumio[15598]: info: Starting Streaming Daemon Feb 12 01:03:48 volumio volumio[15598]: info: Removing browser output: myVolumio user plan is not superstar Feb 12 01:03:48 volumio volumio[15598]: info: Removing audio output: Feb 12 01:03:48 volumio volumio[15598]: info: Stoppping Tunnel 1 Feb 12 01:03:48 volumio sudo[16002]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 12 01:03:48 volumio sudo[16002]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 01:03:48 volumio sudo[16005]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Feb 12 01:03:48 volumio sudo[16005]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 01:03:48 volumio sudo[16002]: pam_unix(sudo:session): session closed for user root Feb 12 01:03:48 volumio volumio[15598]: error: Cannot start Volumio Streaming Daemon Feb 12 01:03:48 volumio volumio[15598]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 12 01:03:48 volumio volumio[15598]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 12 01:03:48 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 12 01:03:48 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 12 01:03:48 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 12 01:03:48 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 12 01:03:48 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 12 01:03:48 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 12 01:03:48 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 12 01:03:48 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 12 01:03:48 volumio sudo[16005]: pam_unix(sudo:session): session closed for user root Feb 12 01:03:48 volumio volumio[15598]: info: Setting Geolocation for MyVolumio to as1 Feb 12 01:03:48 volumio volumio[15598]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 01:03:48 volumio volumio[15598]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 01:03:48 volumio volumio[15598]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 01:03:48 volumio volumio[15598]: info: Remote SSH Stopped Feb 12 01:03:48 volumio volumio[15598]: info: Initializing connection to go-librespot Websocket Feb 12 01:03:48 volumio volumio[15598]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 12 01:03:48 volumio volumio[15598]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Feb 12 01:03:49 volumio volumio[15598]: info: Updating MyVolumio device info Feb 12 01:03:49 volumio volumio[15598]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 01:03:49 volumio volumio[15598]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 01:03:49 volumio volumio[15598]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 01:03:49 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Feb 12 01:03:49 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 01:03:49 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 01:03:49 volumio go-librespot[16008]: go-librespot daemon starting... Feb 12 01:03:49 volumio go-librespot[16009]: time="2026-02-12T01:03:49+07:00" level=info msg="running go-librespot 0.4.0" Feb 12 01:03:49 volumio go-librespot[16009]: time="2026-02-12T01:03:49+07:00" level=debug msg="app state loaded" Feb 12 01:03:49 volumio go-librespot[16009]: time="2026-02-12T01:03:49+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 01:03:49 volumio volumio[15598]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Feb 12 01:03:50 volumio go-librespot[16009]: time="2026-02-12T01:03:50+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 12 01:03:50 volumio go-librespot[16009]: time="2026-02-12T01:03:50+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 12 01:03:50 volumio go-librespot[16009]: time="2026-02-12T01:03:50+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 12 01:03:50 volumio go-librespot[16009]: time="2026-02-12T01:03:50+07:00" level=info msg="zeroconf server listening on port 45367" Feb 12 01:03:50 volumio go-librespot[16009]: time="2026-02-12T01:03:50+07:00" level=debug msg="obtained new client token: AABInmsDE7uNdq8YBXPWLFjq+vAL/7G8cIHG1R156TbI3Xuhc3846OoPaKyG2FbC2geZKA2w6tz9wFsIG7j/4ROZK8iuRSDXS6UmQ/dy1ja7kVED9+O11WVtrgFyO2sMeA/fEx+CO13oK6AS/BKIKr9nVGub7vbGgkEvJTJnhl+HiddDnQl5WMzPF+LHjtRXUW7h9A+/ze8qvqXaUAHtj/FHzgEH0vzqSimh7Ug3qAVoXwE8wynCFceCiA==" Feb 12 01:03:50 volumio go-librespot[16009]: time="2026-02-12T01:03:50+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 12 01:03:50 volumio go-librespot[16009]: time="2026-02-12T01:03:50+07:00" level=debug msg="completed keyexchange" Feb 12 01:03:50 volumio go-librespot[16009]: time="2026-02-12T01:03:50+07:00" level=debug msg="completed challenge" Feb 12 01:03:50 volumio go-librespot[16009]: time="2026-02-12T01:03:50+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 12 01:03:50 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 12 01:03:50 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 12 01:03:51 volumio volumio[15598]: info: Initializing connection to go-librespot Websocket Feb 12 01:03:51 volumio volumio[15598]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 12 01:03:52 volumio volumio[15598]: info: MYVOLUMIO: Adding device Feb 12 01:03:52 volumio volumio[15598]: info: MYVOLUMIO: Evaluating Server Feb 12 01:03:53 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Feb 12 01:03:53 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 01:03:53 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 01:03:53 volumio go-librespot[16031]: go-librespot daemon starting... Feb 12 01:03:53 volumio go-librespot[16032]: time="2026-02-12T01:03:53+07:00" level=info msg="running go-librespot 0.4.0" Feb 12 01:03:53 volumio go-librespot[16032]: time="2026-02-12T01:03:53+07:00" level=debug msg="app state loaded" Feb 12 01:03:53 volumio go-librespot[16032]: time="2026-02-12T01:03:53+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 01:03:54 volumio volumio[15598]: info: Initializing connection to go-librespot Websocket Feb 12 01:03:54 volumio go-librespot[16032]: time="2026-02-12T01:03:54+07:00" level=debug msg="new websocket client" Feb 12 01:03:54 volumio volumio[15598]: info: Connection to go-librespot Websocket established Feb 12 01:03:54 volumio volumio[15598]: info: Setting Geolocation for MyVolumio to as1 Feb 12 01:03:54 volumio volumio[15598]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 01:03:54 volumio volumio[15598]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 01:03:54 volumio volumio[15598]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 01:03:54 volumio go-librespot[16032]: time="2026-02-12T01:03:54+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 12 01:03:54 volumio go-librespot[16032]: time="2026-02-12T01:03:54+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 12 01:03:54 volumio go-librespot[16032]: time="2026-02-12T01:03:54+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 12 01:03:54 volumio go-librespot[16032]: time="2026-02-12T01:03:54+07:00" level=info msg="zeroconf server listening on port 34371" Feb 12 01:03:54 volumio go-librespot[16032]: time="2026-02-12T01:03:54+07:00" level=debug msg="obtained new client token: AAD1/5yRBJ1EWWzaPgJjQaOBXmUhuxJdu6G8gTY71eN69buIsU0KKfnh7aQZD90AmYVtirmZjCEgvoPgdVlB2C62eM+mIwRgbW0Nw79WctmFCP6Znk4qr1U//bH1ImiHgX+2yPIFcoOSyi73prHilvVi6A2YXXlFz85HUkOOgCcSeQUnFWaWgnyjDxzQoalT7HTGK9c9cBA2rcCc5bSkcWJGQg4CcQltQt1n+mbIvFvwt0f3PGRUCfnDYg==" Feb 12 01:03:54 volumio go-librespot[16032]: time="2026-02-12T01:03:54+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 12 01:03:54 volumio go-librespot[16032]: time="2026-02-12T01:03:54+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 12 01:03:54 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 12 01:03:54 volumio volumio[15598]: info: Connection to go-librespot Websocket closed Feb 12 01:03:54 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 12 01:03:55 volumio volumio[15598]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Feb 12 01:03:55 volumio volumio[15598]: info: Updating MyVolumio device info Feb 12 01:03:55 volumio volumio[15598]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 01:03:55 volumio volumio[15598]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 01:03:55 volumio volumio[15598]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 01:03:55 volumio volumio[15598]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Feb 12 01:03:56 volumio volumio[15598]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 12 01:03:56 volumio volumio[15598]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 01:03:56 volumio volumio[15598]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Feb 12 01:03:56 volumio volumio-remote-updater[643]: Test mode disabled Feb 12 01:03:56 volumio volumio-remote-updater[643]: Alpha mode disabled Feb 12 01:03:56 volumio volumio-remote-updater[643]: Alpha legacy test mode disabled Feb 12 01:03:56 volumio volumio[15598]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled Feb 12 01:03:57 volumio volumio[15598]: info: Update Ready: {"changeLogLink":"http://volumio.org","description":"

FIXES

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

NEW ADDITIONS

\n
    \n
  • Add BLE onboarding plugin
    • \n
  • Enable vc4-kms-v3d for all compatible RPi models
    • \n
  • Update Tidal SDK
    • \n
\n","title":"Update v4.096","updateavailable":true} Feb 12 01:03:57 volumio volumio[15598]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Feb 12 01:03:57 volumio volumio[15598]: info: Getting Spotify volume Feb 12 01:03:57 volumio volumio[15598]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 12 01:03:57 volumio volumio[15598]: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 12 01:03:57 volumio volumio[15598]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Feb 12 01:03:57 volumio volumio[15598]: errno: -111, Feb 12 01:03:57 volumio volumio[15598]: code: 'ECONNREFUSED', Feb 12 01:03:57 volumio volumio[15598]: syscall: 'connect', Feb 12 01:03:57 volumio volumio[15598]: address: '127.0.0.1', Feb 12 01:03:57 volumio volumio[15598]: port: 9879, Feb 12 01:03:57 volumio volumio[15598]: response: undefined Feb 12 01:03:57 volumio volumio[15598]: } Feb 12 01:03:57 volumio volumio[15598]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 12 01:03:58 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Feb 12 01:03:58 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 01:03:58 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 01:03:58 volumio go-librespot[16075]: go-librespot daemon starting... Feb 12 01:03:58 volumio go-librespot[16076]: time="2026-02-12T01:03:58+07:00" level=info msg="running go-librespot 0.4.0" Feb 12 01:03:58 volumio go-librespot[16076]: time="2026-02-12T01:03:58+07:00" level=debug msg="app state loaded" Feb 12 01:03:58 volumio go-librespot[16076]: time="2026-02-12T01:03:58+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 01:03:58 volumio go-librespot[16076]: time="2026-02-12T01:03:58+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 12 01:03:58 volumio go-librespot[16076]: time="2026-02-12T01:03:58+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 12 01:03:58 volumio go-librespot[16076]: time="2026-02-12T01:03:58+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 12 01:03:58 volumio go-librespot[16076]: time="2026-02-12T01:03:58+07:00" level=info msg="zeroconf server listening on port 33211" Feb 12 01:03:58 volumio go-librespot[16076]: time="2026-02-12T01:03:58+07:00" level=debug msg="obtained new client token: AAAJzhu40cODtTN+V0+mN05jwwQv0rrJby/XB6iHzcVX3hrQGnlenCc5J8S2pRY1nrlP0qddz2e9ZgLDV1aJxa375tW59vVZik4JLtXjzV487sfglgRRy1B/nNrP+k1em3MAo3ffXK/t3d4ydEGAiykeeEemQh4VFfb6zK55XYLl5z9FiCmz05qJWhI6+ak9grIAgpYUbbDgxrl4W5KsqTr6F5sSpQgw76u6fLGO60nUZVjn86UG+SZQAA==" Feb 12 01:03:59 volumio sudo[16085]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-12 01:02' Feb 12 01:03:59 volumio sudo[16085]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 01:03:59 volumio go-librespot[16076]: time="2026-02-12T01:03:59+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 12 01:03:59 volumio go-librespot[16076]: time="2026-02-12T01:03:59+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Feb 12 01:03:59 volumio go-librespot[16076]: time="2026-02-12T01:03:59+07:00" level=debug msg="completed keyexchange" Feb 12 01:03:59 volumio go-librespot[16076]: time="2026-02-12T01:03:59+07:00" level=debug msg="completed challenge" Feb 12 01:03:59 volumio go-librespot[16076]: time="2026-02-12T01:03:59+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 12 01:03:59 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 12 01:03:59 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. PRETTY_NAME="Raspbian GNU/Linux 12 (bookworm)" NAME="Raspbian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="b05a530ca81d05eb9a84d0acf82089f0a60b8ee6" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="4ad85e2147d972f0b838d33c21382d2d813b2ae8" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu Dec 25 09:13:19 UTC 2025" VOLUMIO_VERSION="4.084" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="792f09af7488531aecd1aadcaa9b175e"