Feb 07 21:00:00 volumio volumio[25422]: Starting albumart workers Feb 07 21:00:00 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Feb 07 21:00:00 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 07 21:00:00 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 07 21:00:00 volumio go-librespot[25518]: go-librespot daemon starting... Feb 07 21:00:00 volumio go-librespot[25519]: time="2026-02-07T21:00:00+07:00" level=info msg="running go-librespot 0.4.0" Feb 07 21:00:00 volumio volumio[25291]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 07 21:00:00 volumio volumio[25291]: info: [1770472800577] CoreMusicLibrary::Adding element YouTube Music Feb 07 21:00:00 volumio volumio[25291]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 07 21:00:00 volumio volumio[25291]: Cannot find translation for source YouTube Music Feb 07 21:00:00 volumio volumio[25291]: info: Volumio Calling Home Feb 07 21:00:00 volumio sudo[25526]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Feb 07 21:00:00 volumio sudo[25526]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 21:00:00 volumio sudo[25526]: pam_unix(sudo:session): session closed for user root Feb 07 21:00:01 volumio go-librespot[25519]: time="2026-02-07T21:00:01+07:00" level=info msg="zeroconf server listening on port 34881" Feb 07 21:00:01 volumio volumio[25291]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Feb 07 21:00:01 volumio volumio[25291]: info: Discovery: Found device Volumio Feb 07 21:00:01 volumio volumio[25291]: info: CoreCommandRouter::volumioGetState Feb 07 21:00:01 volumio volumio[25291]: info: CorePlayQueue::getTrack 0 Feb 07 21:00:01 volumio volumio[25291]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Feb 07 21:00:01 volumio volumio[25291]: info: Discovery: Found device Volumio Feb 07 21:00:01 volumio volumio[25291]: info: CoreCommandRouter::volumioGetState Feb 07 21:00:01 volumio volumio[25291]: info: CorePlayQueue::getTrack 0 Feb 07 21:00:01 volumio volumio[25291]: info: MPD Permissions set Feb 07 21:00:01 volumio volumio[25291]: info: MPD Permissions set Feb 07 21:00:01 volumio volumio[25291]: info: Upmpdcli Daemon Started Feb 07 21:00:01 volumio volumio[25291]: info: Volumio called home Feb 07 21:00:01 volumio volumio[25291]: info: Spotify config file written Feb 07 21:00:01 volumio sudo[25546]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 07 21:00:01 volumio sudo[25546]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 21:00:01 volumio volumio[25291]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Feb 07 21:00:01 volumio volumio[25291]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 21:00:01 volumio volumio[25291]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 21:00:01 volumio volumio[25291]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 21:00:01 volumio volumio[25291]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 21:00:01 volumio volumio[25291]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 21:00:01 volumio volumio[25291]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 21:00:01 volumio volumio[25291]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 21:00:01 volumio volumio[25291]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 21:00:01 volumio volumio[25291]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 21:00:01 volumio volumio[25291]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 21:00:01 volumio volumio[25291]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 21:00:01 volumio volumio[25291]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 21:00:01 volumio volumio[25291]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 21:00:01 volumio volumio[25291]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 21:00:01 volumio volumio[25291]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 21:00:01 volumio volumio[25291]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 21:00:01 volumio volumio[25291]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 21:00:01 volumio volumio[25291]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 21:00:01 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Feb 07 21:00:01 volumio systemd[1]: go-librespot-daemon.service: Killing process 25523 (go-librespot) with signal SIGKILL. Feb 07 21:00:01 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Feb 07 21:00:01 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 07 21:00:01 volumio volumio[25291]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 21:00:01 volumio volumio[25291]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 21:00:01 volumio volumio[25291]: info: No need to fix Spotify hosts Feb 07 21:00:01 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 07 21:00:01 volumio go-librespot[25558]: go-librespot daemon starting... Feb 07 21:00:02 volumio sudo[25546]: pam_unix(sudo:session): session closed for user root Feb 07 21:00:02 volumio go-librespot[25559]: time="2026-02-07T21:00:02+07:00" level=info msg="running go-librespot 0.4.0" Feb 07 21:00:02 volumio go-librespot[25559]: time="2026-02-07T21:00:02+07:00" level=debug msg="app state loaded" Feb 07 21:00:02 volumio go-librespot[25559]: time="2026-02-07T21:00:02+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 07 21:00:02 volumio go-librespot[25559]: time="2026-02-07T21:00:02+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 07 21:00:02 volumio go-librespot[25559]: time="2026-02-07T21:00:02+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 07 21:00:02 volumio go-librespot[25559]: time="2026-02-07T21:00:02+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 07 21:00:02 volumio go-librespot[25559]: time="2026-02-07T21:00:02+07:00" level=info msg="zeroconf server listening on port 38635" Feb 07 21:00:02 volumio volumio[25291]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 07 21:00:02 volumio volumio[25291]: SPOTIFY: BQD159c7D-Nm1Fs5R0R7Tao6aDiaJH3G_Mh9LoZ7cyPmzvMOTWJupqlilbkJSSEx3MGnfonji8BK7jpwWX8l54w_1QkQgWyfBW8cTYhop9RSIfP1QCR0SQiPJVHLrUrtZmIjhCuYOAK3tAAA607egDErxsehEUmHzQ8soaD3_M4Edj5Zw1147LoqNtx-QTUAVaxzKiT3rmaKzixFCQr8oqa5L_w7izhoWVggp4lHsTHEiNqRFI8oxhWRzNklHixJr-HP7W_pgNRJ2F4DZ49vWY8XI-Mogy3G-3MbaeimmlLAQUrGvb_XmBBa Feb 07 21:00:02 volumio volumio[25291]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 07 21:00:02 volumio volumio[25291]: info: New Spotify access token = BQD159c7D-Nm1Fs5R0R7Tao6aDiaJH3G_Mh9LoZ7cyPmzvMOTWJupqlilbkJSSEx3MGnfonji8BK7jpwWX8l54w_1QkQgWyfBW8cTYhop9RSIfP1QCR0SQiPJVHLrUrtZmIjhCuYOAK3tAAA607egDErxsehEUmHzQ8soaD3_M4Edj5Zw1147LoqNtx-QTUAVaxzKiT3rmaKzixFCQr8oqa5L_w7izhoWVggp4lHsTHEiNqRFI8oxhWRzNklHixJr-HP7W_pgNRJ2F4DZ49vWY8XI-Mogy3G-3MbaeimmlLAQUrGvb_XmBBa Feb 07 21:00:02 volumio volumio[25291]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 07 21:00:02 volumio volumio[25291]: info: Starting Shairport Sync Feb 07 21:00:02 volumio volumio[25291]: info: Starting Shairport Sync Feb 07 21:00:02 volumio volumio[25291]: info: Starting Shairport Sync Feb 07 21:00:02 volumio go-librespot[25559]: time="2026-02-07T21:00:02+07:00" level=debug msg="obtained new client token: AACY8ATzzkfylXgdmfLeEMQJID6+2BTlwcA1pHbM0NKjX/K0HxHBhLh9l60nVUQzaMNcf2dmCRKDL7Hlx4X00ENIjw/3Ij2CiHzwuKb5CaNLR6xuoaQ3GPf7cZGWtGIOsF264dRg2DZbHGxHfzaqswY/KKbxO6b6Ts3xyfTgDyY7QKb5pxxj3xqZVG5oEEi3yQEKzKKsMiCLfvWUWswt6ZSTsJyZC3bbTC+qN4pbQrOpezssm7SSyvd7rw==" Feb 07 21:00:02 volumio sudo[25573]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 07 21:00:02 volumio sudo[25573]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 21:00:02 volumio sudo[25576]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 07 21:00:03 volumio sudo[25577]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 07 21:00:03 volumio sudo[25577]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 21:00:03 volumio sudo[25576]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 21:00:03 volumio go-librespot[25559]: time="2026-02-07T21:00:03+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 07 21:00:03 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 07 21:00:03 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 07 21:00:03 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 07 21:00:03 volumio systemd[1]: shairport-sync.service: Consumed 2.250s CPU time. Feb 07 21:00:03 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 07 21:00:03 volumio sudo[25573]: pam_unix(sudo:session): session closed for user root Feb 07 21:00:03 volumio sudo[25577]: pam_unix(sudo:session): session closed for user root Feb 07 21:00:03 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 07 21:00:03 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 07 21:00:03 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 07 21:00:03 volumio volumio[25291]: info: CoreCommandRouter::volumioGetState Feb 07 21:00:03 volumio volumio[25291]: info: CorePlayQueue::getTrack 0 Feb 07 21:00:03 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 07 21:00:03 volumio sudo[25576]: pam_unix(sudo:session): session closed for user root Feb 07 21:00:03 volumio volumio[25291]: info: Shairport-Sync Started Feb 07 21:00:03 volumio volumio[25291]: Error adding Membership: Error: addMembership EINVAL Feb 07 21:00:03 volumio volumio[25291]: info: Shairport-Sync Started Feb 07 21:00:03 volumio go-librespot[25559]: time="2026-02-07T21:00:03+07:00" level=debug msg="completed keyexchange" Feb 07 21:00:03 volumio go-librespot[25559]: time="2026-02-07T21:00:03+07:00" level=debug msg="completed challenge" Feb 07 21:00:03 volumio volumio[25291]: info: Shairport-Sync Started Feb 07 21:00:03 volumio go-librespot[25559]: time="2026-02-07T21:00:03+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 07 21:00:03 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 07 21:00:03 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 07 21:00:03 volumio volumio[25291]: SPOTIFY: User informations: {"country":"PK","display_name":"215mmgea6kss3jxeqsqdquvji","email":"linh.ngotran@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/215mmgea6kss3jxeqsqdquvji"},"followers":{"href":null,"total":1},"href":"https://api.spotify.com/v1/users/215mmgea6kss3jxeqsqdquvji","id":"215mmgea6kss3jxeqsqdquvji","images":[],"product":"premium","type":"user","uri":"spotify:user:215mmgea6kss3jxeqsqdquvji"} Feb 07 21:00:03 volumio volumio[25291]: info: Spotify Successfully logged in Feb 07 21:00:03 volumio volumio[25291]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 07 21:00:03 volumio volumio[25291]: info: [1770472803670] CoreMusicLibrary::Adding element Spotify Feb 07 21:00:03 volumio volumio[25291]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 07 21:00:03 volumio volumio[25291]: Cannot find translation for source YouTube Music Feb 07 21:00:03 volumio volumio[25291]: Cannot find translation for source Spotify Feb 07 21:00:04 volumio volumio[25291]: info: [yt-cast-receiver] DIAL server listening on port 8098 Feb 07 21:00:04 volumio volumio[25291]: info: CoreCommandRouter::volumioRetrievevolume Feb 07 21:00:04 volumio volumio[25291]: info: VolumeController:: Volume=100 Mute =false Feb 07 21:00:04 volumio volumio[25291]: info: CoreCommandRouter::volumioGetState Feb 07 21:00:04 volumio volumio[25291]: info: CorePlayQueue::getTrack 0 Feb 07 21:00:04 volumio volumio[25291]: info: CoreStateMachine::pushState Feb 07 21:00:04 volumio volumio[25291]: info: CorePlayQueue::getTrack 0 Feb 07 21:00:04 volumio volumio[25291]: info: CoreCommandRouter::volumioPushState Feb 07 21:00:05 volumio volumio[25291]: info: go-librespot daemon successfully initialized Feb 07 21:00:06 volumio mpd[25516]: 2026-02-07T21:00:06 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 07 21:00:06 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 07 21:00:06 volumio sudo[25487]: pam_unix(sudo:session): session closed for user root Feb 07 21:00:06 volumio sudo[25477]: pam_unix(sudo:session): session closed for user root Feb 07 21:00:06 volumio volumio[25291]: error: MPD error: The expression evaluated to a falsy value: Feb 07 21:00:06 volumio volumio[25291]: assert.ok(self.idling) Feb 07 21:00:06 volumio volumio[25291]: error: The expression evaluated to a falsy value: Feb 07 21:00:06 volumio volumio[25291]: assert.ok(self.idling) Feb 07 21:00:06 volumio volumio[25291]: error: updateQueue error: null Feb 07 21:00:06 volumio volumio[25291]: info: MPD running with PID25516 Feb 07 21:00:06 volumio volumio[25291]: ,establishing connection Feb 07 21:00:06 volumio volumio[25291]: info: Completed starting Core Plugins Feb 07 21:00:06 volumio volumio[25291]: info: ------------------------------------------- Feb 07 21:00:06 volumio volumio[25291]: info: ----- MyVolumio plugins startup ---- Feb 07 21:00:06 volumio volumio[25291]: info: ------------------------------------------- Feb 07 21:00:06 volumio volumio[25291]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 07 21:00:06 volumio volumio[25291]: error: updateQueue error: null Feb 07 21:00:06 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Feb 07 21:00:06 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 07 21:00:06 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 07 21:00:06 volumio go-librespot[25619]: go-librespot daemon starting... Feb 07 21:00:06 volumio go-librespot[25620]: time="2026-02-07T21:00:06+07:00" level=info msg="running go-librespot 0.4.0" Feb 07 21:00:06 volumio go-librespot[25620]: time="2026-02-07T21:00:06+07:00" level=debug msg="app state loaded" Feb 07 21:00:06 volumio go-librespot[25620]: time="2026-02-07T21:00:06+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 07 21:00:07 volumio go-librespot[25620]: time="2026-02-07T21:00:07+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 07 21:00:07 volumio go-librespot[25620]: time="2026-02-07T21:00:07+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 07 21:00:07 volumio go-librespot[25620]: time="2026-02-07T21:00:07+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 07 21:00:07 volumio go-librespot[25620]: time="2026-02-07T21:00:07+07:00" level=info msg="zeroconf server listening on port 46567" Feb 07 21:00:07 volumio go-librespot[25620]: time="2026-02-07T21:00:07+07:00" level=debug msg="obtained new client token: AAAMxRYadGPkTN3W1DTBqztcmp1sT7yszJvqOb5irvbl6OzZZ/ItmWyVmcsxNqbHp7VIucfjopganxgLhsiA6nCiKIlGo9CAx2+sERscg5niLlRgk79veizV+VkYMv5f4fCTnM7g0hRy8enkVHva/uBPAqrN3EAyWoHFRxcw33LNzlnMmMuhLkoE+TsmZpMGW0U4ObxosAVMgsWrlvRDRRMD4f5e3On60wQL9LcLVW1yqa9cj7h+FtRW9Q==" Feb 07 21:00:07 volumio go-librespot[25620]: time="2026-02-07T21:00:07+07:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:4070, retrying with a different AP" error="dial tcp 104.199.241.202:4070: connect: connection refused" Feb 07 21:00:07 volumio go-librespot[25620]: time="2026-02-07T21:00:07+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Feb 07 21:00:07 volumio go-librespot[25620]: time="2026-02-07T21:00:07+07:00" level=debug msg="completed keyexchange" Feb 07 21:00:07 volumio go-librespot[25620]: time="2026-02-07T21:00:07+07:00" level=debug msg="completed challenge" Feb 07 21:00:07 volumio go-librespot[25620]: time="2026-02-07T21:00:07+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 07 21:00:07 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 07 21:00:07 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 07 21:00:08 volumio volumio[25291]: info: Initializing connection to go-librespot Websocket Feb 07 21:00:08 volumio volumio[25291]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 07 21:00:11 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Feb 07 21:00:11 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 07 21:00:11 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 07 21:00:11 volumio go-librespot[25627]: go-librespot daemon starting... Feb 07 21:00:11 volumio go-librespot[25628]: time="2026-02-07T21:00:11+07:00" level=info msg="running go-librespot 0.4.0" Feb 07 21:00:11 volumio go-librespot[25628]: time="2026-02-07T21:00:11+07:00" level=debug msg="app state loaded" Feb 07 21:00:11 volumio go-librespot[25628]: time="2026-02-07T21:00:11+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 07 21:00:11 volumio volumio[25291]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 07 21:00:11 volumio go-librespot[25628]: time="2026-02-07T21:00:11+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 07 21:00:11 volumio go-librespot[25628]: time="2026-02-07T21:00:11+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 07 21:00:11 volumio go-librespot[25628]: time="2026-02-07T21:00:11+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 07 21:00:11 volumio go-librespot[25628]: time="2026-02-07T21:00:11+07:00" level=info msg="zeroconf server listening on port 42329" Feb 07 21:00:11 volumio volumio[25291]: info: Initializing connection to go-librespot Websocket Feb 07 21:00:11 volumio go-librespot[25628]: time="2026-02-07T21:00:11+07:00" level=debug msg="new websocket client" Feb 07 21:00:11 volumio volumio[25291]: info: Connection to go-librespot Websocket established Feb 07 21:00:11 volumio go-librespot[25628]: time="2026-02-07T21:00:11+07:00" level=debug msg="obtained new client token: AAAk1ysZaSkfFlQOjnlaXwR6EsGMaR//afy5nUo5wfAeaAaaoU6EwtyqVVps2rNBCzY3HCAWBdH3x6GIsQM4zQAhO1Y4JerB0EzvE7uqmoFelT/IgevshjcGVnCbJ9GOUUC+9zdFZ8Q+Lc+F8uFBnjClflzI8ENCGi316UPadD3aDfD2DvgrX6RJkSGMAwavK/ujccT0b+2ZBrJgAx77awSuCKDEza0CWR+nngQntyyBAh9bxhPvSbjcag==" Feb 07 21:00:11 volumio go-librespot[25628]: time="2026-02-07T21:00:11+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 07 21:00:12 volumio go-librespot[25628]: time="2026-02-07T21:00:12+07:00" level=debug msg="completed keyexchange" Feb 07 21:00:12 volumio go-librespot[25628]: time="2026-02-07T21:00:12+07:00" level=debug msg="completed challenge" Feb 07 21:00:12 volumio go-librespot[25628]: time="2026-02-07T21:00:12+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 07 21:00:12 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 07 21:00:12 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 07 21:00:12 volumio volumio[25291]: info: Connection to go-librespot Websocket closed Feb 07 21:00:14 volumio volumio[25291]: info: Getting Spotify volume Feb 07 21:00:14 volumio volumio[25291]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 07 21:00:14 volumio volumio[25291]: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 07 21:00:14 volumio volumio[25291]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Feb 07 21:00:14 volumio volumio[25291]: errno: -111, Feb 07 21:00:14 volumio volumio[25291]: code: 'ECONNREFUSED', Feb 07 21:00:14 volumio volumio[25291]: syscall: 'connect', Feb 07 21:00:14 volumio volumio[25291]: address: '127.0.0.1', Feb 07 21:00:14 volumio volumio[25291]: port: 9879, Feb 07 21:00:14 volumio volumio[25291]: response: undefined Feb 07 21:00:14 volumio volumio[25291]: } Feb 07 21:00:14 volumio volumio[25291]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 07 21:00:15 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Feb 07 21:00:15 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 07 21:00:15 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 07 21:00:15 volumio go-librespot[25661]: go-librespot daemon starting... Feb 07 21:00:15 volumio go-librespot[25662]: time="2026-02-07T21:00:15+07:00" level=info msg="running go-librespot 0.4.0" Feb 07 21:00:15 volumio go-librespot[25662]: time="2026-02-07T21:00:15+07:00" level=debug msg="app state loaded" Feb 07 21:00:15 volumio go-librespot[25662]: time="2026-02-07T21:00:15+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 07 21:00:15 volumio go-librespot[25662]: time="2026-02-07T21:00:15+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 07 21:00:15 volumio go-librespot[25662]: time="2026-02-07T21:00:15+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 07 21:00:15 volumio go-librespot[25662]: time="2026-02-07T21:00:15+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 07 21:00:15 volumio go-librespot[25662]: time="2026-02-07T21:00:15+07:00" level=info msg="zeroconf server listening on port 45495" Feb 07 21:00:16 volumio go-librespot[25662]: time="2026-02-07T21:00:16+07:00" level=debug msg="obtained new client token: AADrn2Fb9WjG3nizRTWJmo0QxD+gzaWitwZACyLqFZfThp8308cEXJaOMmYvs+ThlyNk4UB73CGi8N37Y2QNbg+xjeMvosSpKiMgX0ZnkCjTKn2/Zm8taKE/g4gShAgorQM2RIGKAWoqANI6PGAALSCoa1op1IXmdxGgvWHj6VdIX1IGo/31FwnemhaOSBRnWybXvMPjy81KF8vkQwbNSsjaUAl5rSD0hsMhCdLwFSDTGN2I8XBRnJY=" Feb 07 21:00:16 volumio go-librespot[25662]: time="2026-02-07T21:00:16+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 07 21:00:16 volumio go-librespot[25662]: time="2026-02-07T21:00:16+07:00" level=debug msg="completed keyexchange" Feb 07 21:00:16 volumio go-librespot[25662]: time="2026-02-07T21:00:16+07:00" level=debug msg="completed challenge" Feb 07 21:00:16 volumio sudo[25671]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-07 20:59' Feb 07 21:00:16 volumio sudo[25671]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 21:00:16 volumio go-librespot[25662]: time="2026-02-07T21:00:16+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 07 21:00:16 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 07 21:00:16 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 07 21:00:16 volumio sudo[25671]: pam_unix(sudo:session): session closed for user root Feb 07 21:00:16 volumio volumio-remote-updater[643]: [2026-02-07 21:00:16] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Feb 07 21:00:16 volumio volumio-remote-updater[643]: [2026-02-07 21:00:16] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Feb 07 21:00:16 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Feb 07 21:00:16 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Feb 07 21:00:16 volumio systemd[1]: volumio.service: Consumed 49.495s CPU time. Feb 07 21:00:16 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 07 21:00:16 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 07 21:00:16 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 6318. Feb 07 21:00:16 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 07 21:00:16 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Feb 07 21:00:16 volumio systemd[1]: volumio.service: Consumed 49.495s CPU time. Feb 07 21:00:16 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Feb 07 21:00:17 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 07 21:00:19 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Feb 07 21:00:19 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 07 21:00:19 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 07 21:00:19 volumio go-librespot[25698]: go-librespot daemon starting... Feb 07 21:00:19 volumio go-librespot[25699]: time="2026-02-07T21:00:19+07:00" level=info msg="running go-librespot 0.4.0" Feb 07 21:00:19 volumio go-librespot[25699]: time="2026-02-07T21:00:19+07:00" level=debug msg="app state loaded" Feb 07 21:00:19 volumio go-librespot[25699]: time="2026-02-07T21:00:19+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 07 21:00:20 volumio go-librespot[25699]: time="2026-02-07T21:00:20+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 07 21:00:20 volumio go-librespot[25699]: time="2026-02-07T21:00:20+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 07 21:00:20 volumio go-librespot[25699]: time="2026-02-07T21:00:20+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 07 21:00:20 volumio go-librespot[25699]: time="2026-02-07T21:00:20+07:00" level=info msg="zeroconf server listening on port 33423" Feb 07 21:00:20 volumio go-librespot[25699]: time="2026-02-07T21:00:20+07:00" level=debug msg="obtained new client token: AABTr/1NRl806OzKzxVHvvTZUCwSwSVVSesczgz+ElteeKvVMfCygqkjMDD2qbIBC7Or22vPQeDcVnAZ0Ua7G8kKOcBL/podVdonj30JP9fUwHYZIvJelaLP021WM3oY2w9RCpW5OsMvjg0/S64twAyNxsErUhlxSs1t9jF5ejZufkQ6TssOpc7ISzjuJjhk/iJhjvGTz4AZqyHjbPDfQ+6HI7MkzyPLG+bM0ERs7L6iwqvJofLLyTtf2Q==" Feb 07 21:00:20 volumio volumio[25683]: info: ------------------------------------------- Feb 07 21:00:20 volumio volumio[25683]: info: ----- Volumio3 ---- Feb 07 21:00:20 volumio volumio[25683]: info: ------------------------------------------- Feb 07 21:00:20 volumio volumio[25683]: info: ----- System startup ---- Feb 07 21:00:20 volumio volumio[25683]: info: ------------------------------------------- Feb 07 21:00:20 volumio go-librespot[25699]: time="2026-02-07T21:00:20+07:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:4070, retrying with a different AP" error="dial tcp 104.199.241.202:4070: connect: connection refused" Feb 07 21:00:20 volumio go-librespot[25699]: time="2026-02-07T21:00:20+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Feb 07 21:00:20 volumio go-librespot[25699]: time="2026-02-07T21:00:20+07:00" level=debug msg="completed keyexchange" Feb 07 21:00:20 volumio go-librespot[25699]: time="2026-02-07T21:00:20+07:00" level=debug msg="completed challenge" Feb 07 21:00:20 volumio go-librespot[25699]: time="2026-02-07T21:00:20+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 07 21:00:20 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 07 21:00:20 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 07 21:00:21 volumio volumio-remote-updater[643]: [2026-02-07 21:00:21] [connect] Successful connection Feb 07 21:00:21 volumio volumio[25683]: info: MYVOLUMIO Environment detected Feb 07 21:00:22 volumio volumio[25683]: info: Plugin folders cleanup Feb 07 21:00:22 volumio volumio[25683]: info: Scanning into folder /volumio/app/plugins/ Feb 07 21:00:22 volumio volumio[25683]: info: Scanning category audio_interface Feb 07 21:00:22 volumio volumio[25683]: info: Scanning category miscellanea Feb 07 21:00:22 volumio volumio[25683]: info: Scanning category music_service Feb 07 21:00:22 volumio volumio[25683]: info: Scanning category plugins.json Feb 07 21:00:22 volumio volumio[25683]: info: Scanning category system_controller Feb 07 21:00:22 volumio volumio[25683]: info: Scanning category user_interface Feb 07 21:00:22 volumio volumio[25683]: info: Scanning into folder /data/plugins/ Feb 07 21:00:22 volumio volumio[25683]: info: Scanning category music_service Feb 07 21:00:22 volumio volumio[25683]: info: Plugin folders cleanup completed Feb 07 21:00:22 volumio volumio[25683]: info: ------------------------------------------- Feb 07 21:00:22 volumio volumio[25683]: info: ----- Core plugins startup ---- Feb 07 21:00:22 volumio volumio[25683]: info: ------------------------------------------- Feb 07 21:00:22 volumio volumio[25683]: info: Loading plugins from folder /volumio/app/plugins/ Feb 07 21:00:22 volumio volumio[25683]: info: Adding plugin upnp to MyMusic Plugins Feb 07 21:00:22 volumio volumio[25683]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 07 21:00:22 volumio volumio[25683]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 07 21:00:22 volumio volumio[25683]: info: Loading plugins from folder /data/plugins/ Feb 07 21:00:22 volumio volumio[25683]: info: Loading plugin "system"... Feb 07 21:00:22 volumio volumio[25683]: info: Loading plugin "appearance"... Feb 07 21:00:24 volumio volumio[25683]: info: Loading plugin "network"... Feb 07 21:00:24 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Feb 07 21:00:24 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 07 21:00:24 volumio volumio[25683]: info: Refreshing Cached IP Addresses Feb 07 21:00:24 volumio sudo[25720]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 07 21:00:24 volumio sudo[25720]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 21:00:24 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 07 21:00:24 volumio go-librespot[25718]: go-librespot daemon starting... Feb 07 21:00:24 volumio sudo[25720]: pam_unix(sudo:session): session closed for user root Feb 07 21:00:24 volumio volumio[25683]: info: Loading plugin "services"... Feb 07 21:00:24 volumio sudo[25722]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 07 21:00:24 volumio sudo[25722]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 21:00:24 volumio volumio[25683]: info: Loading plugin "alsa_controller"... Feb 07 21:00:24 volumio sudo[25722]: pam_unix(sudo:session): session closed for user root Feb 07 21:00:24 volumio sudo[25730]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 07 21:00:24 volumio sudo[25730]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 21:00:24 volumio go-librespot[25735]: time="2026-02-07T21:00:24+07:00" level=info msg="running go-librespot 0.4.0" Feb 07 21:00:24 volumio go-librespot[25735]: time="2026-02-07T21:00:24+07:00" level=debug msg="app state loaded" Feb 07 21:00:24 volumio go-librespot[25735]: time="2026-02-07T21:00:24+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 07 21:00:24 volumio volumio[25683]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 07 21:00:24 volumio volumio[25683]: info: Loading plugin "wizard"... Feb 07 21:00:24 volumio volumio[25683]: info: Loading plugin "networkfs"... Feb 07 21:00:24 volumio volumio[25683]: info: Starting Udev Watcher for removable devices Feb 07 21:00:24 volumio volumio[25683]: info: Ignoring mount for partition: boot Feb 07 21:00:24 volumio volumio[25683]: info: Ignoring mount for partition: volumio Feb 07 21:00:24 volumio volumio[25683]: info: Ignoring mount for partition: volumio_data Feb 07 21:00:24 volumio volumio[25683]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 07 21:00:24 volumio volumio[25683]: info: Loading plugin "volumio_command_line_client"... Feb 07 21:00:24 volumio volumio[25683]: info: Loading plugin "upnp"... Feb 07 21:00:24 volumio volumio[25683]: info: [1770472824518] Starting Upmpd Daemon Feb 07 21:00:24 volumio volumio[25683]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 07 21:00:24 volumio volumio[25683]: info: Loading plugin "my_music"... Feb 07 21:00:24 volumio volumio[25683]: info: Loading plugin "mpd"... Feb 07 21:00:24 volumio go-librespot[25735]: time="2026-02-07T21:00:24+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 07 21:00:24 volumio go-librespot[25735]: time="2026-02-07T21:00:24+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 07 21:00:24 volumio go-librespot[25735]: time="2026-02-07T21:00:24+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 07 21:00:24 volumio go-librespot[25735]: time="2026-02-07T21:00:24+07:00" level=info msg="zeroconf server listening on port 41807" Feb 07 21:00:25 volumio go-librespot[25735]: time="2026-02-07T21:00:25+07:00" level=debug msg="obtained new client token: AAD7G7UsROwFMGAg5cMaWqEOM4nwm3OwILOkiiFnGVZUS4f7zwaXiZBarDU2+w9VBg5hOQb9lI3zAUZVS7vR5QEDZzaFVYZXKRbh15rc/eDKlBwikkXAbkIDTLe7ASurKPGGNlJFk6c6TiCAn4sGRAUX/gR1unucyoE7LY85uE7bcMODnY856plX/0FKo7XZl6kRwSV8Zr9H9mi+DVMA8NFJVLOySVVIipXmobpnarGOg74AQUGAxKs=" Feb 07 21:00:25 volumio go-librespot[25735]: time="2026-02-07T21:00:25+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 07 21:00:25 volumio volumio[25683]: info: Loading plugin "upnp_browser"... Feb 07 21:00:25 volumio go-librespot[25735]: time="2026-02-07T21:00:25+07:00" level=debug msg="completed keyexchange" Feb 07 21:00:25 volumio go-librespot[25735]: time="2026-02-07T21:00:25+07:00" level=debug msg="completed challenge" Feb 07 21:00:25 volumio go-librespot[25735]: time="2026-02-07T21:00:25+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 07 21:00:25 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 07 21:00:25 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 07 21:00:26 volumio sudo[25730]: pam_unix(sudo:session): session closed for user root Feb 07 21:00:28 volumio volumio[25683]: info: Starting UPNP Browser Feb 07 21:00:28 volumio volumio[25683]: info: Loading plugin "alarm-clock"... Feb 07 21:00:28 volumio volumio[25683]: info: Loading plugin "airplay_emulation"... Feb 07 21:00:28 volumio volumio[25683]: info: Starting Shairport Sync Feb 07 21:00:28 volumio volumio[25683]: info: Loading plugin "last_100"... Feb 07 21:00:28 volumio volumio[25683]: info: Loading plugin "webradio"... Feb 07 21:00:28 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Feb 07 21:00:28 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 07 21:00:28 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 07 21:00:28 volumio go-librespot[25761]: go-librespot daemon starting... Feb 07 21:00:28 volumio go-librespot[25762]: time="2026-02-07T21:00:28+07:00" level=info msg="running go-librespot 0.4.0" Feb 07 21:00:28 volumio go-librespot[25762]: time="2026-02-07T21:00:28+07:00" level=debug msg="app state loaded" Feb 07 21:00:28 volumio go-librespot[25762]: time="2026-02-07T21:00:28+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 07 21:00:28 volumio volumio[25683]: info: Loading plugin "i2s_dacs"... Feb 07 21:00:28 volumio volumio[25683]: info: Loading plugin "volumiodiscovery"... Feb 07 21:00:28 volumio volumio[25683]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 07 21:00:28 volumio volumio[25683]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 07 21:00:28 volumio volumio[25683]: *** WARNING *** For more information see Feb 07 21:00:28 volumio volumio[25683]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 07 21:00:28 volumio volumio[25683]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 07 21:00:28 volumio volumio[25683]: *** WARNING *** For more information see Feb 07 21:00:28 volumio node[25683]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 07 21:00:28 volumio node[25683]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 07 21:00:28 volumio node[25683]: *** WARNING *** For more information see Feb 07 21:00:28 volumio node[25683]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 07 21:00:28 volumio node[25683]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 07 21:00:28 volumio node[25683]: *** WARNING *** For more information see Feb 07 21:00:28 volumio volumio[25683]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 07 21:00:28 volumio volumio[25683]: info: Discovery: Started advertising with name: Volumio Feb 07 21:00:28 volumio volumio[25683]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 07 21:00:28 volumio volumio[25683]: info: Loading plugin "spop"... Feb 07 21:00:29 volumio go-librespot[25762]: time="2026-02-07T21:00:29+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 07 21:00:29 volumio go-librespot[25762]: time="2026-02-07T21:00:29+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 07 21:00:29 volumio go-librespot[25762]: time="2026-02-07T21:00:29+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 07 21:00:29 volumio go-librespot[25762]: time="2026-02-07T21:00:29+07:00" level=info msg="zeroconf server listening on port 37413" Feb 07 21:00:29 volumio go-librespot[25762]: time="2026-02-07T21:00:29+07:00" level=debug msg="obtained new client token: AADPcs3nk69t/KUFud+6fcNQYbgmjtRo1BMmCKggD8PTKpEc+i42BNe0JbW4uwcFi5WaU0Mx56KhukywVEEcBh+2f+zoRusZlmSKoaOTC1gmsaJW6YLGkIYVww6ISVXqqEx0tiZ0SFw+5npz9YgIDoSScZ3lTwOqPMGtGd7spbLZPqxh1K1vAbilDkJIZz7tYdbIihRhWsK9nRE4vz2TdhO1l0XUPGh3i39DrZpPsv6YvKkSoeo/4Ok8Lw==" Feb 07 21:00:29 volumio go-librespot[25762]: time="2026-02-07T21:00:29+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 07 21:00:29 volumio go-librespot[25762]: time="2026-02-07T21:00:29+07:00" level=debug msg="completed keyexchange" Feb 07 21:00:29 volumio go-librespot[25762]: time="2026-02-07T21:00:29+07:00" level=debug msg="completed challenge" Feb 07 21:00:29 volumio go-librespot[25762]: time="2026-02-07T21:00: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 07 21:00:29 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 07 21:00:29 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 07 21:00:30 volumio volumio[25683]: info: Loading plugin "ytcr"... Feb 07 21:00:33 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Feb 07 21:00:33 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 07 21:00:33 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 07 21:00:33 volumio go-librespot[25775]: go-librespot daemon starting... Feb 07 21:00:33 volumio go-librespot[25776]: time="2026-02-07T21:00:33+07:00" level=info msg="running go-librespot 0.4.0" Feb 07 21:00:33 volumio go-librespot[25776]: time="2026-02-07T21:00:33+07:00" level=debug msg="app state loaded" Feb 07 21:00:33 volumio go-librespot[25776]: time="2026-02-07T21:00:33+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 07 21:00:33 volumio volumio[25683]: info: Loading plugin "ytmusic"... Feb 07 21:00:33 volumio go-librespot[25776]: time="2026-02-07T21:00: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 07 21:00:33 volumio go-librespot[25776]: time="2026-02-07T21:00:33+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 07 21:00:33 volumio go-librespot[25776]: time="2026-02-07T21:00:33+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 07 21:00:33 volumio go-librespot[25776]: time="2026-02-07T21:00:33+07:00" level=info msg="zeroconf server listening on port 37641" Feb 07 21:00:33 volumio go-librespot[25776]: time="2026-02-07T21:00:33+07:00" level=debug msg="obtained new client token: AADatCjO4w/MrhPJpHWKt73XP72TNk1zBZfR7A7K02W1sJInZ6fK4Ua+czGxRS9yTgQlmuSWVktCn/E+ODuROchF3tnkGyKhMky8YccxgbxiOQ5PPkaCnRzIrNlR7tAfNZV9V+EMEoFhEEoTgBJOCV8NeyL2xnMepuJ7jGSQPKVrTCP7GTU6v0/gxYNa07EXfi37PzeqXZ89657OTXS7XBWhwEB/XMucoO5aBIMoJxD0Xwf5favZ4T9L6A==" Feb 07 21:00:34 volumio go-librespot[25776]: time="2026-02-07T21:00:34+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 07 21:00:34 volumio go-librespot[25776]: time="2026-02-07T21:00:34+07:00" level=debug msg="completed keyexchange" Feb 07 21:00:34 volumio go-librespot[25776]: time="2026-02-07T21:00:34+07:00" level=debug msg="completed challenge" Feb 07 21:00:34 volumio go-librespot[25776]: time="2026-02-07T21:00:34+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 07 21:00:34 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 07 21:00:34 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 07 21:00:34 volumio volumio-remote-updater[643]: [2026-02-07 21:00:34] [connect] Successful connection Feb 07 21:00:34 volumio volumio[25683]: info: Loading plugin "outputs"... Feb 07 21:00:34 volumio volumio[25683]: info: Loading plugin "albumart"... Feb 07 21:00:34 volumio volumio[25683]: info: Plugin example_plugin is not enabled Feb 07 21:00:34 volumio volumio[25683]: info: Loading plugin "inputs"... Feb 07 21:00:34 volumio volumio[25683]: info: Loading plugin "updater_comm"... Feb 07 21:00:34 volumio volumio[25683]: info: Plugin mpdemulation is not enabled Feb 07 21:00:34 volumio volumio[25683]: info: Loading plugin "rest_api"... Feb 07 21:00:34 volumio volumio[25683]: info: Loading plugin "websocket"... Feb 07 21:00:34 volumio volumio[25683]: info: Starting Socket.io Server version 1.7.4 Feb 07 21:00:34 volumio volumio[25683]: info: Loading plugin "RoonBridge"... Feb 07 21:00:35 volumio volumio[25683]: info: Applying required configuration parameters for plugin RoonBridge Feb 07 21:00:35 volumio volumio[25683]: info: Loading i18n strings for locale en Feb 07 21:00:35 volumio volumio[25683]: Updating browse sources language Feb 07 21:00:35 volumio volumio[25683]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 07 21:00:35 volumio volumio[25797]: Forking 3 albumart workers Feb 07 21:00:35 volumio volumio[25683]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 07 21:00:35 volumio volumio[25683]: info: CoreCommandRouter::initPlayerControls Feb 07 21:00:35 volumio volumio[25683]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 21:00:35 volumio volumio[25683]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 21:00:35 volumio volumio[25683]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 21:00:35 volumio volumio[25683]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 21:00:35 volumio volumio[25683]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 21:00:35 volumio volumio[25683]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 21:00:35 volumio volumio[25683]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 21:00:35 volumio volumio[25683]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 21:00:35 volumio volumio[25683]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 07 21:00:35 volumio volumio[25683]: Express server listening on port 3000 Feb 07 21:00:35 volumio volumio[25683]: [Metrics] WebUI: 16s 254.44ms Feb 07 21:00:35 volumio volumio[25683]: info: CoreStateMachine::resetVolumioState Feb 07 21:00:35 volumio volumio[25683]: info: CoreStateMachine::getcurrentVolume Feb 07 21:00:35 volumio volumio[25683]: info: CoreCommandRouter::volumioRetrievevolume Feb 07 21:00:36 volumio sudo[25842]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 07 21:00:36 volumio sudo[25842]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 21:00:36 volumio sudo[25842]: pam_unix(sudo:session): session closed for user root Feb 07 21:00:36 volumio sudo[25844]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 07 21:00:36 volumio sudo[25844]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 21:00:36 volumio sudo[25844]: pam_unix(sudo:session): session closed for user root Feb 07 21:00:36 volumio volumio[25683]: info: Volumio Network Manager: Network status updated: 1 Feb 07 21:00:36 volumio volumio[25683]: info: VolumeController:: Volume=100 Mute =false Feb 07 21:00:36 volumio volumio[25683]: info: CoreStateMachine::pushState Feb 07 21:00:36 volumio volumio[25683]: info: CorePlayQueue::getTrack 0 Feb 07 21:00:36 volumio volumio[25683]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 07 21:00:36 volumio volumio[25683]: info: CoreCommandRouter::volumioPushState Feb 07 21:00:36 volumio volumio[25683]: info: CoreStateMachine::updateTrackBlock Feb 07 21:00:36 volumio volumio[25683]: info: CorePlayQueue::getTrackBlock Feb 07 21:00:36 volumio volumio[25683]: info: CoreCommandRouter::volumioRetrievevolume Feb 07 21:00:36 volumio volumio-remote-updater[643]: [2026-02-07 21:00:36] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1770472834 101 Feb 07 21:00:36 volumio volumio[25683]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 1 Feb 07 21:00:36 volumio volumio[25683]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 21:00:36 volumio volumio[25683]: info: Reloading queue from file Feb 07 21:00:36 volumio volumio[25683]: info: CoreStateMachine::setRepeat null single undefined Feb 07 21:00:36 volumio volumio[25683]: info: CoreStateMachine::pushState Feb 07 21:00:36 volumio volumio[25683]: info: CorePlayQueue::getTrack 0 Feb 07 21:00:36 volumio volumio[25683]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 07 21:00:36 volumio volumio[25683]: info: CoreCommandRouter::volumioPushState Feb 07 21:00:36 volumio volumio[25683]: info: CoreStateMachine::setRandom null Feb 07 21:00:36 volumio volumio[25683]: info: CoreStateMachine::pushState Feb 07 21:00:36 volumio volumio[25683]: info: CorePlayQueue::getTrack 0 Feb 07 21:00:36 volumio volumio[25683]: info: CoreCommandRouter::volumioPushState Feb 07 21:00:36 volumio volumio[25683]: info: Setting Device type: Raspberry PI Feb 07 21:00:36 volumio volumio[25683]: info: Completed loading Core Plugins Feb 07 21:00:36 volumio volumio[25683]: info: Preparing to generate the ALSA configuration file Feb 07 21:00:36 volumio volumio[25683]: info: VolumeController:: Volume=100 Mute =false Feb 07 21:00:36 volumio volumio[25683]: info: CoreStateMachine::pushState Feb 07 21:00:36 volumio volumio[25683]: info: CorePlayQueue::getTrack 0 Feb 07 21:00:36 volumio volumio[25683]: info: CoreCommandRouter::volumioPushState Feb 07 21:00:37 volumio volumio[25683]: info: Asound.conf file unchanged, so no further update is needed Feb 07 21:00:37 volumio volumio[25683]: info: Output device has changed, restarting MPD Feb 07 21:00:37 volumio volumio[25683]: info: Output device has changed, restarting Shairport Sync Feb 07 21:00:37 volumio volumio[25683]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 21:00:37 volumio volumio[25683]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 21:00:37 volumio sudo[25858]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 07 21:00:37 volumio sudo[25858]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 21:00:37 volumio sudo[25860]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 07 21:00:37 volumio sudo[25860]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 21:00:37 volumio volumio[25683]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 07 21:00:37 volumio volumio[25683]: info: ___________ START PLUGINS ___________ Feb 07 21:00:37 volumio sudo[25860]: pam_unix(sudo:session): session closed for user root Feb 07 21:00:37 volumio sudo[25862]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 07 21:00:37 volumio sudo[25862]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 21:00:37 volumio volumio[25683]: info: ControllerMpd::onStart: Initializing MPD Feb 07 21:00:37 volumio volumio[25683]: info: Creating MPD Configuration file Feb 07 21:00:37 volumio volumio[25683]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 07 21:00:37 volumio volumio[25683]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 07 21:00:37 volumio volumio[25683]: info: [1770472837239] CoreMusicLibrary::Adding element Media Servers Feb 07 21:00:37 volumio volumio[25683]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 07 21:00:37 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Feb 07 21:00:37 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 07 21:00:37 volumio volumio[25683]: info: UPNP Browser: Client initialized successfully Feb 07 21:00:37 volumio sudo[25870]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 07 21:00:37 volumio sudo[25870]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 21:00:37 volumio sudo[25870]: pam_unix(sudo:session): session closed for user root Feb 07 21:00:37 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 07 21:00:37 volumio go-librespot[25874]: go-librespot daemon starting... Feb 07 21:00:37 volumio volumio[25683]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 21:00:37 volumio volumio[25683]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 21:00:37 volumio sudo[25873]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 07 21:00:37 volumio sudo[25873]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 21:00:37 volumio go-librespot[25876]: time="2026-02-07T21:00:37+07:00" level=info msg="running go-librespot 0.4.0" Feb 07 21:00:37 volumio go-librespot[25876]: time="2026-02-07T21:00:37+07:00" level=debug msg="app state loaded" Feb 07 21:00:37 volumio go-librespot[25876]: time="2026-02-07T21:00:37+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 07 21:00:37 volumio sudo[25858]: pam_unix(sudo:session): session closed for user root Feb 07 21:00:37 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 07 21:00:37 volumio volumio[25683]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 07 21:00:37 volumio volumio[25683]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 21:00:37 volumio volumio[25683]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 21:00:37 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 07 21:00:37 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 07 21:00:37 volumio systemd[1]: mpd.service: Consumed 7.091s CPU time. Feb 07 21:00:37 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 07 21:00:37 volumio volumio[25683]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 07 21:00:37 volumio volumio[25683]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 07 21:00:37 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 07 21:00:37 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 07 21:00:37 volumio volumio[25683]: info: [1770472837624] CoreMusicLibrary::Adding element Last_100 Feb 07 21:00:37 volumio volumio[25683]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 07 21:00:37 volumio volumio[25683]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 07 21:00:37 volumio volumio[25683]: info: [1770472837654] CoreMusicLibrary::Adding element Webradio Feb 07 21:00:37 volumio volumio[25683]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 07 21:00:37 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 07 21:00:37 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 07 21:00:37 volumio volumio[25683]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 07 21:00:37 volumio volumio[25683]: info: Initializing BBC Radios Feb 07 21:00:38 volumio volumio[25683]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 07 21:00:38 volumio volumio[25683]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 21:00:38 volumio go-librespot[25876]: time="2026-02-07T21:00:38+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 07 21:00:38 volumio go-librespot[25876]: time="2026-02-07T21:00:38+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 07 21:00:38 volumio go-librespot[25876]: time="2026-02-07T21:00:38+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 07 21:00:38 volumio volumio[25683]: info: Creating Spotify config file Feb 07 21:00:38 volumio volumio[25683]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 21:00:38 volumio sudo[25892]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 07 21:00:38 volumio sudo[25892]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 07 21:00:38 volumio go-librespot[25876]: time="2026-02-07T21:00:38+07:00" level=info msg="zeroconf server listening on port 37973" Feb 07 21:00:38 volumio sudo[25892]: pam_unix(sudo:session): session closed for user root Feb 07 21:00:38 volumio go-librespot[25876]: time="2026-02-07T21:00:38+07:00" level=debug msg="obtained new client token: AACXEA0DKfk71UHbOllwgTFQkxwM9neWBZwmSKjeY1Dex30iVJwgF2nuvb41JsmXuInBC3IZ4ERHmNsMUzdysKMcJZ0ZwzTdaCsZI0oDY3I03QnrvzvF/v56BGZVxPy7C5kJmPONfMVyUQr2zVBE6QoBWu814BiIjLqXs9WvYMbzwhceF3jOiQV3HvoPY+4l0hsLnnswraTTY9THEAVoDPieIlg96/jgm480lHDOFkq9cV07C4d0juXJew==" Feb 07 21:00:38 volumio go-librespot[25876]: time="2026-02-07T21:00:38+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 07 21:00:38 volumio go-librespot[25876]: time="2026-02-07T21:00:38+07:00" level=debug msg="completed keyexchange" Feb 07 21:00:38 volumio go-librespot[25876]: time="2026-02-07T21:00:38+07:00" level=debug msg="completed challenge" Feb 07 21:00:38 volumio go-librespot[25876]: time="2026-02-07T21:00:38+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 07 21:00:38 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 07 21:00:38 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 07 21:00:39 volumio volumio[25809]: Starting albumart workers Feb 07 21:00:39 volumio volumio[25808]: Starting albumart workers Feb 07 21:00:39 volumio volumio[25807]: Starting albumart workers Feb 07 21:00:39 volumio volumio[25683]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 07 21:00:39 volumio volumio[25683]: info: [1770472839542] CoreMusicLibrary::Adding element YouTube Music Feb 07 21:00:39 volumio volumio[25683]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 07 21:00:39 volumio volumio[25683]: Cannot find translation for source YouTube Music Feb 07 21:00:39 volumio volumio[25683]: info: Volumio Calling Home Feb 07 21:00:39 volumio sudo[25911]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Feb 07 21:00:39 volumio sudo[25911]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 21:00:39 volumio sudo[25911]: pam_unix(sudo:session): session closed for user root Feb 07 21:00:40 volumio volumio[25683]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Feb 07 21:00:40 volumio volumio[25683]: info: Discovery: Found device Volumio Feb 07 21:00:40 volumio volumio[25683]: info: CoreCommandRouter::volumioGetState Feb 07 21:00:40 volumio volumio[25683]: info: CorePlayQueue::getTrack 0 Feb 07 21:00:40 volumio volumio[25683]: info: MPD Permissions set Feb 07 21:00:40 volumio volumio[25683]: info: MPD Permissions set Feb 07 21:00:40 volumio volumio[25683]: info: Upmpdcli Daemon Started Feb 07 21:00:40 volumio volumio[25683]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Feb 07 21:00:40 volumio volumio[25683]: info: Discovery: Found device Volumio Feb 07 21:00:40 volumio volumio[25683]: info: CoreCommandRouter::volumioGetState Feb 07 21:00:40 volumio volumio[25683]: info: CorePlayQueue::getTrack 0 Feb 07 21:00:40 volumio volumio[25683]: info: Volumio called home Feb 07 21:00:40 volumio volumio[25683]: info: Spotify config file written Feb 07 21:00:40 volumio sudo[25923]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 07 21:00:40 volumio sudo[25923]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 21:00:40 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 07 21:00:41 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 07 21:00:41 volumio go-librespot[25931]: go-librespot daemon starting... Feb 07 21:00:41 volumio sudo[25923]: pam_unix(sudo:session): session closed for user root Feb 07 21:00:41 volumio go-librespot[25932]: time="2026-02-07T21:00:41+07:00" level=info msg="running go-librespot 0.4.0" Feb 07 21:00:41 volumio go-librespot[25932]: time="2026-02-07T21:00:41+07:00" level=debug msg="app state loaded" Feb 07 21:00:41 volumio go-librespot[25932]: time="2026-02-07T21:00:41+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 07 21:00:41 volumio volumio[25683]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Feb 07 21:00:41 volumio volumio[25683]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 21:00:41 volumio volumio[25683]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 21:00:41 volumio volumio[25683]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 21:00:41 volumio volumio[25683]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 21:00:41 volumio volumio[25683]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 21:00:41 volumio volumio[25683]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 21:00:41 volumio volumio[25683]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 21:00:41 volumio volumio[25683]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 21:00:41 volumio volumio[25683]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 21:00:41 volumio volumio[25683]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 21:00:41 volumio volumio[25683]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 21:00:41 volumio volumio[25683]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 21:00:41 volumio volumio[25683]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 21:00:41 volumio volumio[25683]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 21:00:41 volumio volumio[25683]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 21:00:41 volumio volumio[25683]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 21:00:41 volumio volumio[25683]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 21:00:41 volumio volumio[25683]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 21:00:41 volumio volumio[25683]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 21:00:41 volumio volumio[25683]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 21:00:41 volumio volumio[25683]: info: No need to fix Spotify hosts Feb 07 21:00:41 volumio go-librespot[25932]: time="2026-02-07T21:00: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 07 21:00:41 volumio go-librespot[25932]: time="2026-02-07T21:00:41+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 07 21:00:41 volumio go-librespot[25932]: time="2026-02-07T21:00:41+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 07 21:00:41 volumio go-librespot[25932]: time="2026-02-07T21:00:41+07:00" level=info msg="zeroconf server listening on port 46855" Feb 07 21:00:41 volumio volumio[25683]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 07 21:00:41 volumio volumio[25683]: SPOTIFY: BQDvBWYaqD3kfU91F4rm_y2UGPqIycUmTe60WJeaE7NHUf_9KsuPeR28dlMVBgeWXFbg8Q_4TGvM7ZE2a9GnHdT0d698EOmAP5lFjAcwB1eBdhFqCMQjba9viVYxN7q1qL2tuq1lTDAh6fgUp7SbjCUtDKBszfrNJsbeyaiudiyb8RMRjSVCVHxJPjqfArMoMEtMn1OQ_cDTdkpC2XeDJeY1KXXFAB5DuRqVOYmvlljXqju6_ywLbC3_ZwCkLY_sMk9ufsK10D47NBCoITt6YH6_Qrsds0S4lrwurapAiHG8QCclCwKoGIND Feb 07 21:00:41 volumio volumio[25683]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 07 21:00:41 volumio volumio[25683]: info: New Spotify access token = BQDvBWYaqD3kfU91F4rm_y2UGPqIycUmTe60WJeaE7NHUf_9KsuPeR28dlMVBgeWXFbg8Q_4TGvM7ZE2a9GnHdT0d698EOmAP5lFjAcwB1eBdhFqCMQjba9viVYxN7q1qL2tuq1lTDAh6fgUp7SbjCUtDKBszfrNJsbeyaiudiyb8RMRjSVCVHxJPjqfArMoMEtMn1OQ_cDTdkpC2XeDJeY1KXXFAB5DuRqVOYmvlljXqju6_ywLbC3_ZwCkLY_sMk9ufsK10D47NBCoITt6YH6_Qrsds0S4lrwurapAiHG8QCclCwKoGIND Feb 07 21:00:41 volumio volumio[25683]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 07 21:00:42 volumio volumio[25683]: info: Starting Shairport Sync Feb 07 21:00:42 volumio volumio[25683]: info: Starting Shairport Sync Feb 07 21:00:42 volumio volumio[25683]: info: Starting Shairport Sync Feb 07 21:00:42 volumio go-librespot[25932]: time="2026-02-07T21:00:42+07:00" level=debug msg="obtained new client token: AAA1nqJv6BLuKGkewI2y69tmsBeGYdIldTH7pvwJvoxSf2/Rh0ljk+RfgNgDqdXJfKbwhEDd0kYcROdSpOGjSHZHm+qcEPxLbw0f3qNeBNI6bpx8FZJJFL/a+Tr5oD5jfIZnhPdBTciurDuA+ZTQxGgQ9od1gpBloL0hxEbEFj42Sf+Vijk4e88/x1/Jo6AHG0suR2CC8Am+iM0V3Paly7Xlky0+Jfoh0ZvO3S665f49s4SfVrwOw4I=" Feb 07 21:00:42 volumio sudo[25956]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 07 21:00:42 volumio sudo[25956]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 21:00:42 volumio sudo[25958]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 07 21:00:42 volumio sudo[25958]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 21:00:42 volumio go-librespot[25932]: time="2026-02-07T21:00:42+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 07 21:00:42 volumio sudo[25960]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 07 21:00:42 volumio sudo[25960]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 21:00:42 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 07 21:00:42 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 07 21:00:42 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 07 21:00:42 volumio systemd[1]: shairport-sync.service: Consumed 2.225s CPU time. Feb 07 21:00:42 volumio go-librespot[25932]: time="2026-02-07T21:00:42+07:00" level=debug msg="completed keyexchange" Feb 07 21:00:42 volumio go-librespot[25932]: time="2026-02-07T21:00:42+07:00" level=debug msg="completed challenge" Feb 07 21:00:42 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 07 21:00:42 volumio go-librespot[25932]: time="2026-02-07T21:00: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 07 21:00:42 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 07 21:00:42 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 07 21:00:42 volumio sudo[25956]: pam_unix(sudo:session): session closed for user root Feb 07 21:00:42 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 07 21:00:42 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 07 21:00:42 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 07 21:00:42 volumio volumio[25683]: info: Shairport-Sync Started Feb 07 21:00:42 volumio volumio[25683]: Error adding Membership: Error: addMembership EINVAL Feb 07 21:00:42 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 07 21:00:42 volumio volumio[25683]: info: CoreCommandRouter::volumioGetState Feb 07 21:00:42 volumio volumio[25683]: info: CorePlayQueue::getTrack 0 Feb 07 21:00:42 volumio sudo[25958]: pam_unix(sudo:session): session closed for user root Feb 07 21:00:42 volumio sudo[25960]: pam_unix(sudo:session): session closed for user root Feb 07 21:00:42 volumio volumio[25683]: info: Shairport-Sync Started Feb 07 21:00:42 volumio volumio[25683]: info: Shairport-Sync Started Feb 07 21:00:42 volumio volumio[25683]: SPOTIFY: User informations: {"country":"PK","display_name":"215mmgea6kss3jxeqsqdquvji","email":"linh.ngotran@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/215mmgea6kss3jxeqsqdquvji"},"followers":{"href":null,"total":1},"href":"https://api.spotify.com/v1/users/215mmgea6kss3jxeqsqdquvji","id":"215mmgea6kss3jxeqsqdquvji","images":[],"product":"premium","type":"user","uri":"spotify:user:215mmgea6kss3jxeqsqdquvji"} Feb 07 21:00:42 volumio volumio[25683]: info: Spotify Successfully logged in Feb 07 21:00:42 volumio volumio[25683]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 07 21:00:42 volumio volumio[25683]: info: [1770472842902] CoreMusicLibrary::Adding element Spotify Feb 07 21:00:42 volumio volumio[25683]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 07 21:00:42 volumio volumio[25683]: Cannot find translation for source YouTube Music Feb 07 21:00:42 volumio volumio[25683]: Cannot find translation for source Spotify Feb 07 21:00:43 volumio volumio[25683]: info: [yt-cast-receiver] DIAL server listening on port 8098 Feb 07 21:00:43 volumio volumio[25683]: info: CoreCommandRouter::volumioRetrievevolume Feb 07 21:00:43 volumio volumio[25683]: info: VolumeController:: Volume=100 Mute =false Feb 07 21:00:43 volumio volumio[25683]: info: CoreCommandRouter::volumioGetState Feb 07 21:00:43 volumio volumio[25683]: info: CorePlayQueue::getTrack 0 Feb 07 21:00:43 volumio volumio[25683]: info: CoreStateMachine::pushState Feb 07 21:00:43 volumio volumio[25683]: info: CorePlayQueue::getTrack 0 Feb 07 21:00:43 volumio volumio[25683]: info: CoreCommandRouter::volumioPushState Feb 07 21:00:44 volumio volumio[25683]: info: go-librespot daemon successfully initialized Feb 07 21:00:44 volumio mpd[25909]: 2026-02-07T21:00:44 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 07 21:00:45 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 07 21:00:45 volumio sudo[25862]: pam_unix(sudo:session): session closed for user root Feb 07 21:00:45 volumio sudo[25873]: pam_unix(sudo:session): session closed for user root Feb 07 21:00:45 volumio volumio[25683]: error: MPD error: The expression evaluated to a falsy value: Feb 07 21:00:45 volumio volumio[25683]: assert.ok(self.idling) Feb 07 21:00:45 volumio volumio[25683]: error: The expression evaluated to a falsy value: Feb 07 21:00:45 volumio volumio[25683]: assert.ok(self.idling) Feb 07 21:00:45 volumio volumio[25683]: info: MPD running with PID25909 Feb 07 21:00:45 volumio volumio[25683]: ,establishing connection Feb 07 21:00:45 volumio volumio[25683]: error: updateQueue error: null Feb 07 21:00:45 volumio volumio[25683]: info: Completed starting Core Plugins Feb 07 21:00:45 volumio volumio[25683]: info: ------------------------------------------- Feb 07 21:00:45 volumio volumio[25683]: info: ----- MyVolumio plugins startup ---- Feb 07 21:00:45 volumio volumio[25683]: info: ------------------------------------------- Feb 07 21:00:45 volumio volumio[25683]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 07 21:00:45 volumio volumio[25683]: error: updateQueue error: null Feb 07 21:00:45 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Feb 07 21:00:45 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 07 21:00:45 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 07 21:00:45 volumio go-librespot[26015]: go-librespot daemon starting... Feb 07 21:00:45 volumio go-librespot[26016]: time="2026-02-07T21:00:45+07:00" level=info msg="running go-librespot 0.4.0" Feb 07 21:00:45 volumio go-librespot[26016]: time="2026-02-07T21:00:45+07:00" level=debug msg="app state loaded" Feb 07 21:00:45 volumio go-librespot[26016]: time="2026-02-07T21:00:45+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 07 21:00:46 volumio go-librespot[26016]: time="2026-02-07T21:00:46+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 07 21:00:46 volumio go-librespot[26016]: time="2026-02-07T21:00:46+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 07 21:00:46 volumio go-librespot[26016]: time="2026-02-07T21:00:46+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 07 21:00:46 volumio go-librespot[26016]: time="2026-02-07T21:00:46+07:00" level=info msg="zeroconf server listening on port 33409" Feb 07 21:00:46 volumio go-librespot[26016]: time="2026-02-07T21:00:46+07:00" level=debug msg="obtained new client token: AADfq6+xVPK57tM3LfnhiXQ2mTWEHgLwPwu1+K0XH3m1MZG0p/s69PVCbE8siYWj5o0V1uw6cMIulXTdgkw6jccYn5XYmHZ4UQ2zjtTbnwSQr2exly54ClGhD4f4eItTLCtMO3l1fmJ6sL0Z/s0XCFswzefQDcwWLvObbqxQaOYn94819xRW88pxqs50VPrW6OeYcuEuxqIRAr7B9RspvfA9xX/SPDsa2zhPsw8Sio8iOoTjj4TfVpcHsw==" Feb 07 21:00:46 volumio go-librespot[26016]: time="2026-02-07T21:00:46+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 07 21:00:46 volumio go-librespot[26016]: time="2026-02-07T21:00:46+07:00" level=debug msg="completed keyexchange" Feb 07 21:00:46 volumio go-librespot[26016]: time="2026-02-07T21:00:46+07:00" level=debug msg="completed challenge" Feb 07 21:00:46 volumio go-librespot[26016]: time="2026-02-07T21:00: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 07 21:00:46 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 07 21:00:46 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 07 21:00:47 volumio volumio[25683]: info: Initializing connection to go-librespot Websocket Feb 07 21:00:47 volumio volumio[25683]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 07 21:00:49 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Feb 07 21:00:49 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 07 21:00:49 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 07 21:00:49 volumio go-librespot[26024]: go-librespot daemon starting... Feb 07 21:00:49 volumio go-librespot[26025]: time="2026-02-07T21:00:49+07:00" level=info msg="running go-librespot 0.4.0" Feb 07 21:00:49 volumio go-librespot[26025]: time="2026-02-07T21:00:49+07:00" level=debug msg="app state loaded" Feb 07 21:00:49 volumio go-librespot[26025]: time="2026-02-07T21:00:49+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 07 21:00:50 volumio volumio[25683]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 07 21:00:50 volumio go-librespot[26025]: time="2026-02-07T21:00: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 07 21:00:50 volumio go-librespot[26025]: time="2026-02-07T21:00: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 07 21:00:50 volumio go-librespot[26025]: time="2026-02-07T21:00: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 07 21:00:50 volumio go-librespot[26025]: time="2026-02-07T21:00:50+07:00" level=info msg="zeroconf server listening on port 46463" Feb 07 21:00:50 volumio go-librespot[26025]: time="2026-02-07T21:00:50+07:00" level=debug msg="obtained new client token: AADfDXghrHjR9yMIIG7vicB8EIrgiIGCpUsO6RTHN34e9QUL9maXzn5GQnS7cje8fIvQ4snJVO/p6vPudw4sbma1gjs4qn5wQVamzUbdZwohutk0Q6j7Yv/xzWQf6sbKNrGjad7HR9rz16jDlB054EwFHqVpktQY8CtQGGNLpAoIbWfVj/G0Xbiua0lRkYOLRl7dnq9kfcxJV3dKgK38tfvACyYPL8ie6ZPIJ48R2x1UaxTB42FzD5ED6w==" Feb 07 21:00:50 volumio volumio[25683]: info: Initializing connection to go-librespot Websocket Feb 07 21:00:50 volumio go-librespot[26025]: time="2026-02-07T21:00:50+07:00" level=debug msg="new websocket client" Feb 07 21:00:50 volumio volumio[25683]: info: Connection to go-librespot Websocket established Feb 07 21:00:50 volumio go-librespot[26025]: time="2026-02-07T21:00:50+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 07 21:00:50 volumio go-librespot[26025]: time="2026-02-07T21:00:50+07:00" level=debug msg="completed keyexchange" Feb 07 21:00:50 volumio go-librespot[26025]: time="2026-02-07T21:00:50+07:00" level=debug msg="completed challenge" Feb 07 21:00:50 volumio go-librespot[26025]: time="2026-02-07T21:00: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 07 21:00:50 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 07 21:00:50 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 07 21:00:50 volumio volumio[25683]: info: Connection to go-librespot Websocket closed Feb 07 21:00:53 volumio volumio[25683]: info: Getting Spotify volume Feb 07 21:00:53 volumio volumio[25683]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 07 21:00:53 volumio volumio[25683]: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 07 21:00:53 volumio volumio[25683]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Feb 07 21:00:53 volumio volumio[25683]: errno: -111, Feb 07 21:00:53 volumio volumio[25683]: code: 'ECONNREFUSED', Feb 07 21:00:53 volumio volumio[25683]: syscall: 'connect', Feb 07 21:00:53 volumio volumio[25683]: address: '127.0.0.1', Feb 07 21:00:53 volumio volumio[25683]: port: 9879, Feb 07 21:00:53 volumio volumio[25683]: response: undefined Feb 07 21:00:53 volumio volumio[25683]: } Feb 07 21:00:53 volumio volumio[25683]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 07 21:00:54 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 11. Feb 07 21:00:54 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 07 21:00:54 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 07 21:00:54 volumio go-librespot[26044]: go-librespot daemon starting... Feb 07 21:00:54 volumio go-librespot[26045]: time="2026-02-07T21:00:54+07:00" level=info msg="running go-librespot 0.4.0" Feb 07 21:00:54 volumio go-librespot[26045]: time="2026-02-07T21:00:54+07:00" level=debug msg="app state loaded" Feb 07 21:00:54 volumio go-librespot[26045]: time="2026-02-07T21:00:54+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 07 21:00:54 volumio go-librespot[26045]: time="2026-02-07T21:00: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-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 07 21:00:54 volumio go-librespot[26045]: time="2026-02-07T21:00:54+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 07 21:00:54 volumio go-librespot[26045]: time="2026-02-07T21:00:54+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 07 21:00:54 volumio go-librespot[26045]: time="2026-02-07T21:00:54+07:00" level=info msg="zeroconf server listening on port 41597" Feb 07 21:00:55 volumio go-librespot[26045]: time="2026-02-07T21:00:55+07:00" level=debug msg="obtained new client token: AAB6mERG6Cdn3OAYlo3L/ESqYDiRey5aNWX0o1kXEiHDUZtMaGKQg+lKons8p1KDOul7OSCldf3HWzsTSVvVjztc2KalnS9Mh8zuUXR5jDWjjiFFRR7z2sJO9arhPJYtYGLG6NjqyrFku0riPz/WGGHFlgRsFMnwJW491QI3KCiH3T14/Of+idLWf9S8sSbNqs7oivE1wYc6W9gelyB7vzYHwlTs6bUkx4MlHzc6DTD3CNX+kkK608lAyg==" Feb 07 21:00:55 volumio go-librespot[26045]: time="2026-02-07T21:00:55+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 07 21:00:55 volumio go-librespot[26045]: time="2026-02-07T21:00:55+07:00" level=debug msg="completed keyexchange" Feb 07 21:00:55 volumio go-librespot[26045]: time="2026-02-07T21:00:55+07:00" level=debug msg="completed challenge" Feb 07 21:00:55 volumio sudo[26069]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-07 20:59' Feb 07 21:00:55 volumio go-librespot[26045]: time="2026-02-07T21:00:55+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 07 21:00:55 volumio sudo[26069]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 21:00:55 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 07 21:00:55 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 07 21:00:55 volumio sudo[26069]: pam_unix(sudo:session): session closed for user root Feb 07 21:00:55 volumio volumio-remote-updater[643]: [2026-02-07 21:00:55] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Feb 07 21:00:55 volumio volumio-remote-updater[643]: [2026-02-07 21:00:55] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Feb 07 21:00:55 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Feb 07 21:00:55 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Feb 07 21:00:55 volumio systemd[1]: volumio.service: Consumed 49.373s CPU time. Feb 07 21:00:55 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 07 21:00:55 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 07 21:00:56 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 6319. Feb 07 21:00:56 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 07 21:00:56 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Feb 07 21:00:56 volumio systemd[1]: volumio.service: Consumed 49.373s CPU time. Feb 07 21:00:56 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Feb 07 21:00:56 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 07 21:00:58 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 12. Feb 07 21:00:58 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 07 21:00:58 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 07 21:00:58 volumio go-librespot[26102]: go-librespot daemon starting... Feb 07 21:00:58 volumio go-librespot[26103]: time="2026-02-07T21:00:58+07:00" level=info msg="running go-librespot 0.4.0" Feb 07 21:00:58 volumio go-librespot[26103]: time="2026-02-07T21:00:58+07:00" level=debug msg="app state loaded" Feb 07 21:00:58 volumio go-librespot[26103]: time="2026-02-07T21:00:58+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 07 21:00:59 volumio go-librespot[26103]: time="2026-02-07T21:00:59+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 07 21:00:59 volumio go-librespot[26103]: time="2026-02-07T21:00:59+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 07 21:00:59 volumio go-librespot[26103]: time="2026-02-07T21:00:59+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 07 21:00:59 volumio go-librespot[26103]: time="2026-02-07T21:00:59+07:00" level=info msg="zeroconf server listening on port 45357" Feb 07 21:00:59 volumio go-librespot[26103]: time="2026-02-07T21:00:59+07:00" level=debug msg="obtained new client token: AAAiv48QphzJuPplZA7MqU7pJUbQ4dLEJzrSFeJ5HSoRuenm17v4qe4gCPwWjiN9I1wClZnFzQSCFLzADW6Mp7pJP7LTj1RtpGwpC+/KNONMaornZSNLFA5E0FsL/dMLX0kweW4dUfrb9CsZXA1wCPU0Ypo4UWevhoI4YHQlI56+BJUGFTQtKNC+3OhsqNsWJ357GMQsjnQ2w1TjJfIHuFoFsxDma5WH1SDVm5Hr0+bnkRv6wWBhCxgdXQ==" Feb 07 21:00:59 volumio go-librespot[26103]: time="2026-02-07T21:00:59+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 07 21:00:59 volumio go-librespot[26103]: time="2026-02-07T21:00:59+07:00" level=debug msg="completed keyexchange" Feb 07 21:00:59 volumio go-librespot[26103]: time="2026-02-07T21:00:59+07:00" level=debug msg="completed challenge" Feb 07 21:00:59 volumio go-librespot[26103]: time="2026-02-07T21:00: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 07 21:00:59 volumio volumio[26087]: info: ------------------------------------------- Feb 07 21:00:59 volumio volumio[26087]: info: ----- Volumio3 ---- Feb 07 21:00:59 volumio volumio[26087]: info: ------------------------------------------- Feb 07 21:00:59 volumio volumio[26087]: info: ----- System startup ---- Feb 07 21:00:59 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 07 21:00:59 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 07 21:00:59 volumio volumio[26087]: info: ------------------------------------------- Feb 07 21:01:00 volumio volumio-remote-updater[643]: [2026-02-07 21:01:00] [connect] Successful connection Feb 07 21:01:01 volumio volumio[26087]: info: MYVOLUMIO Environment detected Feb 07 21:01:01 volumio volumio[26087]: info: Plugin folders cleanup Feb 07 21:01:01 volumio volumio[26087]: info: Scanning into folder /volumio/app/plugins/ Feb 07 21:01:01 volumio volumio[26087]: info: Scanning category audio_interface Feb 07 21:01:01 volumio volumio[26087]: info: Scanning category miscellanea Feb 07 21:01:01 volumio volumio[26087]: info: Scanning category music_service Feb 07 21:01:01 volumio volumio[26087]: info: Scanning category plugins.json Feb 07 21:01:01 volumio volumio[26087]: info: Scanning category system_controller Feb 07 21:01:01 volumio volumio[26087]: info: Scanning category user_interface Feb 07 21:01:01 volumio volumio[26087]: info: Scanning into folder /data/plugins/ Feb 07 21:01:01 volumio volumio[26087]: info: Scanning category music_service Feb 07 21:01:01 volumio volumio[26087]: info: Plugin folders cleanup completed Feb 07 21:01:01 volumio volumio[26087]: info: ------------------------------------------- Feb 07 21:01:01 volumio volumio[26087]: info: ----- Core plugins startup ---- Feb 07 21:01:01 volumio volumio[26087]: info: ------------------------------------------- Feb 07 21:01:01 volumio volumio[26087]: info: Loading plugins from folder /volumio/app/plugins/ Feb 07 21:01:01 volumio volumio[26087]: info: Adding plugin upnp to MyMusic Plugins Feb 07 21:01:01 volumio volumio[26087]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 07 21:01:01 volumio volumio[26087]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 07 21:01:01 volumio volumio[26087]: info: Loading plugins from folder /data/plugins/ Feb 07 21:01:01 volumio volumio[26087]: info: Loading plugin "system"... Feb 07 21:01:01 volumio volumio[26087]: info: Loading plugin "appearance"... Feb 07 21:01:02 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 13. Feb 07 21:01:02 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 07 21:01:02 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 07 21:01:02 volumio go-librespot[26127]: go-librespot daemon starting... Feb 07 21:01:02 volumio go-librespot[26128]: time="2026-02-07T21:01:02+07:00" level=info msg="running go-librespot 0.4.0" Feb 07 21:01:02 volumio go-librespot[26128]: time="2026-02-07T21:01:02+07:00" level=debug msg="app state loaded" Feb 07 21:01:02 volumio go-librespot[26128]: time="2026-02-07T21:01:02+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 07 21:01:03 volumio volumio[26087]: info: Loading plugin "network"... Feb 07 21:01:03 volumio volumio[26087]: info: Refreshing Cached IP Addresses Feb 07 21:01:03 volumio sudo[26136]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 07 21:01:03 volumio sudo[26136]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 21:01:03 volumio sudo[26136]: pam_unix(sudo:session): session closed for user root Feb 07 21:01:03 volumio sudo[26138]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 07 21:01:03 volumio sudo[26138]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 21:01:03 volumio volumio[26087]: info: Loading plugin "services"... Feb 07 21:01:03 volumio sudo[26138]: pam_unix(sudo:session): session closed for user root Feb 07 21:01:03 volumio volumio[26087]: info: Loading plugin "alsa_controller"... Feb 07 21:01:03 volumio sudo[26147]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 07 21:01:03 volumio sudo[26147]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 21:01:03 volumio go-librespot[26128]: time="2026-02-07T21:01:03+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 07 21:01:03 volumio go-librespot[26128]: time="2026-02-07T21:01:03+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 07 21:01:03 volumio go-librespot[26128]: time="2026-02-07T21:01:03+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 07 21:01:03 volumio volumio[26087]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 07 21:01:03 volumio volumio[26087]: info: Loading plugin "wizard"... Feb 07 21:01:03 volumio go-librespot[26128]: time="2026-02-07T21:01:03+07:00" level=info msg="zeroconf server listening on port 35817" Feb 07 21:01:03 volumio volumio[26087]: info: Loading plugin "networkfs"... Feb 07 21:01:03 volumio volumio[26087]: info: Starting Udev Watcher for removable devices Feb 07 21:01:03 volumio volumio[26087]: info: Ignoring mount for partition: boot Feb 07 21:01:03 volumio volumio[26087]: info: Ignoring mount for partition: volumio Feb 07 21:01:03 volumio volumio[26087]: info: Ignoring mount for partition: volumio_data Feb 07 21:01:03 volumio volumio[26087]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 07 21:01:03 volumio volumio[26087]: info: Loading plugin "volumio_command_line_client"... Feb 07 21:01:03 volumio volumio[26087]: info: Loading plugin "upnp"... Feb 07 21:01:03 volumio volumio[26087]: info: [1770472863665] Starting Upmpd Daemon Feb 07 21:01:03 volumio volumio[26087]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 07 21:01:03 volumio volumio[26087]: info: Loading plugin "my_music"... Feb 07 21:01:03 volumio volumio[26087]: info: Loading plugin "mpd"... Feb 07 21:01:03 volumio go-librespot[26128]: time="2026-02-07T21:01:03+07:00" level=debug msg="obtained new client token: AADvEsbUhQflvu8QmFxS0fJvu6mBOVZ6imzu7kvzHGnW0PMxivmoduWL/Z7IDD6vgOZsZTqXumqNjm6LZ9Yzn8xRYgjzxPFjgAVhNEeT1nMT9W62QJA7KJIYkz7Fa5Sm1DQrqeb0+/8rrBf/ZRdOQQIWWPUsZ/BbTv9nFsx8e2WtMDY11jx/QVeFBnpPuzqIZdWROaiJ+hVlvC0zvlhil5mwEx18Uo4foHAO5Z+FpLVqqTRwph13d4NESw==" Feb 07 21:01:03 volumio go-librespot[26128]: time="2026-02-07T21:01:03+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 07 21:01:04 volumio go-librespot[26128]: time="2026-02-07T21:01:04+07:00" level=debug msg="completed keyexchange" Feb 07 21:01:04 volumio go-librespot[26128]: time="2026-02-07T21:01:04+07:00" level=debug msg="completed challenge" Feb 07 21:01:04 volumio go-librespot[26128]: time="2026-02-07T21:01:04+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 07 21:01:04 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 07 21:01:04 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 07 21:01:04 volumio volumio[26087]: info: Loading plugin "upnp_browser"... Feb 07 21:01:06 volumio sudo[26147]: pam_unix(sudo:session): session closed for user root Feb 07 21:01:07 volumio volumio[26087]: info: Starting UPNP Browser Feb 07 21:01:07 volumio volumio[26087]: info: Loading plugin "alarm-clock"... Feb 07 21:01:07 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 14. Feb 07 21:01:07 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 07 21:01:07 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 07 21:01:07 volumio go-librespot[26170]: go-librespot daemon starting... Feb 07 21:01:07 volumio go-librespot[26171]: time="2026-02-07T21:01:07+07:00" level=info msg="running go-librespot 0.4.0" Feb 07 21:01:07 volumio go-librespot[26171]: time="2026-02-07T21:01:07+07:00" level=debug msg="app state loaded" Feb 07 21:01:07 volumio go-librespot[26171]: time="2026-02-07T21:01:07+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 07 21:01:07 volumio volumio[26087]: info: Loading plugin "airplay_emulation"... Feb 07 21:01:07 volumio volumio[26087]: info: Starting Shairport Sync Feb 07 21:01:07 volumio volumio[26087]: info: Loading plugin "last_100"... Feb 07 21:01:07 volumio volumio[26087]: info: Loading plugin "webradio"... Feb 07 21:01:07 volumio volumio[26087]: info: Loading plugin "i2s_dacs"... Feb 07 21:01:07 volumio volumio[26087]: info: Loading plugin "volumiodiscovery"... Feb 07 21:01:07 volumio volumio[26087]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 07 21:01:07 volumio volumio[26087]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 07 21:01:07 volumio volumio[26087]: *** WARNING *** For more information see Feb 07 21:01:07 volumio volumio[26087]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 07 21:01:07 volumio volumio[26087]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 07 21:01:07 volumio volumio[26087]: *** WARNING *** For more information see Feb 07 21:01:07 volumio node[26087]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 07 21:01:07 volumio node[26087]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 07 21:01:07 volumio node[26087]: *** WARNING *** For more information see Feb 07 21:01:07 volumio node[26087]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 07 21:01:07 volumio node[26087]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 07 21:01:07 volumio node[26087]: *** WARNING *** For more information see Feb 07 21:01:07 volumio volumio[26087]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 07 21:01:07 volumio volumio[26087]: info: Discovery: Started advertising with name: Volumio Feb 07 21:01:07 volumio volumio[26087]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 07 21:01:07 volumio volumio[26087]: info: Loading plugin "spop"... Feb 07 21:01:08 volumio go-librespot[26171]: time="2026-02-07T21:01:08+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 07 21:01:08 volumio go-librespot[26171]: time="2026-02-07T21:01:08+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 07 21:01:08 volumio go-librespot[26171]: time="2026-02-07T21:01:08+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 07 21:01:08 volumio go-librespot[26171]: time="2026-02-07T21:01:08+07:00" level=info msg="zeroconf server listening on port 34463" Feb 07 21:01:08 volumio go-librespot[26171]: time="2026-02-07T21:01:08+07:00" level=debug msg="obtained new client token: AABYZbwQcQazne9g//fYmV16vlgRuhGeNy96yFF//ZQa91wlLzMdlw7KOzPDp11vS9ENFsu9JyawOOWHoMz84GdUOPkzQ4E7Qx20e3vpwGYomD23iJfwlZxzSI+jW/LW0k/KaMhCOHTdKuCytmdq4inE0WLzsysQCkP+Fy2AP/M853ne1SWQTR+YYjrWmKuot9s544MEA5ZvaVTeEhpAbrHv69pU4k7NuH9Ef4z0+LcifUQboGumul4=" Feb 07 21:01:08 volumio go-librespot[26171]: time="2026-02-07T21:01:08+07:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:4070, retrying with a different AP" error="dial tcp 104.199.241.202:4070: connect: connection refused" Feb 07 21:01:08 volumio go-librespot[26171]: time="2026-02-07T21:01:08+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Feb 07 21:01:08 volumio go-librespot[26171]: time="2026-02-07T21:01:08+07:00" level=debug msg="completed keyexchange" Feb 07 21:01:08 volumio go-librespot[26171]: time="2026-02-07T21:01:08+07:00" level=debug msg="completed challenge" Feb 07 21:01:08 volumio go-librespot[26171]: time="2026-02-07T21:01:08+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 07 21:01:08 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 07 21:01:08 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 07 21:01:09 volumio volumio[26087]: info: Loading plugin "ytcr"... Feb 07 21:01:11 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 15. Feb 07 21:01:11 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 07 21:01:11 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 07 21:01:11 volumio go-librespot[26180]: go-librespot daemon starting... Feb 07 21:01:11 volumio go-librespot[26181]: time="2026-02-07T21:01:11+07:00" level=info msg="running go-librespot 0.4.0" Feb 07 21:01:11 volumio go-librespot[26181]: time="2026-02-07T21:01:11+07:00" level=debug msg="app state loaded" Feb 07 21:01:11 volumio go-librespot[26181]: time="2026-02-07T21:01:11+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 07 21:01:12 volumio volumio[26087]: info: Loading plugin "ytmusic"... Feb 07 21:01:12 volumio go-librespot[26181]: time="2026-02-07T21:01:12+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 07 21:01:12 volumio go-librespot[26181]: time="2026-02-07T21:01:12+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 07 21:01:12 volumio go-librespot[26181]: time="2026-02-07T21:01:12+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 07 21:01:12 volumio go-librespot[26181]: time="2026-02-07T21:01:12+07:00" level=info msg="zeroconf server listening on port 41685" Feb 07 21:01:12 volumio go-librespot[26181]: time="2026-02-07T21:01:12+07:00" level=debug msg="obtained new client token: AABof+XP913YhpmrTzrBr3r8UYXFlByaNuWPOpj5/YdlLVEYURORdRAoQKDAIP+X12aqoD359hL5Rds0NonXi/qZyxXbKjq8Epru/G+j7ubZ2+kgkBWSTXTQR0Tl5lDxcTrcUg+De3YmSeJAhhUTtgcjNeAirUq9i1RDgR0+6LbxF4F5QQtw1S+zMCVTSn8+ZU9/+labLHk9s7fqVVpOEWLFiUrO5Nie8tih/+vPsr2jdFMxrPmjZmFKeQ==" Feb 07 21:01:12 volumio go-librespot[26181]: time="2026-02-07T21:01:12+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 07 21:01:12 volumio go-librespot[26181]: time="2026-02-07T21:01:12+07:00" level=debug msg="completed keyexchange" Feb 07 21:01:12 volumio go-librespot[26181]: time="2026-02-07T21:01:12+07:00" level=debug msg="completed challenge" Feb 07 21:01:13 volumio go-librespot[26181]: time="2026-02-07T21:01:13+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 07 21:01:13 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 07 21:01:13 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 07 21:01:13 volumio volumio-remote-updater[643]: [2026-02-07 21:01:13] [connect] Successful connection Feb 07 21:01:13 volumio volumio[26087]: info: Loading plugin "outputs"... Feb 07 21:01:13 volumio volumio[26087]: info: Loading plugin "albumart"... Feb 07 21:01:13 volumio volumio[26087]: info: Plugin example_plugin is not enabled Feb 07 21:01:13 volumio volumio[26087]: info: Loading plugin "inputs"... Feb 07 21:01:13 volumio volumio[26087]: info: Loading plugin "updater_comm"... Feb 07 21:01:13 volumio volumio[26087]: info: Plugin mpdemulation is not enabled Feb 07 21:01:13 volumio volumio[26087]: info: Loading plugin "rest_api"... Feb 07 21:01:13 volumio volumio[26087]: info: Loading plugin "websocket"... Feb 07 21:01:13 volumio volumio[26087]: info: Starting Socket.io Server version 1.7.4 Feb 07 21:01:13 volumio volumio[26087]: info: Loading plugin "RoonBridge"... Feb 07 21:01:14 volumio volumio[26087]: info: Applying required configuration parameters for plugin RoonBridge Feb 07 21:01:14 volumio volumio[26087]: info: Loading i18n strings for locale en Feb 07 21:01:14 volumio volumio[26087]: Updating browse sources language Feb 07 21:01:14 volumio volumio[26087]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 07 21:01:14 volumio volumio[26203]: Forking 3 albumart workers Feb 07 21:01:14 volumio volumio[26087]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 07 21:01:14 volumio volumio[26087]: info: CoreCommandRouter::initPlayerControls Feb 07 21:01:14 volumio volumio[26087]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 21:01:14 volumio volumio[26087]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 21:01:14 volumio volumio[26087]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 21:01:14 volumio volumio[26087]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 21:01:14 volumio volumio[26087]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 21:01:14 volumio volumio[26087]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 21:01:14 volumio volumio[26087]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 21:01:14 volumio volumio[26087]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 21:01:14 volumio volumio[26087]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 07 21:01:14 volumio volumio[26087]: Express server listening on port 3000 Feb 07 21:01:14 volumio volumio[26087]: [Metrics] WebUI: 16s 33.34ms Feb 07 21:01:14 volumio volumio[26087]: info: CoreStateMachine::resetVolumioState Feb 07 21:01:14 volumio volumio[26087]: info: CoreStateMachine::getcurrentVolume Feb 07 21:01:14 volumio volumio[26087]: info: CoreCommandRouter::volumioRetrievevolume Feb 07 21:01:15 volumio sudo[26248]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 07 21:01:15 volumio sudo[26250]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 07 21:01:15 volumio volumio[26087]: info: Volumio Network Manager: Network status updated: 1 Feb 07 21:01:15 volumio sudo[26248]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 21:01:15 volumio sudo[26250]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 21:01:15 volumio sudo[26250]: pam_unix(sudo:session): session closed for user root Feb 07 21:01:15 volumio sudo[26248]: pam_unix(sudo:session): session closed for user root Feb 07 21:01:15 volumio volumio[26087]: info: VolumeController:: Volume=100 Mute =false Feb 07 21:01:15 volumio volumio[26087]: info: CoreStateMachine::pushState Feb 07 21:01:15 volumio volumio[26087]: info: CorePlayQueue::getTrack 0 Feb 07 21:01:15 volumio volumio[26087]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 07 21:01:15 volumio volumio[26087]: info: CoreCommandRouter::volumioPushState Feb 07 21:01:15 volumio volumio[26087]: info: CoreStateMachine::updateTrackBlock Feb 07 21:01:15 volumio volumio[26087]: info: CorePlayQueue::getTrackBlock Feb 07 21:01:15 volumio volumio[26087]: info: CoreCommandRouter::volumioRetrievevolume Feb 07 21:01:15 volumio volumio-remote-updater[643]: [2026-02-07 21:01:15] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1770472873 101 Feb 07 21:01:15 volumio volumio[26087]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 1 Feb 07 21:01:15 volumio volumio[26087]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 21:01:15 volumio volumio[26087]: info: Reloading queue from file Feb 07 21:01:15 volumio volumio[26087]: info: CoreStateMachine::setRepeat null single undefined Feb 07 21:01:15 volumio volumio[26087]: info: CoreStateMachine::pushState Feb 07 21:01:15 volumio volumio[26087]: info: CorePlayQueue::getTrack 0 Feb 07 21:01:15 volumio volumio[26087]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 07 21:01:15 volumio volumio[26087]: info: CoreCommandRouter::volumioPushState Feb 07 21:01:15 volumio volumio[26087]: info: CoreStateMachine::setRandom null Feb 07 21:01:15 volumio volumio[26087]: info: CoreStateMachine::pushState Feb 07 21:01:15 volumio volumio[26087]: info: CorePlayQueue::getTrack 0 Feb 07 21:01:15 volumio volumio[26087]: info: CoreCommandRouter::volumioPushState Feb 07 21:01:15 volumio volumio[26087]: info: Setting Device type: Raspberry PI Feb 07 21:01:15 volumio volumio[26087]: info: Completed loading Core Plugins Feb 07 21:01:15 volumio volumio[26087]: info: Preparing to generate the ALSA configuration file Feb 07 21:01:15 volumio volumio[26087]: info: VolumeController:: Volume=100 Mute =false Feb 07 21:01:15 volumio volumio[26087]: info: CoreStateMachine::pushState Feb 07 21:01:15 volumio volumio[26087]: info: CorePlayQueue::getTrack 0 Feb 07 21:01:15 volumio volumio[26087]: info: CoreCommandRouter::volumioPushState Feb 07 21:01:15 volumio volumio[26087]: info: Asound.conf file unchanged, so no further update is needed Feb 07 21:01:15 volumio volumio[26087]: info: Output device has changed, restarting MPD Feb 07 21:01:15 volumio volumio[26087]: info: Output device has changed, restarting Shairport Sync Feb 07 21:01:15 volumio volumio[26087]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 21:01:15 volumio volumio[26087]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 21:01:15 volumio sudo[26264]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 07 21:01:15 volumio sudo[26264]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 21:01:16 volumio sudo[26266]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 07 21:01:16 volumio volumio[26087]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 07 21:01:16 volumio sudo[26266]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 21:01:16 volumio volumio[26087]: info: ___________ START PLUGINS ___________ Feb 07 21:01:16 volumio volumio[26087]: info: ControllerMpd::onStart: Initializing MPD Feb 07 21:01:16 volumio sudo[26266]: pam_unix(sudo:session): session closed for user root Feb 07 21:01:16 volumio volumio[26087]: info: Creating MPD Configuration file Feb 07 21:01:16 volumio sudo[26268]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 07 21:01:16 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 16. Feb 07 21:01:16 volumio volumio[26087]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 07 21:01:16 volumio volumio[26087]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 07 21:01:16 volumio volumio[26087]: info: [1770472876095] CoreMusicLibrary::Adding element Media Servers Feb 07 21:01:16 volumio volumio[26087]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 07 21:01:16 volumio sudo[26268]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 21:01:16 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 07 21:01:16 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 07 21:01:16 volumio go-librespot[26280]: go-librespot daemon starting... Feb 07 21:01:16 volumio sudo[26276]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 07 21:01:16 volumio volumio[26087]: info: UPNP Browser: Client initialized successfully Feb 07 21:01:16 volumio sudo[26276]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 21:01:16 volumio sudo[26276]: pam_unix(sudo:session): session closed for user root Feb 07 21:01:16 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 07 21:01:16 volumio go-librespot[26281]: time="2026-02-07T21:01:16+07:00" level=info msg="running go-librespot 0.4.0" Feb 07 21:01:16 volumio sudo[26264]: pam_unix(sudo:session): session closed for user root Feb 07 21:01:16 volumio go-librespot[26281]: time="2026-02-07T21:01:16+07:00" level=debug msg="app state loaded" Feb 07 21:01:16 volumio go-librespot[26281]: time="2026-02-07T21:01:16+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 07 21:01:16 volumio sudo[26278]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 07 21:01:16 volumio sudo[26278]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 21:01:16 volumio volumio[26087]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 21:01:16 volumio volumio[26087]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 21:01:16 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 07 21:01:16 volumio volumio[26087]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 07 21:01:16 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 07 21:01:16 volumio systemd[1]: mpd.service: Consumed 7.063s CPU time. Feb 07 21:01:16 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 07 21:01:16 volumio volumio[26087]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 21:01:16 volumio volumio[26087]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 21:01:16 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 07 21:01:16 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 07 21:01:16 volumio volumio[26087]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 07 21:01:16 volumio volumio[26087]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 07 21:01:16 volumio volumio[26087]: info: [1770472876532] CoreMusicLibrary::Adding element Last_100 Feb 07 21:01:16 volumio volumio[26087]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 07 21:01:16 volumio volumio[26087]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 07 21:01:16 volumio volumio[26087]: info: [1770472876551] CoreMusicLibrary::Adding element Webradio Feb 07 21:01:16 volumio volumio[26087]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 07 21:01:16 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 07 21:01:16 volumio volumio[26087]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 07 21:01:16 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 07 21:01:16 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 07 21:01:16 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 07 21:01:16 volumio volumio[26087]: info: Initializing BBC Radios Feb 07 21:01:16 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 07 21:01:16 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 07 21:01:16 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 07 21:01:16 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 07 21:01:16 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 07 21:01:16 volumio volumio[26087]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 07 21:01:16 volumio volumio[26087]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 21:01:16 volumio volumio[26087]: info: Creating Spotify config file Feb 07 21:01:16 volumio volumio[26087]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 21:01:16 volumio go-librespot[26281]: time="2026-02-07T21:01:16+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 07 21:01:16 volumio go-librespot[26281]: time="2026-02-07T21:01:16+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 07 21:01:16 volumio go-librespot[26281]: time="2026-02-07T21:01:16+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 07 21:01:17 volumio go-librespot[26281]: time="2026-02-07T21:01:17+07:00" level=info msg="zeroconf server listening on port 37943" Feb 07 21:01:17 volumio sudo[26303]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 07 21:01:17 volumio sudo[26303]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 07 21:01:17 volumio sudo[26303]: pam_unix(sudo:session): session closed for user root Feb 07 21:01:17 volumio go-librespot[26281]: time="2026-02-07T21:01:17+07:00" level=debug msg="obtained new client token: AADVqlsoFMcwvXkUF7zF/xVbYqbcw191ySv+uAT+ce+atoRogayIHQx60TAT7nSMqiw9mkPebfPuqP/MFUjVKnZchQ6jPgdsTrv+GkLgFixLFl592cuNX0jYtkqj1aSctD3i92PoKSvxK9yWttzyBqHFVq57AR3DoU0/XA+1x5kzdEsPIDMUorS8pt45IBY/uxn8vLQAGJQ5EwXOql6K0CtLp8m5sltDPa5UugtrZerlBcB0yFOHO50=" Feb 07 21:01:17 volumio go-librespot[26281]: time="2026-02-07T21:01:17+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 07 21:01:17 volumio go-librespot[26281]: time="2026-02-07T21:01:17+07:00" level=debug msg="completed keyexchange" Feb 07 21:01:17 volumio go-librespot[26281]: time="2026-02-07T21:01:17+07:00" level=debug msg="completed challenge" Feb 07 21:01:17 volumio go-librespot[26281]: time="2026-02-07T21:01:17+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 07 21:01:17 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 07 21:01:17 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 07 21:01:17 volumio volumio[26214]: Starting albumart workers Feb 07 21:01:18 volumio volumio[26087]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 07 21:01:18 volumio volumio[26087]: info: [1770472878079] CoreMusicLibrary::Adding element YouTube Music Feb 07 21:01:18 volumio volumio[26087]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 07 21:01:18 volumio volumio[26087]: Cannot find translation for source YouTube Music Feb 07 21:01:18 volumio volumio[26087]: info: Volumio Calling Home Feb 07 21:01:18 volumio sudo[26318]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Feb 07 21:01:18 volumio sudo[26318]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 21:01:18 volumio sudo[26318]: pam_unix(sudo:session): session closed for user root Feb 07 21:01:18 volumio volumio[26213]: Starting albumart workers Feb 07 21:01:18 volumio volumio[26215]: Starting albumart workers Feb 07 21:01:18 volumio volumio[26087]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Feb 07 21:01:18 volumio volumio[26087]: info: Discovery: Found device Volumio Feb 07 21:01:18 volumio volumio[26087]: info: CoreCommandRouter::volumioGetState Feb 07 21:01:18 volumio volumio[26087]: info: CorePlayQueue::getTrack 0 Feb 07 21:01:18 volumio volumio[26087]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Feb 07 21:01:18 volumio volumio[26087]: info: Discovery: Found device Volumio Feb 07 21:01:18 volumio volumio[26087]: info: CoreCommandRouter::volumioGetState Feb 07 21:01:18 volumio volumio[26087]: info: CorePlayQueue::getTrack 0 Feb 07 21:01:18 volumio volumio[26087]: info: MPD Permissions set Feb 07 21:01:18 volumio volumio[26087]: info: MPD Permissions set Feb 07 21:01:18 volumio volumio[26087]: info: Upmpdcli Daemon Started Feb 07 21:01:19 volumio volumio[26087]: info: Spotify config file written Feb 07 21:01:19 volumio sudo[26324]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 07 21:01:19 volumio sudo[26324]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 21:01:19 volumio volumio[26087]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Feb 07 21:01:19 volumio volumio[26087]: info: Volumio called home Feb 07 21:01:19 volumio volumio[26087]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 21:01:19 volumio volumio[26087]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 21:01:19 volumio volumio[26087]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 21:01:19 volumio volumio[26087]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 21:01:19 volumio volumio[26087]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 21:01:19 volumio volumio[26087]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 21:01:19 volumio volumio[26087]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 21:01:19 volumio volumio[26087]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 21:01:19 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 07 21:01:19 volumio volumio[26087]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 21:01:19 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 07 21:01:19 volumio go-librespot[26331]: go-librespot daemon starting... Feb 07 21:01:19 volumio volumio[26087]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 21:01:19 volumio volumio[26087]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 21:01:19 volumio volumio[26087]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 21:01:19 volumio volumio[26087]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 21:01:19 volumio volumio[26087]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 21:01:19 volumio volumio[26087]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 21:01:19 volumio volumio[26087]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 21:01:19 volumio volumio[26087]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 21:01:19 volumio volumio[26087]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 21:01:19 volumio sudo[26324]: pam_unix(sudo:session): session closed for user root Feb 07 21:01:19 volumio go-librespot[26332]: time="2026-02-07T21:01:19+07:00" level=info msg="running go-librespot 0.4.0" Feb 07 21:01:19 volumio go-librespot[26332]: time="2026-02-07T21:01:19+07:00" level=debug msg="app state loaded" Feb 07 21:01:19 volumio go-librespot[26332]: time="2026-02-07T21:01:19+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 07 21:01:19 volumio volumio[26087]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 21:01:19 volumio volumio[26087]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 07 21:01:19 volumio volumio[26087]: info: No need to fix Spotify hosts Feb 07 21:01:20 volumio go-librespot[26332]: time="2026-02-07T21:01:20+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 07 21:01:20 volumio go-librespot[26332]: time="2026-02-07T21:01:20+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 07 21:01:20 volumio go-librespot[26332]: time="2026-02-07T21:01:20+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 07 21:01:20 volumio go-librespot[26332]: time="2026-02-07T21:01:20+07:00" level=info msg="zeroconf server listening on port 37057" Feb 07 21:01:20 volumio go-librespot[26332]: time="2026-02-07T21:01:20+07:00" level=debug msg="obtained new client token: AADRZuaeCeUuPFmOt2ki6mN77IPJIFWPDaSOPtK61Bz2TD80oGLRqy/EAYbKyaNkvUmVmZn3eV1sA59gBaUHTpjDWgWBH+wjjvWa0FwneLbDHlJ2IJ4TS79qYj6cqjq+cIKTsvQ6c9JuOhI+hjCD6e1oT1nNuApBLwgYM4/KWVql6QN6vsNzNvXfBzkTR5BUFTTy4pXUmFHU/wupTZxr9r/wv97sD3J51mHz/6P633kDOi0wSJ7lhoQ6rw==" Feb 07 21:01:20 volumio go-librespot[26332]: time="2026-02-07T21:01:20+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 07 21:01:20 volumio go-librespot[26332]: time="2026-02-07T21:01:20+07:00" level=debug msg="completed keyexchange" Feb 07 21:01:20 volumio go-librespot[26332]: time="2026-02-07T21:01:20+07:00" level=debug msg="completed challenge" Feb 07 21:01:20 volumio go-librespot[26332]: time="2026-02-07T21:01:20+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 07 21:01:20 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 07 21:01:20 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 07 21:01:20 volumio volumio[26087]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 07 21:01:20 volumio volumio[26087]: SPOTIFY: BQBoQ24Iedf13M6mfKfiAubpyB9FGhUC9Pm9MbqgthQ4kPrsatppXaqrOquN_5zSNyCQa3jpa-7V3rAwMLFfOWqkh-_CZp4852euQHKUmr3-oDRkttcY7rhOMeQBZOrzvIvh06epRYlc8767wIoRgH10VKmtsXPeFgJwE_P41NQcb6KOwhergeljwVKB7ZKHk-arUDSHcbWRDKZ5K72tAZNzM1vtuDwK8swfVThiaFE5IKLg9UJhRhNPrp-EVbbdiEGv5MfTMCa9dc7KzoWXdf-Gng-jR6WnTwT9bzs9XdyNj9BaHbVzPRAJ Feb 07 21:01:20 volumio volumio[26087]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 07 21:01:20 volumio volumio[26087]: info: New Spotify access token = BQBoQ24Iedf13M6mfKfiAubpyB9FGhUC9Pm9MbqgthQ4kPrsatppXaqrOquN_5zSNyCQa3jpa-7V3rAwMLFfOWqkh-_CZp4852euQHKUmr3-oDRkttcY7rhOMeQBZOrzvIvh06epRYlc8767wIoRgH10VKmtsXPeFgJwE_P41NQcb6KOwhergeljwVKB7ZKHk-arUDSHcbWRDKZ5K72tAZNzM1vtuDwK8swfVThiaFE5IKLg9UJhRhNPrp-EVbbdiEGv5MfTMCa9dc7KzoWXdf-Gng-jR6WnTwT9bzs9XdyNj9BaHbVzPRAJ Feb 07 21:01:20 volumio volumio[26087]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 07 21:01:20 volumio volumio[26087]: info: Starting Shairport Sync Feb 07 21:01:20 volumio volumio[26087]: info: Starting Shairport Sync Feb 07 21:01:20 volumio volumio[26087]: info: Starting Shairport Sync Feb 07 21:01:21 volumio sudo[26363]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 07 21:01:21 volumio sudo[26363]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 21:01:21 volumio sudo[26365]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 07 21:01:21 volumio sudo[26365]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 21:01:21 volumio sudo[26367]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 07 21:01:21 volumio sudo[26367]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 21:01:21 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 07 21:01:21 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 07 21:01:21 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 07 21:01:21 volumio systemd[1]: shairport-sync.service: Consumed 2.245s CPU time. Feb 07 21:01:21 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 07 21:01:21 volumio sudo[26363]: pam_unix(sudo:session): session closed for user root Feb 07 21:01:21 volumio sudo[26365]: pam_unix(sudo:session): session closed for user root Feb 07 21:01:21 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 07 21:01:21 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 07 21:01:21 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 07 21:01:21 volumio volumio[26087]: info: Shairport-Sync Started Feb 07 21:01:21 volumio volumio[26087]: Error adding Membership: Error: addMembership EINVAL Feb 07 21:01:21 volumio volumio[26087]: info: Shairport-Sync Started Feb 07 21:01:21 volumio volumio[26087]: info: CoreCommandRouter::volumioGetState Feb 07 21:01:21 volumio volumio[26087]: info: CorePlayQueue::getTrack 0 Feb 07 21:01:21 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 07 21:01:21 volumio sudo[26367]: pam_unix(sudo:session): session closed for user root Feb 07 21:01:21 volumio volumio[26087]: info: Shairport-Sync Started Feb 07 21:01:21 volumio volumio[26087]: SPOTIFY: User informations: {"country":"PK","display_name":"215mmgea6kss3jxeqsqdquvji","email":"linh.ngotran@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/215mmgea6kss3jxeqsqdquvji"},"followers":{"href":null,"total":1},"href":"https://api.spotify.com/v1/users/215mmgea6kss3jxeqsqdquvji","id":"215mmgea6kss3jxeqsqdquvji","images":[],"product":"premium","type":"user","uri":"spotify:user:215mmgea6kss3jxeqsqdquvji"} Feb 07 21:01:21 volumio volumio[26087]: info: Spotify Successfully logged in Feb 07 21:01:21 volumio volumio[26087]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 07 21:01:21 volumio volumio[26087]: info: [1770472881693] CoreMusicLibrary::Adding element Spotify Feb 07 21:01:21 volumio volumio[26087]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 07 21:01:21 volumio volumio[26087]: Cannot find translation for source YouTube Music Feb 07 21:01:21 volumio volumio[26087]: Cannot find translation for source Spotify Feb 07 21:01:22 volumio volumio[26087]: info: [yt-cast-receiver] DIAL server listening on port 8098 Feb 07 21:01:22 volumio volumio[26087]: info: CoreCommandRouter::volumioRetrievevolume Feb 07 21:01:22 volumio volumio[26087]: info: VolumeController:: Volume=100 Mute =false Feb 07 21:01:22 volumio volumio[26087]: info: CoreCommandRouter::volumioGetState Feb 07 21:01:22 volumio volumio[26087]: info: CorePlayQueue::getTrack 0 Feb 07 21:01:22 volumio volumio[26087]: info: CoreStateMachine::pushState Feb 07 21:01:22 volumio volumio[26087]: info: CorePlayQueue::getTrack 0 Feb 07 21:01:22 volumio volumio[26087]: info: CoreCommandRouter::volumioPushState Feb 07 21:01:23 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 17. Feb 07 21:01:23 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 07 21:01:23 volumio volumio[26087]: info: go-librespot daemon successfully initialized Feb 07 21:01:23 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 07 21:01:23 volumio go-librespot[26404]: go-librespot daemon starting... Feb 07 21:01:23 volumio go-librespot[26405]: time="2026-02-07T21:01:23+07:00" level=info msg="running go-librespot 0.4.0" Feb 07 21:01:23 volumio go-librespot[26405]: time="2026-02-07T21:01:23+07:00" level=debug msg="app state loaded" Feb 07 21:01:23 volumio go-librespot[26405]: time="2026-02-07T21:01:23+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 07 21:01:24 volumio mpd[26316]: 2026-02-07T21:01:24 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 07 21:01:24 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 07 21:01:24 volumio sudo[26278]: pam_unix(sudo:session): session closed for user root Feb 07 21:01:24 volumio sudo[26268]: pam_unix(sudo:session): session closed for user root Feb 07 21:01:24 volumio go-librespot[26405]: time="2026-02-07T21:01:24+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 07 21:01:24 volumio go-librespot[26405]: time="2026-02-07T21:01:24+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 07 21:01:24 volumio go-librespot[26405]: time="2026-02-07T21:01:24+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 07 21:01:24 volumio volumio[26087]: error: MPD error: The expression evaluated to a falsy value: Feb 07 21:01:24 volumio volumio[26087]: assert.ok(self.idling) Feb 07 21:01:24 volumio volumio[26087]: error: The expression evaluated to a falsy value: Feb 07 21:01:24 volumio volumio[26087]: assert.ok(self.idling) Feb 07 21:01:24 volumio go-librespot[26405]: time="2026-02-07T21:01:24+07:00" level=info msg="zeroconf server listening on port 43849" Feb 07 21:01:24 volumio volumio[26087]: info: MPD running with PID26316 Feb 07 21:01:24 volumio volumio[26087]: ,establishing connection Feb 07 21:01:24 volumio volumio[26087]: error: updateQueue error: null Feb 07 21:01:24 volumio volumio[26087]: info: Completed starting Core Plugins Feb 07 21:01:24 volumio volumio[26087]: info: ------------------------------------------- Feb 07 21:01:24 volumio volumio[26087]: info: ----- MyVolumio plugins startup ---- Feb 07 21:01:24 volumio volumio[26087]: info: ------------------------------------------- Feb 07 21:01:24 volumio volumio[26087]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 07 21:01:24 volumio volumio[26087]: error: updateQueue error: null Feb 07 21:01:24 volumio go-librespot[26405]: time="2026-02-07T21:01:24+07:00" level=debug msg="obtained new client token: AABx4sFOPA7LUIYa/OR1fEfWQYfip5fc5fgP7I/bYtbYiMbcSm9CGHN2X4rmjHsWFChhdH5RkhZJrlvQN4azbEgjD3OyUBIsx9CJriZzJlqSEQMHxtqYhLr3P471V9lF0FOlFenYa8CWBS+ktGBE8tvVa2r5LfMH1QPoldKWZxUfU0UI3Zeutjm6IO728WOLlcsuKh3iY5InwXS7p0SZzrDQHtnLF/NSiD9d8/AL0xgSTwGROdElxH3VnA==" Feb 07 21:01:24 volumio go-librespot[26405]: time="2026-02-07T21:01:24+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 07 21:01:24 volumio go-librespot[26405]: time="2026-02-07T21:01:24+07:00" level=debug msg="completed keyexchange" Feb 07 21:01:24 volumio go-librespot[26405]: time="2026-02-07T21:01:24+07:00" level=debug msg="completed challenge" Feb 07 21:01:24 volumio go-librespot[26405]: time="2026-02-07T21:01:24+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 07 21:01:24 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 07 21:01:24 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 07 21:01:26 volumio volumio[26087]: info: Initializing connection to go-librespot Websocket Feb 07 21:01:26 volumio volumio[26087]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 07 21:01:28 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 18. Feb 07 21:01:28 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 07 21:01:28 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 07 21:01:28 volumio go-librespot[26419]: go-librespot daemon starting... Feb 07 21:01:28 volumio go-librespot[26420]: time="2026-02-07T21:01:28+07:00" level=info msg="running go-librespot 0.4.0" Feb 07 21:01:28 volumio go-librespot[26420]: time="2026-02-07T21:01:28+07:00" level=debug msg="app state loaded" Feb 07 21:01:28 volumio go-librespot[26420]: time="2026-02-07T21:01:28+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 07 21:01:28 volumio go-librespot[26420]: time="2026-02-07T21:01: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 07 21:01:28 volumio go-librespot[26420]: time="2026-02-07T21:01: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 07 21:01:28 volumio go-librespot[26420]: time="2026-02-07T21:01: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 07 21:01:28 volumio go-librespot[26420]: time="2026-02-07T21:01:28+07:00" level=info msg="zeroconf server listening on port 34269" Feb 07 21:01:28 volumio go-librespot[26420]: time="2026-02-07T21:01:28+07:00" level=debug msg="obtained new client token: AAClEuRWBL2bQBNqQxYgQwa2KswajGwKLyYndVsxEQhFBNIReB/j0Y5PQOiqOse/GmpjuwmTx0hIfU7S3t9mtY2fwh/iaL61Q8lhFDBVymJ1wRTdiuiCzAuw2Wsjr8tZ8nk2Wpoxny9lDg1sFdxTREOd1ALgswSrpSDRqAXeterr1cKCot92aaBy/onb7xn3tOhLXNknEVLYeeitTHrX98t+fkwR2Uv0wgUGmFzzgPLg8CiL1JPWRoGZOg==" Feb 07 21:01:28 volumio go-librespot[26420]: time="2026-02-07T21:01:28+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 07 21:01:29 volumio go-librespot[26420]: time="2026-02-07T21:01:29+07:00" level=debug msg="completed keyexchange" Feb 07 21:01:29 volumio go-librespot[26420]: time="2026-02-07T21:01:29+07:00" level=debug msg="completed challenge" Feb 07 21:01:29 volumio go-librespot[26420]: time="2026-02-07T21:01: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 07 21:01:29 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 07 21:01:29 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 07 21:01:29 volumio volumio[26087]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 07 21:01:29 volumio volumio[26087]: info: Initializing connection to go-librespot Websocket Feb 07 21:01:29 volumio volumio[26087]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 07 21:01:32 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 19. Feb 07 21:01:32 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 07 21:01:32 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 07 21:01:32 volumio go-librespot[26428]: go-librespot daemon starting... Feb 07 21:01:32 volumio go-librespot[26429]: time="2026-02-07T21:01:32+07:00" level=info msg="running go-librespot 0.4.0" Feb 07 21:01:32 volumio go-librespot[26429]: time="2026-02-07T21:01:32+07:00" level=debug msg="app state loaded" Feb 07 21:01:32 volumio go-librespot[26429]: time="2026-02-07T21:01:32+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 07 21:01:32 volumio volumio[26087]: info: Initializing connection to go-librespot Websocket Feb 07 21:01:32 volumio go-librespot[26429]: time="2026-02-07T21:01:32+07:00" level=debug msg="new websocket client" Feb 07 21:01:32 volumio volumio[26087]: info: Connection to go-librespot Websocket established Feb 07 21:01:32 volumio go-librespot[26429]: time="2026-02-07T21:01:32+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 07 21:01:32 volumio go-librespot[26429]: time="2026-02-07T21:01:32+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 07 21:01:32 volumio go-librespot[26429]: time="2026-02-07T21:01:32+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 07 21:01:32 volumio go-librespot[26429]: time="2026-02-07T21:01:32+07:00" level=info msg="zeroconf server listening on port 36113" Feb 07 21:01:33 volumio go-librespot[26429]: time="2026-02-07T21:01:33+07:00" level=debug msg="obtained new client token: AAAL7JLVFHf1bA3Ndptj8HM6y6lFQPVy7R43J9qqSAKw6U3ffdmrEv+ub+rf1RbP6kz/BzRwj6figcQmsHoZINIKkayQhotJEkC7r8xOFKvrAZUzfwCveLhuCc2Q4BVChXy+jAvbrVJLsQMJYV2V7UWxKtjKcn4cZZgPvMheaCkj6SgpEKl6+ByVf63C3GxHaKhkOvH7qJGWFDpplb/LcMG++w21Fdxs1i+Dit9plKOhu96I/48uF20=" Feb 07 21:01:33 volumio go-librespot[26429]: time="2026-02-07T21:01: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 07 21:01:33 volumio volumio[26087]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 07 21:01:33 volumio volumio[26087]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 07 21:01:33 volumio volumio[26087]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 07 21:01:33 volumio volumio[26087]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 07 21:01:33 volumio volumio[26087]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 07 21:01:33 volumio volumio[26087]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 07 21:01:33 volumio volumio[26087]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 07 21:01:33 volumio volumio[26087]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 07 21:01:33 volumio volumio[26087]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 07 21:01:33 volumio volumio[26087]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 07 21:01:33 volumio volumio[26087]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 07 21:01:33 volumio volumio[26087]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 07 21:01:33 volumio volumio[26087]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 07 21:01:33 volumio volumio[26087]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 07 21:01:33 volumio volumio[26087]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 07 21:01:33 volumio volumio[26087]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 07 21:01:33 volumio volumio[26087]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 07 21:01:33 volumio volumio[26087]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 07 21:01:33 volumio volumio[26087]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 07 21:01:33 volumio volumio[26087]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 07 21:01:33 volumio volumio[26087]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 07 21:01:33 volumio volumio[26087]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 07 21:01:33 volumio volumio[26087]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 07 21:01:33 volumio volumio[26087]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 07 21:01:33 volumio volumio[26087]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 07 21:01:33 volumio volumio[26087]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 07 21:01:33 volumio volumio[26087]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 07 21:01:33 volumio volumio[26087]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 07 21:01:33 volumio volumio[26087]: info: Adding plugin bluetooth to MyMusic Plugins Feb 07 21:01:33 volumio volumio[26087]: info: Adding plugin multiroom to MyMusic Plugins Feb 07 21:01:33 volumio volumio[26087]: info: Adding plugin metavolumio to MyMusic Plugins Feb 07 21:01:33 volumio volumio[26087]: info: Adding plugin cd_controller to MyMusic Plugins Feb 07 21:01:33 volumio volumio[26087]: info: Adding plugin qobuzconnect to MyMusic Plugins Feb 07 21:01:33 volumio volumio[26087]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 07 21:01:33 volumio volumio[26087]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 07 21:01:33 volumio volumio[26087]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 07 21:01:33 volumio go-librespot[26429]: time="2026-02-07T21:01:33+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Feb 07 21:01:33 volumio go-librespot[26429]: time="2026-02-07T21:01:33+07:00" level=debug msg="completed keyexchange" Feb 07 21:01:33 volumio go-librespot[26429]: time="2026-02-07T21:01:33+07:00" level=debug msg="completed challenge" Feb 07 21:01:33 volumio go-librespot[26429]: time="2026-02-07T21:01: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 07 21:01:33 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 07 21:01:33 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 07 21:01:35 volumio volumio[26087]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 07 21:01:35 volumio volumio[26087]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 07 21:01:35 volumio volumio[26087]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 21:01:35 volumio volumio[26087]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 07 21:01:35 volumio volumio[26087]: info: Starting MyVolumio Remote Streaming Endpoints Feb 07 21:01:35 volumio volumio[26087]: info: MyVolumio login type: Token Feb 07 21:01:35 volumio volumio[26087]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 07 21:01:35 volumio volumio[26087]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 07 21:01:36 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 20. Feb 07 21:01:36 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 07 21:01:36 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 07 21:01:36 volumio go-librespot[26450]: go-librespot daemon starting... Feb 07 21:01:36 volumio go-librespot[26451]: time="2026-02-07T21:01:36+07:00" level=info msg="running go-librespot 0.4.0" Feb 07 21:01:36 volumio go-librespot[26451]: time="2026-02-07T21:01:36+07:00" level=debug msg="app state loaded" Feb 07 21:01:36 volumio go-librespot[26451]: time="2026-02-07T21:01:36+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 07 21:01:36 volumio volumio[26087]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 07 21:01:36 volumio volumio[26087]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 07 21:01:36 volumio volumio[26087]: info: Streaming services startup Feb 07 21:01:36 volumio volumio[26087]: info: Starting Streaming Daemon Feb 07 21:01:37 volumio volumio[26087]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 07 21:01:37 volumio sudo[26459]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 07 21:01:37 volumio sudo[26459]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 07 21:01:37 volumio sudo[26459]: pam_unix(sudo:session): session closed for user root Feb 07 21:01:37 volumio volumio[26087]: info: Getting Spotify volume Feb 07 21:01:37 volumio volumio[26087]: info: Connection to go-librespot Websocket closed Feb 07 21:01:37 volumio volumio[26087]: error: Cannot start Volumio Streaming Daemon Feb 07 21:01:37 volumio volumio[26087]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 07 21:01:37 volumio volumio[26087]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 07 21:01:37 volumio volumio[26087]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Feb 07 21:01:37 volumio volumio[26087]: info: CoreCommandRouter::volumioGetState Feb 07 21:01:37 volumio volumio[26087]: info: CorePlayQueue::getTrack 0 Feb 07 21:01:37 volumio go-librespot[26451]: time="2026-02-07T21:01: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-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 07 21:01:37 volumio go-librespot[26451]: time="2026-02-07T21:01:37+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 07 21:01:37 volumio go-librespot[26451]: time="2026-02-07T21:01:37+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 07 21:01:37 volumio volumio[26087]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Feb 07 21:01:37 volumio volumio[26087]: SPOTIFY: SPOTIFY VOLUME undefined Feb 07 21:01:37 volumio volumio[26087]: SPOTIFY: VOLUMIO VOLUME 100 Feb 07 21:01:37 volumio volumio[26087]: info: Aligning Spotify Volume to Volumio Volume Feb 07 21:01:37 volumio volumio[26087]: info: CoreCommandRouter::volumioGetState Feb 07 21:01:37 volumio volumio[26087]: info: CorePlayQueue::getTrack 0 Feb 07 21:01:37 volumio volumio[26087]: info: Setting Spotify Volume from Volumio: 100 Feb 07 21:01:37 volumio go-librespot[26451]: time="2026-02-07T21:01:37+07:00" level=info msg="zeroconf server listening on port 40177" Feb 07 21:01:37 volumio go-librespot[26451]: time="2026-02-07T21:01:37+07:00" level=debug msg="obtained new client token: AAA1nbv8kogTACOPm7woK86zG/4nfUPkgNiPXPWwUwjAc5aFMaCtjiuSGjXb4dJNWUqQT8ZoPM8n8Z8Nr+S+gCquIST391XxeUawYg55GhhEh6h/n8cdkxUoSsR8DDB8kHfapAVD2hehcM1xQPF1jd98i9IwnsGb3AVvXxh0fBdzewPVerf3D7ilPaJatDfj8+eUsxTehFDAzosLFf+LOCV325OPyba+jOEp0BCoT2OC9zMYM+9OhOGHaQ==" Feb 07 21:01:37 volumio go-librespot[26451]: time="2026-02-07T21:01:37+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 07 21:01:37 volumio go-librespot[26451]: time="2026-02-07T21:01:37+07:00" level=debug msg="completed keyexchange" Feb 07 21:01:37 volumio go-librespot[26451]: time="2026-02-07T21:01:37+07:00" level=debug msg="completed challenge" Feb 07 21:01:38 volumio go-librespot[26451]: time="2026-02-07T21:01:38+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 07 21:01:38 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 07 21:01:38 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 07 21:01:38 volumio volumio[26087]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 07 21:01:38 volumio volumio[26087]: Error: socket hang up Feb 07 21:01:38 volumio volumio[26087]: at connResetException (node:internal/errors:720:14) Feb 07 21:01:38 volumio volumio[26087]: at Socket.socketOnEnd (node:_http_client:519:23) Feb 07 21:01:38 volumio volumio[26087]: at Socket.emit (node:events:526:35) Feb 07 21:01:38 volumio volumio[26087]: at endReadableNT (node:internal/streams/readable:1376:12) Feb 07 21:01:38 volumio volumio[26087]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Feb 07 21:01:38 volumio volumio[26087]: code: 'ECONNRESET', Feb 07 21:01:38 volumio volumio[26087]: response: undefined Feb 07 21:01:38 volumio volumio[26087]: } Feb 07 21:01:38 volumio volumio[26087]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 07 21:01:39 volumio sudo[26481]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-07 21:00' Feb 07 21:01:39 volumio sudo[26481]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) PRETTY_NAME="Raspbian GNU/Linux 12 (bookworm)" NAME="Raspbian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="b05a530ca81d05eb9a84d0acf82089f0a60b8ee6" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="4ad85e2147d972f0b838d33c21382d2d813b2ae8" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu Dec 25 09:13:19 UTC 2025" VOLUMIO_VERSION="4.084" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="792f09af7488531aecd1aadcaa9b175e"