Jan 28 03:26:00 volumio sudo[7758]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jan 28 03:26:00 volumio sudo[7758]: pam_unix(sudo:session): session closed for user root Jan 28 03:26:00 volumio go-librespot[7748]: time="2026-01-28T03:26:00+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 03:26:00 volumio go-librespot[7748]: time="2026-01-28T03:26:00+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]" Jan 28 03:26:00 volumio go-librespot[7748]: time="2026-01-28T03:26:00+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]" Jan 28 03:26:00 volumio go-librespot[7748]: time="2026-01-28T03:26:00+07:00" level=info msg="zeroconf server listening on port 36457" Jan 28 03:26:00 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 03:26:00 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 03:26:00 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 03:26:00 volumio go-librespot[7748]: time="2026-01-28T03:26:00+07:00" level=debug msg="obtained new client token: AAApaxNwQPLzDtw15c93n9lxOossUmW8yQMLkpvfqEpZhywAIQpy2SMoDpskKQOrFfEkM5qmxtXALVyaC8POt68O5jr/EWIFSk+QdrXaOBVxGoO7P4bYUcGIJv/XBI5XwDM0SKc/y24IYv6EvkYSjdNNd+mQTRDua1eH2MQFWw7/pRi0s8Lv3sq1sUJiNiNJcmIXatRqUBsBdcncCyRmQmd990ubUWMg2luX87SgKcyIvB0tTyPO5A6QRC4=" Jan 28 03:26:00 volumio go-librespot[7748]: time="2026-01-28T03:26:00+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 03:26:00 volumio volumio[7539]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 03:26:00 volumio volumio[7539]: info: [1769545560843] CoreMusicLibrary::Adding element YouTube Music Jan 28 03:26:00 volumio volumio[7539]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 03:26:00 volumio volumio[7539]: Cannot find translation for source YouTube Music Jan 28 03:26:00 volumio go-librespot[7748]: time="2026-01-28T03:26:00+07:00" level=debug msg="completed keyexchange" Jan 28 03:26:00 volumio go-librespot[7748]: time="2026-01-28T03:26:00+07:00" level=debug msg="completed challenge" Jan 28 03:26:00 volumio volumio[7539]: info: Volumio Calling Home Jan 28 03:26:00 volumio volumio[7665]: Starting albumart workers Jan 28 03:26:00 volumio go-librespot[7748]: time="2026-01-28T03:26:00+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 03:26:00 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 03:26:00 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 03:26:01 volumio sudo[7768]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Jan 28 03:26:01 volumio sudo[7768]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 03:26:01 volumio sudo[7768]: pam_unix(sudo:session): session closed for user root Jan 28 03:26:01 volumio volumio[7667]: Starting albumart workers Jan 28 03:26:01 volumio volumio[7539]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Jan 28 03:26:01 volumio volumio[7539]: info: Discovery: Found device Volumio Jan 28 03:26:01 volumio volumio[7539]: info: CoreCommandRouter::volumioGetState Jan 28 03:26:01 volumio volumio[7539]: info: CorePlayQueue::getTrack 0 Jan 28 03:26:01 volumio volumio[7539]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Jan 28 03:26:01 volumio volumio[7539]: info: Discovery: Found device Volumio Jan 28 03:26:01 volumio volumio[7539]: info: CoreCommandRouter::volumioGetState Jan 28 03:26:01 volumio volumio[7539]: info: CorePlayQueue::getTrack 0 Jan 28 03:26:01 volumio volumio[7539]: info: MPD Permissions set Jan 28 03:26:01 volumio volumio[7539]: info: MPD Permissions set Jan 28 03:26:01 volumio volumio[7539]: info: Upmpdcli Daemon Started Jan 28 03:26:01 volumio volumio[7539]: info: Spotify config file written Jan 28 03:26:01 volumio volumio[7666]: Starting albumart workers Jan 28 03:26:01 volumio volumio[7539]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Jan 28 03:26:01 volumio sudo[7774]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jan 28 03:26:01 volumio sudo[7774]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 03:26:01 volumio volumio[7539]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 03:26:01 volumio volumio[7539]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 03:26:01 volumio volumio[7539]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 03:26:01 volumio volumio[7539]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 03:26:01 volumio volumio[7539]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 03:26:01 volumio volumio[7539]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 03:26:01 volumio volumio[7539]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 03:26:01 volumio volumio[7539]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 03:26:01 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 03:26:01 volumio volumio[7539]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 03:26:01 volumio volumio[7539]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 03:26:01 volumio volumio[7539]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 03:26:02 volumio volumio[7539]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 03:26:02 volumio volumio[7539]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 03:26:02 volumio volumio[7539]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 03:26:02 volumio volumio[7539]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 03:26:02 volumio volumio[7539]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 03:26:02 volumio volumio[7539]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 03:26:02 volumio volumio[7539]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 03:26:02 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 03:26:02 volumio go-librespot[7781]: go-librespot daemon starting... Jan 28 03:26:02 volumio sudo[7774]: pam_unix(sudo:session): session closed for user root Jan 28 03:26:02 volumio go-librespot[7784]: time="2026-01-28T03:26:02+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 03:26:02 volumio go-librespot[7784]: time="2026-01-28T03:26:02+07:00" level=debug msg="app state loaded" Jan 28 03:26:02 volumio go-librespot[7784]: time="2026-01-28T03:26:02+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 03:26:02 volumio volumio[7539]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 03:26:02 volumio volumio[7539]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 03:26:02 volumio volumio[7539]: info: No need to fix Spotify hosts Jan 28 03:26:02 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 03:26:02 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 03:26:02 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 03:26:02 volumio go-librespot[7784]: time="2026-01-28T03:26:02+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 28 03:26:02 volumio go-librespot[7784]: time="2026-01-28T03:26:02+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]" Jan 28 03:26:02 volumio go-librespot[7784]: time="2026-01-28T03:26:02+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]" Jan 28 03:26:02 volumio go-librespot[7784]: time="2026-01-28T03:26:02+07:00" level=info msg="zeroconf server listening on port 41963" Jan 28 03:26:03 volumio go-librespot[7784]: time="2026-01-28T03:26:03+07:00" level=debug msg="obtained new client token: AACUTdL6YEFj/UTBaCt23BVJuCEeQ3aePceTVcIIL1Yr0Mbl7yctwGAIDIgnEf5lAe+R/22BB45xTMQhB3kuNEg8nxtaSQmfqd0hdMvblK5srN7LPrgVvxo+c5zU05R4whUFW8WIaU9RnahCr89st1dCnhVJqoANoG/Fme1gLM3KsedjjOFZToHQ8vRM/DtLMxiXqURct6R8h+UqDRf3bZMGTAjC4PZ1v/NKo8ydWFNTkOS+u8xS2bOX" Jan 28 03:26:03 volumio volumio[7539]: info: Volumio called home Jan 28 03:26:03 volumio go-librespot[7784]: time="2026-01-28T03:26:03+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" Jan 28 03:26:03 volumio go-librespot[7784]: time="2026-01-28T03:26:03+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Jan 28 03:26:03 volumio go-librespot[7784]: time="2026-01-28T03:26:03+07:00" level=debug msg="completed keyexchange" Jan 28 03:26:03 volumio go-librespot[7784]: time="2026-01-28T03:26:03+07:00" level=debug msg="completed challenge" Jan 28 03:26:03 volumio go-librespot[7784]: time="2026-01-28T03:26: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 " Jan 28 03:26:03 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 03:26:03 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 03:26:03 volumio volumio[7539]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 28 03:26:03 volumio volumio[7539]: SPOTIFY: BQCo2_NH9CnFhp8ayZtglhMWok8xAcZwN8Di7gUeRH15xdGGS-j0ffRMRKu-FGJMklpF0okR1_plptxkMSvVFpgiaWIO5rYD19-XaJeKUpslvF5ms3pC_3_fw6A9ILndzanICMz4UWQhRNoAIlwbTEIJ0Qc5-v5-WVVHm0JWngGutrZD5m5Ux_gZLLUEN8ea5buc6d_w7dXELEyKO0plAVp_9GN8hmO-iRTEL6SL5u4lwO9aAw_NjS6FLdgtD15_jTGIOu8GO8nWM8E-tlas99cb1mAjkdigZBIt0Df6clILPhbSv2s2UFIA Jan 28 03:26:03 volumio volumio[7539]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 28 03:26:03 volumio volumio[7539]: info: New Spotify access token = BQCo2_NH9CnFhp8ayZtglhMWok8xAcZwN8Di7gUeRH15xdGGS-j0ffRMRKu-FGJMklpF0okR1_plptxkMSvVFpgiaWIO5rYD19-XaJeKUpslvF5ms3pC_3_fw6A9ILndzanICMz4UWQhRNoAIlwbTEIJ0Qc5-v5-WVVHm0JWngGutrZD5m5Ux_gZLLUEN8ea5buc6d_w7dXELEyKO0plAVp_9GN8hmO-iRTEL6SL5u4lwO9aAw_NjS6FLdgtD15_jTGIOu8GO8nWM8E-tlas99cb1mAjkdigZBIt0Df6clILPhbSv2s2UFIA Jan 28 03:26:03 volumio volumio[7539]: info: Spotify credentials grant success - running version from March 24, 2019 Jan 28 03:26:03 volumio volumio[7539]: info: Starting Shairport Sync Jan 28 03:26:03 volumio volumio[7539]: info: Starting Shairport Sync Jan 28 03:26:03 volumio volumio[7539]: info: Starting Shairport Sync Jan 28 03:26:03 volumio sudo[7811]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 28 03:26:03 volumio sudo[7811]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 03:26:03 volumio sudo[7809]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 28 03:26:03 volumio sudo[7809]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 03:26:03 volumio sudo[7813]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 28 03:26:03 volumio sudo[7813]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 03:26:04 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 28 03:26:04 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Jan 28 03:26:04 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 28 03:26:04 volumio systemd[1]: shairport-sync.service: Consumed 2.403s CPU time. Jan 28 03:26:04 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 28 03:26:04 volumio sudo[7813]: pam_unix(sudo:session): session closed for user root Jan 28 03:26:04 volumio sudo[7809]: pam_unix(sudo:session): session closed for user root Jan 28 03:26:04 volumio sudo[7811]: pam_unix(sudo:session): session closed for user root Jan 28 03:26:04 volumio volumio[7539]: info: Shairport-Sync Started Jan 28 03:26:04 volumio volumio[7539]: Error adding Membership: Error: addMembership EINVAL Jan 28 03:26:04 volumio volumio[7539]: info: Shairport-Sync Started Jan 28 03:26:04 volumio volumio[7539]: info: Shairport-Sync Started Jan 28 03:26:04 volumio volumio[7539]: info: CoreCommandRouter::volumioGetState Jan 28 03:26:04 volumio volumio[7539]: info: CorePlayQueue::getTrack 0 Jan 28 03:26:04 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 03:26:04 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 03:26:04 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 03:26:04 volumio volumio[7539]: 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"} Jan 28 03:26:04 volumio volumio[7539]: info: Spotify Successfully logged in Jan 28 03:26:04 volumio volumio[7539]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 03:26:04 volumio volumio[7539]: info: [1769545564597] CoreMusicLibrary::Adding element Spotify Jan 28 03:26:04 volumio volumio[7539]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 03:26:04 volumio volumio[7539]: Cannot find translation for source YouTube Music Jan 28 03:26:04 volumio volumio[7539]: Cannot find translation for source Spotify Jan 28 03:26:05 volumio volumio[7539]: info: [yt-cast-receiver] DIAL server listening on port 8098 Jan 28 03:26:05 volumio volumio[7539]: info: CoreCommandRouter::volumioRetrievevolume Jan 28 03:26:05 volumio volumio[7539]: info: VolumeController:: Volume=100 Mute =false Jan 28 03:26:05 volumio volumio[7539]: info: CoreCommandRouter::volumioGetState Jan 28 03:26:05 volumio volumio[7539]: info: CorePlayQueue::getTrack 0 Jan 28 03:26:05 volumio volumio[7539]: info: CoreStateMachine::pushState Jan 28 03:26:05 volumio volumio[7539]: info: CorePlayQueue::getTrack 0 Jan 28 03:26:05 volumio volumio[7539]: info: CoreCommandRouter::volumioPushState Jan 28 03:26:06 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 03:26:06 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 03:26:06 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 03:26:06 volumio volumio[7539]: info: go-librespot daemon successfully initialized Jan 28 03:26:06 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 30. Jan 28 03:26:06 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 03:26:06 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 03:26:06 volumio go-librespot[7854]: go-librespot daemon starting... Jan 28 03:26:06 volumio go-librespot[7855]: time="2026-01-28T03:26:06+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 03:26:06 volumio go-librespot[7855]: time="2026-01-28T03:26:06+07:00" level=debug msg="app state loaded" Jan 28 03:26:06 volumio go-librespot[7855]: time="2026-01-28T03:26:06+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 03:26:07 volumio mpd[7766]: 2026-01-28T03:26:07 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 28 03:26:07 volumio systemd[1]: Started mpd.service - Music Player Daemon. Jan 28 03:26:07 volumio sudo[7731]: pam_unix(sudo:session): session closed for user root Jan 28 03:26:07 volumio sudo[7720]: pam_unix(sudo:session): session closed for user root Jan 28 03:26:07 volumio go-librespot[7855]: time="2026-01-28T03:26: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 03:26:07 volumio go-librespot[7855]: time="2026-01-28T03:26:07+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]" Jan 28 03:26:07 volumio go-librespot[7855]: time="2026-01-28T03:26:07+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]" Jan 28 03:26:07 volumio go-librespot[7855]: time="2026-01-28T03:26:07+07:00" level=info msg="zeroconf server listening on port 37645" Jan 28 03:26:07 volumio volumio[7539]: error: MPD error: The expression evaluated to a falsy value: Jan 28 03:26:07 volumio volumio[7539]: assert.ok(self.idling) Jan 28 03:26:07 volumio volumio[7539]: error: The expression evaluated to a falsy value: Jan 28 03:26:07 volumio volumio[7539]: assert.ok(self.idling) Jan 28 03:26:07 volumio volumio[7539]: error: updateQueue error: null Jan 28 03:26:07 volumio volumio[7539]: info: MPD running with PID7766 Jan 28 03:26:07 volumio volumio[7539]: ,establishing connection Jan 28 03:26:07 volumio volumio[7539]: info: Completed starting Core Plugins Jan 28 03:26:07 volumio volumio[7539]: info: ------------------------------------------- Jan 28 03:26:07 volumio volumio[7539]: info: ----- MyVolumio plugins startup ---- Jan 28 03:26:07 volumio volumio[7539]: info: ------------------------------------------- Jan 28 03:26:07 volumio volumio[7539]: info: [MyVolumio PluginManager] Fetching plans data.... Jan 28 03:26:07 volumio volumio[7539]: error: updateQueue error: null Jan 28 03:26:07 volumio go-librespot[7855]: time="2026-01-28T03:26:07+07:00" level=debug msg="obtained new client token: AADWLMMYEuij+pb51ncnGwnFwpPkNUk2W8geZBx4687kPaY9zR75cRx6ym+6qKYUOcq1nemDGMhNyOBHRtJ/Xcg0xWAwq7mJoVIhVnMxQCIrkO7NcDP1oZNsvCbun6Cv8Gt/7VeJZgvi33hOWgM9bgUKQ0qmN5Mn7bsXNsxOtzgfI+atSbCB5QQdcbv4RHAO9XAR1+kgN6T+aEnrl4q9u0nPpzLO63oAB61HvwB168vex6aSaUcv4uYFE5U=" Jan 28 03:26:07 volumio go-librespot[7855]: time="2026-01-28T03:26:07+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 03:26:07 volumio go-librespot[7855]: time="2026-01-28T03:26:07+07:00" level=debug msg="completed keyexchange" Jan 28 03:26:07 volumio go-librespot[7855]: time="2026-01-28T03:26:07+07:00" level=debug msg="completed challenge" Jan 28 03:26:07 volumio go-librespot[7855]: time="2026-01-28T03:26: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 " Jan 28 03:26:07 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 03:26:07 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 03:26:08 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 03:26:08 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 03:26:08 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 03:26:09 volumio volumio[7539]: info: Initializing connection to go-librespot Websocket Jan 28 03:26:09 volumio volumio[7539]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 28 03:26:10 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 03:26:10 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 03:26:10 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 03:26:10 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 31. Jan 28 03:26:10 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 03:26:11 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 03:26:11 volumio go-librespot[7867]: go-librespot daemon starting... Jan 28 03:26:11 volumio go-librespot[7868]: time="2026-01-28T03:26:11+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 03:26:11 volumio go-librespot[7868]: time="2026-01-28T03:26:11+07:00" level=debug msg="app state loaded" Jan 28 03:26:11 volumio go-librespot[7868]: time="2026-01-28T03:26:11+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 03:26:11 volumio go-librespot[7868]: time="2026-01-28T03:26: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-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 03:26:11 volumio go-librespot[7868]: time="2026-01-28T03:26:11+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]" Jan 28 03:26:11 volumio go-librespot[7868]: time="2026-01-28T03:26:11+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]" Jan 28 03:26:11 volumio go-librespot[7868]: time="2026-01-28T03:26:11+07:00" level=info msg="zeroconf server listening on port 38923" Jan 28 03:26:11 volumio go-librespot[7868]: time="2026-01-28T03:26:11+07:00" level=debug msg="obtained new client token: AABHfvR4uT+Do7G6+x8aotXzI9MHAjbzVXkF14DDUOFADk/1vseWdnAKImsIe2YWFomFBRDg/8pjJjCJq40DXsZpExg6e2v2RIBb+uN/NxlB0xajTNIQskefqAZaAhAALMYeW3KVIj8+4x1T9u0dbCC1ox1dR3jnyvitgqyIaUvH/WbxHHzP8Fxmdq/35Hv+jkjBHKHKBGzM4Xa/slmmoIs+FLQr0gOC09v1/ZYrO+dwbaHOBzA12Ci+MsI=" Jan 28 03:26:11 volumio go-librespot[7868]: time="2026-01-28T03:26:11+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" Jan 28 03:26:12 volumio go-librespot[7868]: time="2026-01-28T03:26:12+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Jan 28 03:26:12 volumio go-librespot[7868]: time="2026-01-28T03:26:12+07:00" level=debug msg="completed keyexchange" Jan 28 03:26:12 volumio go-librespot[7868]: time="2026-01-28T03:26:12+07:00" level=debug msg="completed challenge" Jan 28 03:26:12 volumio go-librespot[7868]: time="2026-01-28T03:26: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 " Jan 28 03:26:12 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 03:26:12 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 03:26:12 volumio volumio[7539]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Jan 28 03:26:12 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 03:26:12 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 03:26:12 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 03:26:12 volumio volumio[7539]: info: Initializing connection to go-librespot Websocket Jan 28 03:26:12 volumio volumio[7539]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 28 03:26:14 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 03:26:14 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 03:26:14 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 03:26:15 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 32. Jan 28 03:26:15 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 03:26:15 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 03:26:15 volumio go-librespot[7875]: go-librespot daemon starting... Jan 28 03:26:15 volumio go-librespot[7876]: time="2026-01-28T03:26:15+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 03:26:15 volumio go-librespot[7876]: time="2026-01-28T03:26:15+07:00" level=debug msg="app state loaded" Jan 28 03:26:15 volumio go-librespot[7876]: time="2026-01-28T03:26:15+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 03:26:15 volumio volumio[7539]: info: Initializing connection to go-librespot Websocket Jan 28 03:26:15 volumio go-librespot[7876]: time="2026-01-28T03:26:15+07:00" level=debug msg="new websocket client" Jan 28 03:26:15 volumio volumio[7539]: info: Connection to go-librespot Websocket established Jan 28 03:26:15 volumio go-librespot[7876]: time="2026-01-28T03:26: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]" Jan 28 03:26:15 volumio go-librespot[7876]: time="2026-01-28T03:26: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]" Jan 28 03:26:15 volumio go-librespot[7876]: time="2026-01-28T03:26: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]" Jan 28 03:26:15 volumio go-librespot[7876]: time="2026-01-28T03:26:15+07:00" level=info msg="zeroconf server listening on port 32979" Jan 28 03:26:16 volumio go-librespot[7876]: time="2026-01-28T03:26:16+07:00" level=debug msg="obtained new client token: AAAeLrxslvWrTIVY6HyMFhLLvcz+XgKzV9uwbLeU98iRsunX3+15BW0wlE1CgUyOy+R88Vf2enrJ4RgMmuI3KLz0dDXF4+kZUxt0gzCD8GfKMU+iq+agQIJkhe6HUkXq2HnckilJFzi0yCBg5onKctpb/t7eyPGis3cnKIH6VPyAun7g0VicGtIBkj+1iw5auR0XQbpG6RsHZaL9uO2PcVizntiaWmmc5T02MXjKnMSqX9b7utwwm8Qm" Jan 28 03:26:16 volumio go-librespot[7876]: time="2026-01-28T03:26:16+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 03:26:16 volumio go-librespot[7876]: time="2026-01-28T03:26:16+07:00" level=debug msg="completed keyexchange" Jan 28 03:26:16 volumio go-librespot[7876]: time="2026-01-28T03:26:16+07:00" level=debug msg="completed challenge" Jan 28 03:26:16 volumio volumio[7539]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Jan 28 03:26:16 volumio volumio[7539]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Jan 28 03:26:16 volumio volumio[7539]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Jan 28 03:26:16 volumio volumio[7539]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Jan 28 03:26:16 volumio volumio[7539]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Jan 28 03:26:16 volumio volumio[7539]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Jan 28 03:26:16 volumio volumio[7539]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Jan 28 03:26:16 volumio volumio[7539]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Jan 28 03:26:16 volumio volumio[7539]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Jan 28 03:26:16 volumio volumio[7539]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Jan 28 03:26:16 volumio volumio[7539]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Jan 28 03:26:16 volumio volumio[7539]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Jan 28 03:26:16 volumio volumio[7539]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Jan 28 03:26:16 volumio volumio[7539]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Jan 28 03:26:16 volumio volumio[7539]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Jan 28 03:26:16 volumio volumio[7539]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Jan 28 03:26:16 volumio volumio[7539]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Jan 28 03:26:16 volumio volumio[7539]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Jan 28 03:26:16 volumio volumio[7539]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Jan 28 03:26:16 volumio volumio[7539]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Jan 28 03:26:16 volumio volumio[7539]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Jan 28 03:26:16 volumio volumio[7539]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Jan 28 03:26:16 volumio volumio[7539]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Jan 28 03:26:16 volumio volumio[7539]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Jan 28 03:26:16 volumio volumio[7539]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Jan 28 03:26:16 volumio volumio[7539]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Jan 28 03:26:16 volumio volumio[7539]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Jan 28 03:26:16 volumio volumio[7539]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Jan 28 03:26:16 volumio go-librespot[7876]: time="2026-01-28T03:26: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 " Jan 28 03:26:16 volumio volumio[7539]: info: Adding plugin bluetooth to MyMusic Plugins Jan 28 03:26:16 volumio volumio[7539]: info: Adding plugin multiroom to MyMusic Plugins Jan 28 03:26:16 volumio volumio[7539]: info: Adding plugin metavolumio to MyMusic Plugins Jan 28 03:26:16 volumio volumio[7539]: info: Adding plugin cd_controller to MyMusic Plugins Jan 28 03:26:16 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 03:26:16 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 03:26:16 volumio volumio[7539]: info: Adding plugin qobuzconnect to MyMusic Plugins Jan 28 03:26:16 volumio volumio[7539]: info: Adding plugin smart_inputs to MyMusic Plugins Jan 28 03:26:16 volumio volumio[7539]: info: Adding plugin tidalconnect to MyMusic Plugins Jan 28 03:26:16 volumio volumio[7539]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Jan 28 03:26:16 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 03:26:16 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 03:26:16 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 03:26:18 volumio volumio[7539]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Jan 28 03:26:18 volumio volumio[7539]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Jan 28 03:26:18 volumio volumio[7539]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 03:26:18 volumio volumio[7539]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 03:26:18 volumio volumio[7539]: info: Starting MyVolumio Remote Streaming Endpoints Jan 28 03:26:18 volumio volumio[7539]: info: MyVolumio login type: Token Jan 28 03:26:18 volumio volumio[7539]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Jan 28 03:26:18 volumio volumio[7539]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Jan 28 03:26:18 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 03:26:18 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 03:26:18 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 03:26:19 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 33. Jan 28 03:26:19 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 03:26:19 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 03:26:19 volumio go-librespot[7897]: go-librespot daemon starting... Jan 28 03:26:19 volumio go-librespot[7898]: time="2026-01-28T03:26:19+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 03:26:19 volumio go-librespot[7898]: time="2026-01-28T03:26:19+07:00" level=debug msg="app state loaded" Jan 28 03:26:19 volumio go-librespot[7898]: time="2026-01-28T03:26:19+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 03:26:20 volumio volumio[7539]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Jan 28 03:26:20 volumio volumio[7539]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Jan 28 03:26:20 volumio volumio[7539]: info: Streaming services startup Jan 28 03:26:20 volumio volumio[7539]: info: Starting Streaming Daemon Jan 28 03:26:20 volumio go-librespot[7898]: time="2026-01-28T03:26: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-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 28 03:26:20 volumio go-librespot[7898]: time="2026-01-28T03:26:20+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]" Jan 28 03:26:20 volumio go-librespot[7898]: time="2026-01-28T03:26:20+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]" Jan 28 03:26:20 volumio go-librespot[7898]: time="2026-01-28T03:26:20+07:00" level=info msg="zeroconf server listening on port 38095" Jan 28 03:26:20 volumio sudo[7908]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jan 28 03:26:20 volumio sudo[7908]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 03:26:20 volumio volumio[7539]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Jan 28 03:26:20 volumio sudo[7908]: pam_unix(sudo:session): session closed for user root Jan 28 03:26:20 volumio volumio[7539]: info: Getting Spotify volume Jan 28 03:26:20 volumio volumio[7539]: info: Connection to go-librespot Websocket closed Jan 28 03:26:20 volumio volumio[7539]: error: Cannot start Volumio Streaming Daemon Jan 28 03:26:20 volumio volumio[7539]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Jan 28 03:26:20 volumio volumio[7539]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Jan 28 03:26:20 volumio volumio[7539]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Jan 28 03:26:20 volumio go-librespot[7898]: time="2026-01-28T03:26:20+07:00" level=debug msg="obtained new client token: AAC5EqcLdN29BvZcdSe87qbNSWA/5kOAFE1u/mAwE0j8gSvarPwOv4qmo9MC6YJm95RbvmMIUob3FJn9qfOOybe0eY/Qs1wvt9vEnDJ6SUB0FCeqmKGnwEkxmYKTsYEaLb+wdN9yM+GICdc8pZNwwD+q2qVxf6JYUJcNmvc1hB6D6WTP/LxeuWNPgGtO/3HTnJN8WyO7N9UMZHp7YbkcdzYfklR6B9nTN5Cw3KESqqBZD3uA1DsxpzwruZ4=" Jan 28 03:26:20 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 03:26:20 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 03:26:20 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 03:26:20 volumio go-librespot[7898]: time="2026-01-28T03:26:20+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 03:26:20 volumio volumio[7539]: info: CoreCommandRouter::volumioGetState Jan 28 03:26:20 volumio volumio[7539]: info: CorePlayQueue::getTrack 0 Jan 28 03:26:20 volumio volumio[7539]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jan 28 03:26:20 volumio volumio[7539]: SPOTIFY: SPOTIFY VOLUME undefined Jan 28 03:26:20 volumio volumio[7539]: SPOTIFY: VOLUMIO VOLUME 100 Jan 28 03:26:20 volumio volumio[7539]: info: Aligning Spotify Volume to Volumio Volume Jan 28 03:26:20 volumio volumio[7539]: info: CoreCommandRouter::volumioGetState Jan 28 03:26:20 volumio volumio[7539]: info: CorePlayQueue::getTrack 0 Jan 28 03:26:20 volumio volumio[7539]: info: Setting Spotify Volume from Volumio: 100 Jan 28 03:26:20 volumio go-librespot[7898]: time="2026-01-28T03:26:20+07:00" level=debug msg="completed keyexchange" Jan 28 03:26:20 volumio go-librespot[7898]: time="2026-01-28T03:26:20+07:00" level=debug msg="completed challenge" Jan 28 03:26:20 volumio go-librespot[7898]: time="2026-01-28T03:26: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 " Jan 28 03:26:20 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 03:26:20 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 03:26:20 volumio volumio[7539]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 28 03:26:20 volumio volumio[7539]: Error: socket hang up Jan 28 03:26:20 volumio volumio[7539]: at connResetException (node:internal/errors:720:14) Jan 28 03:26:20 volumio volumio[7539]: at Socket.socketOnEnd (node:_http_client:519:23) Jan 28 03:26:20 volumio volumio[7539]: at Socket.emit (node:events:526:35) Jan 28 03:26:20 volumio volumio[7539]: at endReadableNT (node:internal/streams/readable:1376:12) Jan 28 03:26:20 volumio volumio[7539]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Jan 28 03:26:20 volumio volumio[7539]: code: 'ECONNRESET', Jan 28 03:26:20 volumio volumio[7539]: response: undefined Jan 28 03:26:20 volumio volumio[7539]: } Jan 28 03:26:20 volumio volumio[7539]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 28 03:26:22 volumio sudo[7928]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-01-28 03:25' Jan 28 03:26:22 volumio sudo[7928]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 03:26:22 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 03:26:22 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 03:26:22 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 03:26:22 volumio sudo[7928]: pam_unix(sudo:session): session closed for user root Jan 28 03:26:23 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 34. Jan 28 03:26:23 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 03:26:24 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 03:26:24 volumio go-librespot[7936]: go-librespot daemon starting... Jan 28 03:26:24 volumio volumio-remote-updater[628]: [2026-01-28 03:26:24] [error] handle_read_frame error: asio.system:104 (Connection reset by peer) Jan 28 03:26:24 volumio volumio-remote-updater[628]: [2026-01-28 03:26:24] [disconnect] Disconnect close local:[1006,Connection reset by peer] remote:[1006] Jan 28 03:26:24 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Jan 28 03:26:24 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Jan 28 03:26:24 volumio systemd[1]: volumio.service: Consumed 55.827s CPU time. Jan 28 03:26:24 volumio go-librespot[7938]: time="2026-01-28T03:26:24+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 03:26:24 volumio go-librespot[7938]: time="2026-01-28T03:26:24+07:00" level=debug msg="app state loaded" Jan 28 03:26:24 volumio go-librespot[7938]: time="2026-01-28T03:26:24+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 03:26:24 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 28 03:26:24 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Jan 28 03:26:24 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 9545. Jan 28 03:26:24 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 28 03:26:24 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Jan 28 03:26:24 volumio systemd[1]: volumio.service: Consumed 55.827s CPU time. Jan 28 03:26:24 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Jan 28 03:26:24 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Jan 28 03:26:24 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 03:26:24 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 03:26:24 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 03:26:24 volumio go-librespot[7938]: time="2026-01-28T03:26: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-gew1.spotify.com:80]" Jan 28 03:26:24 volumio go-librespot[7938]: time="2026-01-28T03:26:24+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]" Jan 28 03:26:24 volumio go-librespot[7938]: time="2026-01-28T03:26:24+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]" Jan 28 03:26:24 volumio go-librespot[7938]: time="2026-01-28T03:26:24+07:00" level=info msg="zeroconf server listening on port 39695" Jan 28 03:26:24 volumio go-librespot[7938]: time="2026-01-28T03:26:24+07:00" level=debug msg="obtained new client token: AAAy+6PDP73G9qHSK80A9su9FTxtN+gi5KuBPH9BLACiMJTyu3sUl+nbHs/3sUSiNZ4TJxzWDQkQ2JPA0ZsXjJ+nPMgGLKf5azDxmJ4L/gjOt3i/Xin+Wnqzv6lCW8qpY34sAFgDjg9dwfV6W0Ct9HNM1PEZa05A39bkUjPw7t9RrYMDLS/YC60lXYd1YOjhMgZmbhxBRJ+Ip6o7+2fk18uvNkWK5DFQQ1lERVt9r47SrQoil3dxDA/b/Us=" Jan 28 03:26:24 volumio go-librespot[7938]: time="2026-01-28T03:26:24+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 03:26:25 volumio go-librespot[7938]: time="2026-01-28T03:26:25+07:00" level=debug msg="completed keyexchange" Jan 28 03:26:25 volumio go-librespot[7938]: time="2026-01-28T03:26:25+07:00" level=debug msg="completed challenge" Jan 28 03:26:25 volumio go-librespot[7938]: time="2026-01-28T03:26: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 " Jan 28 03:26:25 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 03:26:25 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 03:26:26 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 03:26:26 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 03:26:26 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 03:26:27 volumio volumio[7957]: info: ------------------------------------------- Jan 28 03:26:27 volumio volumio[7957]: info: ----- Volumio3 ---- Jan 28 03:26:27 volumio volumio[7957]: info: ------------------------------------------- Jan 28 03:26:27 volumio volumio[7957]: info: ----- System startup ---- Jan 28 03:26:27 volumio volumio[7957]: info: ------------------------------------------- Jan 28 03:26:28 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 35. Jan 28 03:26:28 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 03:26:28 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 03:26:28 volumio go-librespot[7979]: go-librespot daemon starting... Jan 28 03:26:28 volumio go-librespot[7980]: time="2026-01-28T03:26:28+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 03:26:28 volumio go-librespot[7980]: time="2026-01-28T03:26:28+07:00" level=debug msg="app state loaded" Jan 28 03:26:28 volumio go-librespot[7980]: time="2026-01-28T03:26:28+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 03:26:28 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 03:26:28 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 03:26:28 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 03:26:28 volumio go-librespot[7980]: time="2026-01-28T03:26: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]" Jan 28 03:26:28 volumio go-librespot[7980]: time="2026-01-28T03:26: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]" Jan 28 03:26:28 volumio go-librespot[7980]: time="2026-01-28T03:26: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]" Jan 28 03:26:29 volumio go-librespot[7980]: time="2026-01-28T03:26:29+07:00" level=info msg="zeroconf server listening on port 37717" Jan 28 03:26:29 volumio volumio-remote-updater[628]: [2026-01-28 03:26:29] [connect] Successful connection Jan 28 03:26:29 volumio go-librespot[7980]: time="2026-01-28T03:26:29+07:00" level=debug msg="obtained new client token: AAA2pTNIUSw31uc70JP4+YSIDaUNjtlTyIiRVDNaWSVT5hYVJzoLm5OTVX6PNuxzkuQX2NP78Bk8bObolpJXgmIoeKudNS9G28I6g3HJQ+FzC42K23vrblq5JgXyuxu4jZvw9VFjtBV+95pnsgUPYGCb+EAHnjtAnt4PFDQq4hiy5yJDuRFFmCcHToJkgbr+UGSIBhAsWDv8srT8THK2i0t45WhT8xpQVtdBD65Ph1nIxXFUxw5M+YT0" Jan 28 03:26:29 volumio go-librespot[7980]: time="2026-01-28T03:26:29+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 03:26:29 volumio volumio[7957]: info: MYVOLUMIO Environment detected Jan 28 03:26:29 volumio go-librespot[7980]: time="2026-01-28T03:26:29+07:00" level=debug msg="completed keyexchange" Jan 28 03:26:29 volumio go-librespot[7980]: time="2026-01-28T03:26:29+07:00" level=debug msg="completed challenge" Jan 28 03:26:29 volumio volumio[7957]: info: Plugin folders cleanup Jan 28 03:26:29 volumio volumio[7957]: info: Scanning into folder /volumio/app/plugins/ Jan 28 03:26:29 volumio volumio[7957]: info: Scanning category audio_interface Jan 28 03:26:29 volumio volumio[7957]: info: Scanning category miscellanea Jan 28 03:26:29 volumio volumio[7957]: info: Scanning category music_service Jan 28 03:26:29 volumio go-librespot[7980]: time="2026-01-28T03:26: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 " Jan 28 03:26:29 volumio volumio[7957]: info: Scanning category plugins.json Jan 28 03:26:29 volumio volumio[7957]: info: Scanning category system_controller Jan 28 03:26:29 volumio volumio[7957]: info: Scanning category user_interface Jan 28 03:26:29 volumio volumio[7957]: info: Scanning into folder /data/plugins/ Jan 28 03:26:29 volumio volumio[7957]: info: Scanning category music_service Jan 28 03:26:29 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 03:26:29 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 03:26:29 volumio volumio[7957]: info: Plugin folders cleanup completed Jan 28 03:26:29 volumio volumio[7957]: info: ------------------------------------------- Jan 28 03:26:29 volumio volumio[7957]: info: ----- Core plugins startup ---- Jan 28 03:26:29 volumio volumio[7957]: info: ------------------------------------------- Jan 28 03:26:29 volumio volumio[7957]: info: Loading plugins from folder /volumio/app/plugins/ Jan 28 03:26:29 volumio volumio[7957]: info: Adding plugin upnp to MyMusic Plugins Jan 28 03:26:29 volumio volumio[7957]: info: Adding plugin airplay_emulation to MyMusic Plugins Jan 28 03:26:29 volumio volumio[7957]: info: Adding plugin upnp_browser to MyMusic Plugins Jan 28 03:26:29 volumio volumio[7957]: info: Loading plugins from folder /data/plugins/ Jan 28 03:26:29 volumio volumio[7957]: info: Loading plugin "system"... Jan 28 03:26:29 volumio volumio[7957]: info: Loading plugin "appearance"... Jan 28 03:26:30 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 03:26:30 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 03:26:30 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 03:26:31 volumio volumio[7957]: info: Loading plugin "network"... Jan 28 03:26:31 volumio volumio[7957]: info: Refreshing Cached IP Addresses Jan 28 03:26:31 volumio sudo[7994]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 28 03:26:31 volumio sudo[7994]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 03:26:31 volumio sudo[7996]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 28 03:26:31 volumio sudo[7996]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 03:26:31 volumio sudo[7994]: pam_unix(sudo:session): session closed for user root Jan 28 03:26:31 volumio volumio[7957]: info: Loading plugin "services"... Jan 28 03:26:31 volumio volumio[7957]: info: Loading plugin "alsa_controller"... Jan 28 03:26:31 volumio sudo[7996]: pam_unix(sudo:session): session closed for user root Jan 28 03:26:31 volumio sudo[8003]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Jan 28 03:26:31 volumio sudo[8003]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 03:26:31 volumio volumio[7957]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 28 03:26:31 volumio volumio[7957]: info: Loading plugin "wizard"... Jan 28 03:26:31 volumio volumio[7957]: info: Loading plugin "networkfs"... Jan 28 03:26:31 volumio volumio[7957]: info: Starting Udev Watcher for removable devices Jan 28 03:26:31 volumio volumio[7957]: info: Ignoring mount for partition: boot Jan 28 03:26:31 volumio volumio[7957]: info: Ignoring mount for partition: volumio Jan 28 03:26:31 volumio volumio[7957]: info: Ignoring mount for partition: volumio_data Jan 28 03:26:31 volumio volumio[7957]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 28 03:26:31 volumio volumio[7957]: info: Loading plugin "volumio_command_line_client"... Jan 28 03:26:31 volumio volumio[7957]: info: Loading plugin "upnp"... Jan 28 03:26:31 volumio volumio[7957]: info: [1769545591922] Starting Upmpd Daemon Jan 28 03:26:31 volumio volumio[7957]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 28 03:26:31 volumio volumio[7957]: info: Loading plugin "my_music"... Jan 28 03:26:31 volumio volumio[7957]: info: Loading plugin "mpd"... Jan 28 03:26:32 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 03:26:32 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 03:26:32 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 03:26:32 volumio volumio[7957]: info: Loading plugin "upnp_browser"... Jan 28 03:26:32 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 36. Jan 28 03:26:32 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 03:26:32 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 03:26:32 volumio go-librespot[8027]: go-librespot daemon starting... Jan 28 03:26:32 volumio go-librespot[8028]: time="2026-01-28T03:26:32+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 03:26:32 volumio go-librespot[8028]: time="2026-01-28T03:26:32+07:00" level=debug msg="app state loaded" Jan 28 03:26:32 volumio go-librespot[8028]: time="2026-01-28T03:26:32+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 03:26:33 volumio go-librespot[8028]: time="2026-01-28T03:26:33+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 03:26:33 volumio go-librespot[8028]: time="2026-01-28T03:26:33+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]" Jan 28 03:26:33 volumio go-librespot[8028]: time="2026-01-28T03:26:33+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]" Jan 28 03:26:33 volumio go-librespot[8028]: time="2026-01-28T03:26:33+07:00" level=info msg="zeroconf server listening on port 34327" Jan 28 03:26:33 volumio go-librespot[8028]: time="2026-01-28T03:26:33+07:00" level=debug msg="obtained new client token: AABAPDd2wvjbuMKHhZZEZeboKhlvhEJpxzgohtlw6ZvN/wYEpx0N+k7UDGg3KdD4agz15fomQqvu1ZMOyi6pTb5fhQPsRkLjVez82hQ4U5qNikIOa1SR7OKvRr/LKi2QPU4Q6AwIB3hocYAHxbqYSXZrEIxcxnaXEeXfIi60rLfkNhy6lm1CwmDXoQ0hm8LOARP5OSW870Gb1LBzQRoYQLXRiNyJkDST6IbpTmB7dnbVbsJK6oda8vLULXk=" Jan 28 03:26:33 volumio go-librespot[8028]: time="2026-01-28T03:26: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" Jan 28 03:26:33 volumio go-librespot[8028]: time="2026-01-28T03:26:33+07:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:443, retrying with a different AP" error="dial tcp 104.199.241.202:443: connect: connection refused" Jan 28 03:26:33 volumio go-librespot[8028]: time="2026-01-28T03:26:33+07:00" level=debug msg="connected to ap-gae2.spotify.com:80" Jan 28 03:26:34 volumio go-librespot[8028]: time="2026-01-28T03:26:34+07:00" level=debug msg="completed keyexchange" Jan 28 03:26:34 volumio go-librespot[8028]: time="2026-01-28T03:26:34+07:00" level=debug msg="completed challenge" Jan 28 03:26:34 volumio go-librespot[8028]: time="2026-01-28T03:26: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 " Jan 28 03:26:34 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 03:26:34 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 03:26:34 volumio sudo[8003]: pam_unix(sudo:session): session closed for user root Jan 28 03:26:34 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 03:26:34 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 03:26:34 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 03:26:35 volumio volumio[7957]: info: Starting UPNP Browser Jan 28 03:26:35 volumio volumio[7957]: info: Loading plugin "alarm-clock"... Jan 28 03:26:35 volumio volumio[7957]: info: Loading plugin "airplay_emulation"... Jan 28 03:26:35 volumio volumio[7957]: info: Starting Shairport Sync Jan 28 03:26:35 volumio volumio[7957]: info: Loading plugin "last_100"... Jan 28 03:26:35 volumio volumio[7957]: info: Loading plugin "webradio"... Jan 28 03:26:36 volumio volumio[7957]: info: Loading plugin "i2s_dacs"... Jan 28 03:26:36 volumio volumio[7957]: info: Loading plugin "volumiodiscovery"... Jan 28 03:26:36 volumio volumio[7957]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 28 03:26:36 volumio volumio[7957]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 03:26:36 volumio node[7957]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 28 03:26:36 volumio volumio[7957]: *** WARNING *** For more information see Jan 28 03:26:36 volumio volumio[7957]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 28 03:26:36 volumio volumio[7957]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 03:26:36 volumio volumio[7957]: *** WARNING *** For more information see Jan 28 03:26:36 volumio node[7957]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 03:26:36 volumio node[7957]: *** WARNING *** For more information see Jan 28 03:26:36 volumio node[7957]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 28 03:26:36 volumio node[7957]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 03:26:36 volumio node[7957]: *** WARNING *** For more information see Jan 28 03:26:36 volumio volumio[7957]: info: Applying required configuration parameters for plugin volumiodiscovery Jan 28 03:26:36 volumio volumio[7957]: info: Discovery: Started advertising with name: Volumio Jan 28 03:26:36 volumio volumio[7957]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 28 03:26:36 volumio volumio[7957]: info: Loading plugin "spop"... Jan 28 03:26:36 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 03:26:36 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 03:26:36 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 03:26:37 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 37. Jan 28 03:26:37 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 03:26:37 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 03:26:37 volumio go-librespot[8037]: go-librespot daemon starting... Jan 28 03:26:37 volumio go-librespot[8038]: time="2026-01-28T03:26:37+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 03:26:37 volumio go-librespot[8038]: time="2026-01-28T03:26:37+07:00" level=debug msg="app state loaded" Jan 28 03:26:37 volumio go-librespot[8038]: time="2026-01-28T03:26:37+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 03:26:37 volumio go-librespot[8038]: time="2026-01-28T03:26: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-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 28 03:26:37 volumio go-librespot[8038]: time="2026-01-28T03:26:37+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]" Jan 28 03:26:37 volumio go-librespot[8038]: time="2026-01-28T03:26:37+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]" Jan 28 03:26:37 volumio go-librespot[8038]: time="2026-01-28T03:26:37+07:00" level=info msg="zeroconf server listening on port 43891" Jan 28 03:26:38 volumio volumio[7957]: info: Loading plugin "ytcr"... Jan 28 03:26:38 volumio go-librespot[8038]: time="2026-01-28T03:26:38+07:00" level=debug msg="obtained new client token: AADhbyO6UoOr3IgRraFp67aT3TjYSVR0vnempssyitueZJh3CajmvvwVjnEHQO/lXEwkxJDntum+sPZGB8k25Xe4h5WWz/uOvfH5OsGWExSn2gXDmMi5FegoQc0C5JZlxkd5qtSicrFCm3w8Mavi32g2zVDWr9NXCMKAMTThG3JqWl5CQTPYBadmd/zTUBVGBDFAb5ThxPj4XOvdENJiN6tAAfqSVk1F0SoSIGkCEpbvQKrX2rF49ja2" Jan 28 03:26:38 volumio go-librespot[8038]: time="2026-01-28T03:26:38+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 03:26:38 volumio go-librespot[8038]: time="2026-01-28T03:26:38+07:00" level=debug msg="completed keyexchange" Jan 28 03:26:38 volumio go-librespot[8038]: time="2026-01-28T03:26:38+07:00" level=debug msg="completed challenge" Jan 28 03:26:38 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 03:26:38 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 03:26:38 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 03:26:38 volumio go-librespot[8038]: time="2026-01-28T03:26: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 " Jan 28 03:26:38 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 03:26:38 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 03:26:40 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 03:26:40 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 03:26:40 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 03:26:40 volumio volumio[7957]: info: Loading plugin "ytmusic"... Jan 28 03:26:41 volumio volumio-remote-updater[628]: [2026-01-28 03:26:41] [connect] Successful connection Jan 28 03:26:41 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 38. Jan 28 03:26:41 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 03:26:41 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 03:26:41 volumio go-librespot[8060]: go-librespot daemon starting... Jan 28 03:26:41 volumio volumio[7957]: info: Loading plugin "outputs"... Jan 28 03:26:41 volumio go-librespot[8062]: time="2026-01-28T03:26:41+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 03:26:41 volumio go-librespot[8062]: time="2026-01-28T03:26:41+07:00" level=debug msg="app state loaded" Jan 28 03:26:41 volumio go-librespot[8062]: time="2026-01-28T03:26:41+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 03:26:41 volumio volumio[7957]: info: Loading plugin "albumart"... Jan 28 03:26:41 volumio volumio[7957]: info: Plugin example_plugin is not enabled Jan 28 03:26:41 volumio volumio[7957]: info: Loading plugin "inputs"... Jan 28 03:26:41 volumio volumio[7957]: info: Loading plugin "updater_comm"... Jan 28 03:26:42 volumio volumio[7957]: info: Plugin mpdemulation is not enabled Jan 28 03:26:42 volumio volumio[7957]: info: Loading plugin "rest_api"... Jan 28 03:26:42 volumio volumio[7957]: info: Loading plugin "websocket"... Jan 28 03:26:42 volumio go-librespot[8062]: time="2026-01-28T03:26:42+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]" Jan 28 03:26:42 volumio go-librespot[8062]: time="2026-01-28T03:26:42+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]" Jan 28 03:26:42 volumio go-librespot[8062]: time="2026-01-28T03:26:42+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]" Jan 28 03:26:42 volumio go-librespot[8062]: time="2026-01-28T03:26:42+07:00" level=info msg="zeroconf server listening on port 33959" Jan 28 03:26:42 volumio volumio[7957]: info: Starting Socket.io Server version 1.7.4 Jan 28 03:26:42 volumio volumio[7957]: info: Loading plugin "RoonBridge"... Jan 28 03:26:42 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 03:26:42 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 03:26:42 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 03:26:42 volumio go-librespot[8062]: time="2026-01-28T03:26:42+07:00" level=debug msg="obtained new client token: AAB5pzLSvc/rdtoVLPYHt7xQvycD4FFh0mvU3o7dA7GwP7A5zg3HM9259sPdbY0+LR4BaoxcNxSriqbIc+/QB0qdD06Kqq22oEwt1RG0a9A3fl/sWdLA5k2G/WqUIduCGpaBfgHtkK+1lGrXogYBuCnm4kQp7fwYoR5uc1rZv+EWvLZnHvYiBJJzUrPaoADqXRRWi+XFpO3kYs7jN/Fq0WCLAf4P+mb8Y6gBeCqXBpwlNS4SEkQnsla6JS4=" Jan 28 03:26:42 volumio go-librespot[8062]: time="2026-01-28T03:26:42+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 03:26:42 volumio volumio[7957]: info: Applying required configuration parameters for plugin RoonBridge Jan 28 03:26:42 volumio volumio[7957]: info: Loading i18n strings for locale en Jan 28 03:26:42 volumio volumio[7957]: Updating browse sources language Jan 28 03:26:42 volumio volumio[7957]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 03:26:42 volumio go-librespot[8062]: time="2026-01-28T03:26:42+07:00" level=debug msg="completed keyexchange" Jan 28 03:26:42 volumio go-librespot[8062]: time="2026-01-28T03:26:42+07:00" level=debug msg="completed challenge" Jan 28 03:26:43 volumio go-librespot[8062]: time="2026-01-28T03:26:43+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 " Jan 28 03:26:43 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 03:26:43 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 03:26:43 volumio volumio[8069]: Forking 3 albumart workers Jan 28 03:26:43 volumio volumio[7957]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 28 03:26:43 volumio volumio[7957]: info: CoreCommandRouter::initPlayerControls Jan 28 03:26:43 volumio volumio[7957]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 03:26:43 volumio volumio[7957]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 03:26:43 volumio volumio[7957]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 03:26:43 volumio volumio[7957]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 03:26:43 volumio volumio[7957]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 03:26:43 volumio volumio[7957]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 03:26:43 volumio volumio[7957]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 03:26:43 volumio volumio[7957]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 03:26:43 volumio volumio[7957]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 28 03:26:43 volumio volumio[7957]: Express server listening on port 3000 Jan 28 03:26:43 volumio volumio[7957]: [Metrics] WebUI: 16s 247.39ms Jan 28 03:26:43 volumio volumio[7957]: info: CoreStateMachine::resetVolumioState Jan 28 03:26:43 volumio volumio[7957]: info: CoreStateMachine::getcurrentVolume Jan 28 03:26:43 volumio volumio[7957]: info: CoreCommandRouter::volumioRetrievevolume Jan 28 03:26:43 volumio sudo[8112]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 28 03:26:43 volumio sudo[8112]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 03:26:43 volumio sudo[8115]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 28 03:26:43 volumio sudo[8115]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 03:26:43 volumio sudo[8112]: pam_unix(sudo:session): session closed for user root Jan 28 03:26:43 volumio sudo[8115]: pam_unix(sudo:session): session closed for user root Jan 28 03:26:43 volumio volumio[7957]: info: Volumio Network Manager: Network status updated: 1 Jan 28 03:26:43 volumio volumio[7957]: info: VolumeController:: Volume=100 Mute =false Jan 28 03:26:43 volumio volumio[7957]: info: CoreStateMachine::pushState Jan 28 03:26:43 volumio volumio[7957]: info: CorePlayQueue::getTrack 0 Jan 28 03:26:43 volumio volumio[7957]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 28 03:26:43 volumio volumio[7957]: info: CoreCommandRouter::volumioPushState Jan 28 03:26:43 volumio volumio[7957]: info: CoreStateMachine::updateTrackBlock Jan 28 03:26:43 volumio volumio[7957]: info: CorePlayQueue::getTrackBlock Jan 28 03:26:43 volumio volumio[7957]: info: CoreCommandRouter::volumioRetrievevolume Jan 28 03:26:43 volumio volumio-remote-updater[628]: [2026-01-28 03:26:43] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1769545601 101 Jan 28 03:26:43 volumio volumio[7957]: 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 Jan 28 03:26:44 volumio volumio[7957]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 03:26:44 volumio volumio[7957]: info: Reloading queue from file Jan 28 03:26:44 volumio volumio[7957]: info: CoreStateMachine::setRepeat null single undefined Jan 28 03:26:44 volumio volumio[7957]: info: CoreStateMachine::pushState Jan 28 03:26:44 volumio volumio[7957]: info: CorePlayQueue::getTrack 0 Jan 28 03:26:44 volumio volumio[7957]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 28 03:26:44 volumio volumio[7957]: info: CoreCommandRouter::volumioPushState Jan 28 03:26:44 volumio volumio[7957]: info: CoreStateMachine::setRandom null Jan 28 03:26:44 volumio volumio[7957]: info: CoreStateMachine::pushState Jan 28 03:26:44 volumio volumio[7957]: info: CorePlayQueue::getTrack 0 Jan 28 03:26:44 volumio volumio[7957]: info: CoreCommandRouter::volumioPushState Jan 28 03:26:44 volumio volumio[7957]: info: Setting Device type: Raspberry PI Jan 28 03:26:44 volumio volumio[7957]: info: Completed loading Core Plugins Jan 28 03:26:44 volumio volumio[7957]: info: Preparing to generate the ALSA configuration file Jan 28 03:26:44 volumio volumio[7957]: info: VolumeController:: Volume=100 Mute =false Jan 28 03:26:44 volumio volumio[7957]: info: CoreStateMachine::pushState Jan 28 03:26:44 volumio volumio[7957]: info: CorePlayQueue::getTrack 0 Jan 28 03:26:44 volumio volumio[7957]: info: CoreCommandRouter::volumioPushState Jan 28 03:26:44 volumio volumio[7957]: info: Asound.conf file unchanged, so no further update is needed Jan 28 03:26:44 volumio volumio[7957]: info: Output device has changed, restarting MPD Jan 28 03:26:44 volumio volumio[7957]: info: Output device has changed, restarting Shairport Sync Jan 28 03:26:44 volumio volumio[7957]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 03:26:44 volumio volumio[7957]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 03:26:44 volumio sudo[8130]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Jan 28 03:26:44 volumio sudo[8130]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 03:26:44 volumio sudo[8132]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 28 03:26:44 volumio sudo[8132]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 03:26:44 volumio sudo[8132]: pam_unix(sudo:session): session closed for user root Jan 28 03:26:44 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 03:26:44 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 03:26:44 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 03:26:44 volumio volumio[7957]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 28 03:26:44 volumio volumio[7957]: info: ___________ START PLUGINS ___________ Jan 28 03:26:44 volumio sudo[8134]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 28 03:26:44 volumio sudo[8134]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 03:26:44 volumio volumio[7957]: info: ControllerMpd::onStart: Initializing MPD Jan 28 03:26:44 volumio volumio[7957]: info: Creating MPD Configuration file Jan 28 03:26:44 volumio sudo[8130]: pam_unix(sudo:session): session closed for user root Jan 28 03:26:44 volumio volumio[7957]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 28 03:26:44 volumio volumio[7957]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 03:26:44 volumio volumio[7957]: info: [1769545604659] CoreMusicLibrary::Adding element Media Servers Jan 28 03:26:44 volumio volumio[7957]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 03:26:44 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Jan 28 03:26:44 volumio sudo[8143]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 28 03:26:44 volumio sudo[8143]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 03:26:44 volumio volumio[7957]: info: UPNP Browser: Client initialized successfully Jan 28 03:26:44 volumio sudo[8145]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 28 03:26:44 volumio sudo[8145]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 03:26:44 volumio sudo[8143]: pam_unix(sudo:session): session closed for user root Jan 28 03:26:44 volumio volumio[7957]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 03:26:44 volumio volumio[7957]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 03:26:44 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 28 03:26:44 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 28 03:26:44 volumio systemd[1]: mpd.service: Consumed 7.165s CPU time. Jan 28 03:26:44 volumio volumio[7957]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 28 03:26:44 volumio volumio[7957]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 03:26:44 volumio volumio[7957]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 03:26:44 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 28 03:26:44 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 28 03:26:44 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 28 03:26:44 volumio volumio[7957]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 28 03:26:44 volumio volumio[7957]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 03:26:44 volumio volumio[7957]: info: [1769545604939] CoreMusicLibrary::Adding element Last_100 Jan 28 03:26:44 volumio volumio[7957]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 03:26:44 volumio volumio[7957]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 03:26:44 volumio volumio[7957]: info: [1769545604948] CoreMusicLibrary::Adding element Webradio Jan 28 03:26:44 volumio volumio[7957]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 03:26:44 volumio volumio[7957]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 28 03:26:44 volumio volumio[7957]: info: Initializing BBC Radios Jan 28 03:26:44 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 28 03:26:45 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 28 03:26:45 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 28 03:26:45 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 28 03:26:45 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 28 03:26:45 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 28 03:26:45 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 28 03:26:45 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 28 03:26:45 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 28 03:26:45 volumio volumio[7957]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 28 03:26:45 volumio volumio[7957]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 03:26:45 volumio volumio[7957]: info: Creating Spotify config file Jan 28 03:26:45 volumio volumio[7957]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 03:26:45 volumio sudo[8172]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 28 03:26:45 volumio sudo[8172]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jan 28 03:26:45 volumio sudo[8172]: pam_unix(sudo:session): session closed for user root Jan 28 03:26:46 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 39. Jan 28 03:26:46 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 03:26:46 volumio volumio[8079]: Starting albumart workers Jan 28 03:26:46 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 03:26:46 volumio go-librespot[8175]: go-librespot daemon starting... Jan 28 03:26:46 volumio volumio[7957]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 03:26:46 volumio volumio[7957]: info: [1769545606382] CoreMusicLibrary::Adding element YouTube Music Jan 28 03:26:46 volumio volumio[7957]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 03:26:46 volumio volumio[7957]: Cannot find translation for source YouTube Music Jan 28 03:26:46 volumio go-librespot[8176]: time="2026-01-28T03:26:46+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 03:26:46 volumio volumio[7957]: info: Volumio Calling Home Jan 28 03:26:46 volumio sudo[8184]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Jan 28 03:26:46 volumio sudo[8184]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 03:26:46 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 03:26:46 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 03:26:46 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 03:26:46 volumio volumio[8081]: Starting albumart workers Jan 28 03:26:46 volumio sudo[8184]: pam_unix(sudo:session): session closed for user root Jan 28 03:26:46 volumio volumio[8080]: Starting albumart workers Jan 28 03:26:47 volumio go-librespot[8176]: time="2026-01-28T03:26:47+07:00" level=info msg="zeroconf server listening on port 38673" Jan 28 03:26:47 volumio volumio[7957]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Jan 28 03:26:47 volumio volumio[7957]: info: Discovery: Found device Volumio Jan 28 03:26:47 volumio volumio[7957]: info: CoreCommandRouter::volumioGetState Jan 28 03:26:47 volumio volumio[7957]: info: CorePlayQueue::getTrack 0 Jan 28 03:26:47 volumio volumio[7957]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Jan 28 03:26:47 volumio volumio[7957]: info: Discovery: Found device Volumio Jan 28 03:26:47 volumio volumio[7957]: info: CoreCommandRouter::volumioGetState Jan 28 03:26:47 volumio volumio[7957]: info: CorePlayQueue::getTrack 0 Jan 28 03:26:47 volumio volumio[7957]: info: MPD Permissions set Jan 28 03:26:47 volumio volumio[7957]: info: MPD Permissions set Jan 28 03:26:47 volumio volumio[7957]: info: Upmpdcli Daemon Started Jan 28 03:26:47 volumio volumio[7957]: info: Volumio called home Jan 28 03:26:47 volumio volumio[7957]: info: Spotify config file written Jan 28 03:26:47 volumio sudo[8191]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jan 28 03:26:47 volumio sudo[8191]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 03:26:47 volumio volumio[7957]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Jan 28 03:26:47 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Jan 28 03:26:47 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Jan 28 03:26:48 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 03:26:48 volumio volumio[7957]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 03:26:48 volumio volumio[7957]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 03:26:48 volumio volumio[7957]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 03:26:48 volumio volumio[7957]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 03:26:48 volumio volumio[7957]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 03:26:48 volumio volumio[7957]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 03:26:48 volumio volumio[7957]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 03:26:48 volumio volumio[7957]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 03:26:48 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 03:26:48 volumio go-librespot[8193]: go-librespot daemon starting... Jan 28 03:26:48 volumio sudo[8191]: pam_unix(sudo:session): session closed for user root Jan 28 03:26:48 volumio volumio[7957]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 03:26:48 volumio volumio[7957]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 03:26:48 volumio volumio[7957]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 03:26:48 volumio volumio[7957]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 03:26:48 volumio go-librespot[8195]: time="2026-01-28T03:26:48+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 03:26:48 volumio go-librespot[8195]: time="2026-01-28T03:26:48+07:00" level=debug msg="app state loaded" Jan 28 03:26:48 volumio volumio[7957]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 03:26:48 volumio volumio[7957]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 03:26:48 volumio volumio[7957]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 03:26:48 volumio volumio[7957]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 03:26:48 volumio volumio[7957]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 03:26:48 volumio volumio[7957]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 03:26:48 volumio go-librespot[8195]: time="2026-01-28T03:26:48+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 03:26:48 volumio volumio[7957]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 03:26:48 volumio volumio[7957]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 03:26:48 volumio volumio[7957]: info: No need to fix Spotify hosts Jan 28 03:26:48 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 03:26:48 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 03:26:48 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 03:26:48 volumio go-librespot[8195]: time="2026-01-28T03:26:48+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 03:26:48 volumio go-librespot[8195]: time="2026-01-28T03:26:48+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]" Jan 28 03:26:48 volumio go-librespot[8195]: time="2026-01-28T03:26:48+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]" Jan 28 03:26:48 volumio go-librespot[8195]: time="2026-01-28T03:26:48+07:00" level=info msg="zeroconf server listening on port 45255" Jan 28 03:26:49 volumio go-librespot[8195]: time="2026-01-28T03:26:49+07:00" level=debug msg="obtained new client token: AAC6kUQTMmOMkMT7RQBDF78w/asLue9POi1zU9JJaFHCWlgzNLysCDscz/Y9kMRfIP08P0PXD/G+gcy9IEUy6Jq0WViILlfuaYfKp5HE22jRHyXYFEU/kkViS7Il/GydroNIWsMCz+Ynh5r3FfGlfRDCGa5gGxe4GU7XJukEJWuPO/7a+Stkfc2KG1x20zvhzcce1iO27RsEHvfy843ueI+bLk6ac6fb7U1j5cFnmikIHctYljt6drCk" Jan 28 03:26:49 volumio go-librespot[8195]: time="2026-01-28T03:26:49+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 03:26:49 volumio go-librespot[8195]: time="2026-01-28T03:26:49+07:00" level=debug msg="completed keyexchange" Jan 28 03:26:49 volumio go-librespot[8195]: time="2026-01-28T03:26:49+07:00" level=debug msg="completed challenge" Jan 28 03:26:49 volumio go-librespot[8195]: time="2026-01-28T03:26:49+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 03:26:49 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 03:26:49 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 03:26:49 volumio volumio[7957]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 28 03:26:49 volumio volumio[7957]: SPOTIFY: BQBn2hQ2rP0vYZMWSCa_hRZL7lNBp31XD4oSnrMttnBZdPnOV_q7nu_3tFUvtr_t9HzVod_Qy2U4E0Be_iuH66GmKZS-LESMUS4lfa94vw_PymdtujSglPu7QpXFcJfR6yrp7sXHtOxpoBoaPMe0Wwc-3kupDciMSm_TQM5FleWKvA6DHAOLrGzDSDTYbKvueOpp-xqdT2xaTN_wxUMbO4K_Yct6FdANx017KTr-CESChzCW5EU5Cy-8excfSTwK7fIzywtp1FMw-Ub8wKpObmAiduORZkDo7bO7pX9GnwIx5KoPvslJclt0 Jan 28 03:26:49 volumio volumio[7957]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 28 03:26:49 volumio volumio[7957]: info: New Spotify access token = BQBn2hQ2rP0vYZMWSCa_hRZL7lNBp31XD4oSnrMttnBZdPnOV_q7nu_3tFUvtr_t9HzVod_Qy2U4E0Be_iuH66GmKZS-LESMUS4lfa94vw_PymdtujSglPu7QpXFcJfR6yrp7sXHtOxpoBoaPMe0Wwc-3kupDciMSm_TQM5FleWKvA6DHAOLrGzDSDTYbKvueOpp-xqdT2xaTN_wxUMbO4K_Yct6FdANx017KTr-CESChzCW5EU5Cy-8excfSTwK7fIzywtp1FMw-Ub8wKpObmAiduORZkDo7bO7pX9GnwIx5KoPvslJclt0 Jan 28 03:26:49 volumio volumio[7957]: info: Spotify credentials grant success - running version from March 24, 2019 Jan 28 03:26:49 volumio volumio[7957]: info: Starting Shairport Sync Jan 28 03:26:49 volumio volumio[7957]: info: Starting Shairport Sync Jan 28 03:26:49 volumio volumio[7957]: info: Starting Shairport Sync Jan 28 03:26:49 volumio sudo[8231]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 28 03:26:49 volumio sudo[8231]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 03:26:49 volumio sudo[8235]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 28 03:26:49 volumio sudo[8233]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 28 03:26:49 volumio sudo[8235]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 03:26:49 volumio sudo[8233]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 03:26:49 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 28 03:26:49 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Jan 28 03:26:49 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 28 03:26:49 volumio systemd[1]: shairport-sync.service: Consumed 2.358s CPU time. Jan 28 03:26:50 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 28 03:26:50 volumio sudo[8233]: pam_unix(sudo:session): session closed for user root Jan 28 03:26:50 volumio sudo[8231]: pam_unix(sudo:session): session closed for user root Jan 28 03:26:50 volumio sudo[8235]: pam_unix(sudo:session): session closed for user root Jan 28 03:26:50 volumio volumio[7957]: info: Shairport-Sync Started Jan 28 03:26:50 volumio volumio[7957]: Error adding Membership: Error: addMembership EINVAL Jan 28 03:26:50 volumio volumio[7957]: info: Shairport-Sync Started Jan 28 03:26:50 volumio volumio[7957]: info: Shairport-Sync Started Jan 28 03:26:50 volumio volumio[7957]: info: CoreCommandRouter::volumioGetState Jan 28 03:26:50 volumio volumio[7957]: info: CorePlayQueue::getTrack 0 Jan 28 03:26:50 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 03:26:50 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 03:26:50 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 03:26:50 volumio volumio[7957]: 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"} Jan 28 03:26:50 volumio volumio[7957]: info: Spotify Successfully logged in Jan 28 03:26:50 volumio volumio[7957]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 03:26:50 volumio volumio[7957]: info: [1769545610577] CoreMusicLibrary::Adding element Spotify Jan 28 03:26:50 volumio volumio[7957]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 03:26:50 volumio volumio[7957]: Cannot find translation for source YouTube Music Jan 28 03:26:50 volumio volumio[7957]: Cannot find translation for source Spotify Jan 28 03:26:50 volumio volumio[7957]: info: [yt-cast-receiver] DIAL server listening on port 8098 Jan 28 03:26:50 volumio volumio[7957]: info: CoreCommandRouter::volumioRetrievevolume Jan 28 03:26:51 volumio volumio[7957]: info: VolumeController:: Volume=100 Mute =false Jan 28 03:26:51 volumio volumio[7957]: info: CoreCommandRouter::volumioGetState Jan 28 03:26:51 volumio volumio[7957]: info: CorePlayQueue::getTrack 0 Jan 28 03:26:51 volumio volumio[7957]: info: CoreStateMachine::pushState Jan 28 03:26:51 volumio volumio[7957]: info: CorePlayQueue::getTrack 0 Jan 28 03:26:51 volumio volumio[7957]: info: CoreCommandRouter::volumioPushState Jan 28 03:26:52 volumio volumio[7957]: info: go-librespot daemon successfully initialized Jan 28 03:26:52 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Jan 28 03:26:52 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 03:26:52 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 03:26:52 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 03:26:52 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 03:26:52 volumio mpd[8174]: 2026-01-28T03:26:52 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 28 03:26:52 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 03:26:52 volumio go-librespot[8270]: go-librespot daemon starting... Jan 28 03:26:52 volumio systemd[1]: Started mpd.service - Music Player Daemon. Jan 28 03:26:52 volumio sudo[8145]: pam_unix(sudo:session): session closed for user root Jan 28 03:26:52 volumio sudo[8134]: pam_unix(sudo:session): session closed for user root Jan 28 03:26:52 volumio go-librespot[8273]: time="2026-01-28T03:26:52+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 03:26:52 volumio go-librespot[8273]: time="2026-01-28T03:26:52+07:00" level=debug msg="app state loaded" Jan 28 03:26:52 volumio go-librespot[8273]: time="2026-01-28T03:26:52+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 03:26:52 volumio volumio[7957]: error: MPD error: The expression evaluated to a falsy value: Jan 28 03:26:52 volumio volumio[7957]: assert.ok(self.idling) Jan 28 03:26:52 volumio volumio[7957]: error: The expression evaluated to a falsy value: Jan 28 03:26:52 volumio volumio[7957]: assert.ok(self.idling) Jan 28 03:26:52 volumio volumio[7957]: error: updateQueue error: null Jan 28 03:26:52 volumio volumio[7957]: info: MPD running with PID8174 Jan 28 03:26:52 volumio volumio[7957]: ,establishing connection Jan 28 03:26:52 volumio volumio[7957]: error: updateQueue error: null Jan 28 03:26:52 volumio volumio[7957]: info: Completed starting Core Plugins Jan 28 03:26:52 volumio volumio[7957]: info: ------------------------------------------- Jan 28 03:26:52 volumio volumio[7957]: info: ----- MyVolumio plugins startup ---- Jan 28 03:26:52 volumio volumio[7957]: info: ------------------------------------------- Jan 28 03:26:52 volumio volumio[7957]: info: [MyVolumio PluginManager] Fetching plans data.... Jan 28 03:26:53 volumio go-librespot[8273]: time="2026-01-28T03:26:53+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 03:26:53 volumio go-librespot[8273]: time="2026-01-28T03:26:53+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]" Jan 28 03:26:53 volumio go-librespot[8273]: time="2026-01-28T03:26:53+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]" Jan 28 03:26:53 volumio go-librespot[8273]: time="2026-01-28T03:26:53+07:00" level=info msg="zeroconf server listening on port 40631" Jan 28 03:26:53 volumio go-librespot[8273]: time="2026-01-28T03:26:53+07:00" level=debug msg="obtained new client token: AACCQU+ffHzQg+qe2Ep76Kr0AfcfGLtbY76R+T03ZyjXMQsG4yEQGh1lQLDOqUwUCPP++PBSez/+GgkJPX8BkDyiXqPblVzflAXCddL69gnAdHK4nDiEpD5J9LGxaL1bHwQL1eaxRgr9Xuqx/cYSdGY5bisNgoS22pitW48o9RT3d455T0iHL7Xzfuk5A2j7noKUoslWIK0Q86uxLhhTvZ0SrsgyW1DHacPhf9J/XL/cYniyi5ycIAE5QVM=" Jan 28 03:26:53 volumio go-librespot[8273]: time="2026-01-28T03:26:53+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" Jan 28 03:26:53 volumio go-librespot[8273]: time="2026-01-28T03:26:53+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Jan 28 03:26:53 volumio go-librespot[8273]: time="2026-01-28T03:26:53+07:00" level=debug msg="completed keyexchange" Jan 28 03:26:53 volumio go-librespot[8273]: time="2026-01-28T03:26:53+07:00" level=debug msg="completed challenge" Jan 28 03:26:53 volumio go-librespot[8273]: time="2026-01-28T03:26:53+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 03:26:53 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 03:26:53 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 03:26:54 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 03:26:54 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 03:26:54 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 03:26:55 volumio volumio[7957]: info: Initializing connection to go-librespot Websocket Jan 28 03:26:55 volumio volumio[7957]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 28 03:26:56 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 03:26:56 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 03:26:56 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 03:26:56 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Jan 28 03:26:56 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 03:26:56 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 03:26:56 volumio go-librespot[8282]: go-librespot daemon starting... Jan 28 03:26:56 volumio go-librespot[8283]: time="2026-01-28T03:26:56+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 03:26:56 volumio go-librespot[8283]: time="2026-01-28T03:26:56+07:00" level=debug msg="app state loaded" Jan 28 03:26:56 volumio go-librespot[8283]: time="2026-01-28T03:26:56+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 03:26:57 volumio go-librespot[8283]: time="2026-01-28T03:26:57+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 03:26:57 volumio go-librespot[8283]: time="2026-01-28T03:26:57+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]" Jan 28 03:26:57 volumio go-librespot[8283]: time="2026-01-28T03:26:57+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]" Jan 28 03:26:57 volumio go-librespot[8283]: time="2026-01-28T03:26:57+07:00" level=info msg="zeroconf server listening on port 36471" Jan 28 03:26:57 volumio go-librespot[8283]: time="2026-01-28T03:26:57+07:00" level=debug msg="obtained new client token: AADnJGNonThIftXpgprlJS8tziJ/iVCanZmlIzCHf9u+I8OAsTcdjfY2d5J+Cqub7FLcZH8to0TYMKf8+TKoSL7AkoakkRDghM1+v3BbtDAJ6b164kPu96Wf7TpSjeX8Z3bvg1oXP/LElo1jXm6hRp2YynXT5AU+OcHbeYNRgzdeH6nEwQidc2Rk1XCSFkwkD0FWVROC53yuTTs8zUxgkdeQTQjPocmNZJ7qe7fP/YgDEi3Sy0ILbUIsmGI=" Jan 28 03:26:57 volumio volumio[7957]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Jan 28 03:26:57 volumio go-librespot[8283]: time="2026-01-28T03:26:57+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 03:26:57 volumio go-librespot[8283]: time="2026-01-28T03:26:57+07:00" level=debug msg="completed keyexchange" Jan 28 03:26:57 volumio go-librespot[8283]: time="2026-01-28T03:26:57+07:00" level=debug msg="completed challenge" Jan 28 03:26:57 volumio go-librespot[8283]: time="2026-01-28T03:26:57+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 03:26:57 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 03:26:57 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 03:26:58 volumio volumio[7957]: info: Initializing connection to go-librespot Websocket Jan 28 03:26:58 volumio volumio[7957]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 28 03:26:58 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 03:26:58 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 03:26:58 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 03:27:00 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 03:27:00 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 03:27:00 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 03:27:00 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Jan 28 03:27:00 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 03:27:01 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 03:27:01 volumio go-librespot[8291]: go-librespot daemon starting... Jan 28 03:27:01 volumio go-librespot[8292]: time="2026-01-28T03:27:01+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 03:27:01 volumio go-librespot[8292]: time="2026-01-28T03:27:01+07:00" level=debug msg="app state loaded" Jan 28 03:27:01 volumio go-librespot[8292]: time="2026-01-28T03:27:01+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 03:27:01 volumio volumio[7957]: info: Initializing connection to go-librespot Websocket Jan 28 03:27:01 volumio go-librespot[8292]: time="2026-01-28T03:27:01+07:00" level=debug msg="new websocket client" Jan 28 03:27:01 volumio go-librespot[8292]: time="2026-01-28T03:27:01+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 03:27:01 volumio go-librespot[8292]: time="2026-01-28T03:27:01+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 28 03:27:01 volumio go-librespot[8292]: time="2026-01-28T03:27:01+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 28 03:27:01 volumio volumio[7957]: info: Connection to go-librespot Websocket established Jan 28 03:27:01 volumio volumio[7957]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Jan 28 03:27:01 volumio volumio[7957]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Jan 28 03:27:01 volumio volumio[7957]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Jan 28 03:27:01 volumio volumio[7957]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Jan 28 03:27:01 volumio volumio[7957]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Jan 28 03:27:01 volumio volumio[7957]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Jan 28 03:27:01 volumio volumio[7957]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Jan 28 03:27:01 volumio volumio[7957]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Jan 28 03:27:01 volumio volumio[7957]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Jan 28 03:27:01 volumio volumio[7957]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Jan 28 03:27:01 volumio volumio[7957]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Jan 28 03:27:01 volumio volumio[7957]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Jan 28 03:27:01 volumio volumio[7957]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Jan 28 03:27:01 volumio volumio[7957]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Jan 28 03:27:01 volumio volumio[7957]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Jan 28 03:27:01 volumio volumio[7957]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Jan 28 03:27:01 volumio volumio[7957]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Jan 28 03:27:01 volumio volumio[7957]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Jan 28 03:27:01 volumio volumio[7957]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Jan 28 03:27:01 volumio volumio[7957]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Jan 28 03:27:01 volumio volumio[7957]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Jan 28 03:27:01 volumio volumio[7957]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Jan 28 03:27:01 volumio volumio[7957]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Jan 28 03:27:01 volumio volumio[7957]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Jan 28 03:27:01 volumio volumio[7957]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Jan 28 03:27:01 volumio volumio[7957]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Jan 28 03:27:01 volumio volumio[7957]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Jan 28 03:27:01 volumio volumio[7957]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Jan 28 03:27:01 volumio go-librespot[8292]: time="2026-01-28T03:27:01+07:00" level=info msg="zeroconf server listening on port 37743" Jan 28 03:27:01 volumio volumio[7957]: info: Adding plugin bluetooth to MyMusic Plugins Jan 28 03:27:01 volumio volumio[7957]: info: Adding plugin multiroom to MyMusic Plugins Jan 28 03:27:01 volumio volumio[7957]: info: Adding plugin metavolumio to MyMusic Plugins Jan 28 03:27:01 volumio volumio[7957]: info: Adding plugin cd_controller to MyMusic Plugins Jan 28 03:27:01 volumio volumio[7957]: info: Adding plugin qobuzconnect to MyMusic Plugins Jan 28 03:27:01 volumio volumio[7957]: info: Adding plugin smart_inputs to MyMusic Plugins Jan 28 03:27:01 volumio volumio[7957]: info: Adding plugin tidalconnect to MyMusic Plugins Jan 28 03:27:01 volumio volumio[7957]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Jan 28 03:27:01 volumio go-librespot[8292]: time="2026-01-28T03:27:01+07:00" level=debug msg="obtained new client token: AAAMpjz5bKbb2iXTfQrb3RxUytjW9WVwBk8B+hYuQffyh1pbRnWpe+dMHJLgIjwJlsm97/1XMBbHL7/IFuYuMzxZ1jr4oukMXSuOyCWn+Edn5xpo7TElPgrwNhK6BejNjI+I+9ga/RFQf4XZ59y7CcfQAv9WdyfOtBdPjrq9ktC2dVw34DZimEfA1qJpg2/tu5C2SA4sDE1nSlXyXPjvm6HWoH7Rhc+1fG6uHgZIM0SMNqT6Gvy6gXAhxKk=" Jan 28 03:27:01 volumio go-librespot[8292]: time="2026-01-28T03:27:01+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 03:27:01 volumio go-librespot[8292]: time="2026-01-28T03:27:01+07:00" level=debug msg="completed keyexchange" Jan 28 03:27:01 volumio go-librespot[8292]: time="2026-01-28T03:27:01+07:00" level=debug msg="completed challenge" Jan 28 03:27:02 volumio go-librespot[8292]: time="2026-01-28T03:27:02+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 03:27:02 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 03:27:02 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 03:27:02 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 03:27:02 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 03:27:02 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 03:27:03 volumio volumio[7957]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Jan 28 03:27:03 volumio volumio[7957]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Jan 28 03:27:03 volumio volumio[7957]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 03:27:03 volumio volumio[7957]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 03:27:03 volumio volumio[7957]: info: Starting MyVolumio Remote Streaming Endpoints Jan 28 03:27:03 volumio volumio[7957]: info: MyVolumio login type: Token Jan 28 03:27:03 volumio volumio[7957]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Jan 28 03:27:03 volumio volumio[7957]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Jan 28 03:27:04 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 03:27:04 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 03:27:04 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 03:27:05 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Jan 28 03:27:05 volumio volumio[7957]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Jan 28 03:27:05 volumio volumio[7957]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Jan 28 03:27:05 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 03:27:05 volumio volumio[7957]: info: Streaming services startup Jan 28 03:27:05 volumio volumio[7957]: info: Starting Streaming Daemon Jan 28 03:27:05 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 03:27:05 volumio go-librespot[8313]: go-librespot daemon starting... Jan 28 03:27:05 volumio sudo[8315]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jan 28 03:27:05 volumio sudo[8315]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 03:27:05 volumio volumio[7957]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Jan 28 03:27:05 volumio go-librespot[8319]: time="2026-01-28T03:27:05+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 03:27:05 volumio go-librespot[8319]: time="2026-01-28T03:27:05+07:00" level=debug msg="app state loaded" Jan 28 03:27:05 volumio go-librespot[8319]: time="2026-01-28T03:27:05+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 03:27:05 volumio sudo[8315]: pam_unix(sudo:session): session closed for user root Jan 28 03:27:05 volumio volumio[7957]: info: Getting Spotify volume Jan 28 03:27:05 volumio volumio[7957]: info: Connection to go-librespot Websocket closed Jan 28 03:27:05 volumio volumio[7957]: error: Cannot start Volumio Streaming Daemon Jan 28 03:27:05 volumio volumio[7957]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Jan 28 03:27:05 volumio volumio[7957]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Jan 28 03:27:05 volumio volumio[7957]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Jan 28 03:27:05 volumio volumio[7957]: info: CoreCommandRouter::volumioGetState Jan 28 03:27:05 volumio volumio[7957]: info: CorePlayQueue::getTrack 0 Jan 28 03:27:05 volumio volumio[7957]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jan 28 03:27:05 volumio volumio[7957]: SPOTIFY: SPOTIFY VOLUME undefined Jan 28 03:27:05 volumio volumio[7957]: SPOTIFY: VOLUMIO VOLUME 100 Jan 28 03:27:05 volumio volumio[7957]: info: Aligning Spotify Volume to Volumio Volume Jan 28 03:27:05 volumio volumio[7957]: info: CoreCommandRouter::volumioGetState Jan 28 03:27:05 volumio volumio[7957]: info: CorePlayQueue::getTrack 0 Jan 28 03:27:05 volumio volumio[7957]: info: Setting Spotify Volume from Volumio: 100 Jan 28 03:27:05 volumio go-librespot[8319]: time="2026-01-28T03:27:05+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 03:27:05 volumio go-librespot[8319]: time="2026-01-28T03:27:05+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 28 03:27:05 volumio go-librespot[8319]: time="2026-01-28T03:27:05+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 28 03:27:05 volumio go-librespot[8319]: time="2026-01-28T03:27:05+07:00" level=info msg="zeroconf server listening on port 42857" Jan 28 03:27:06 volumio go-librespot[8319]: time="2026-01-28T03:27:06+07:00" level=debug msg="obtained new client token: AADpXp29WBiulVjB+T+kAmt2SUwsvkdzTLUwmrHh0FxJtUoIOlDb/kzt/+/Yx/Gadvd/VzOsRJ4YVD0jaaWfg+eOb7d0n6WB0QteXXagke3DbCyVJhlO2g3/6fynhrSU0EWpEKtroeXHRpA8Cq9EXK5Hrur4AFM9flN7FBuGgah1XbcTZ4jUwGFGE8N/SX9bQsozN6M+BOaxLjupaI/irttqyc0hfOeGHy+UEvuIhBzbREhEqozaseNo" Jan 28 03:27:06 volumio go-librespot[8319]: time="2026-01-28T03:27:06+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 03:27:06 volumio go-librespot[8319]: time="2026-01-28T03:27:06+07:00" level=debug msg="completed keyexchange" Jan 28 03:27:06 volumio go-librespot[8319]: time="2026-01-28T03:27:06+07:00" level=debug msg="completed challenge" Jan 28 03:27:06 volumio go-librespot[8319]: time="2026-01-28T03:27:06+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 03:27:06 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 03:27:06 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 03:27:06 volumio volumio[7957]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 28 03:27:06 volumio volumio[7957]: Error: socket hang up Jan 28 03:27:06 volumio volumio[7957]: at connResetException (node:internal/errors:720:14) Jan 28 03:27:06 volumio volumio[7957]: at Socket.socketOnEnd (node:_http_client:519:23) Jan 28 03:27:06 volumio volumio[7957]: at Socket.emit (node:events:526:35) Jan 28 03:27:06 volumio volumio[7957]: at endReadableNT (node:internal/streams/readable:1376:12) Jan 28 03:27:06 volumio volumio[7957]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Jan 28 03:27:06 volumio volumio[7957]: code: 'ECONNRESET', Jan 28 03:27:06 volumio volumio[7957]: response: undefined Jan 28 03:27:06 volumio volumio[7957]: } Jan 28 03:27:06 volumio volumio[7957]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 28 03:27:06 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 03:27:06 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 03:27:06 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 03:27:07 volumio sudo[8342]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-01-28 03:26' Jan 28 03:27:07 volumio sudo[8342]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 03:27:08 volumio sudo[8342]: pam_unix(sudo:session): session closed for user root Jan 28 03:27:08 volumio volumio-remote-updater[628]: [2026-01-28 03:27:08] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Jan 28 03:27:08 volumio volumio-remote-updater[628]: [2026-01-28 03:27:08] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Jan 28 03:27:08 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Jan 28 03:27:08 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Jan 28 03:27:08 volumio systemd[1]: volumio.service: Consumed 55.714s CPU time. Jan 28 03:27:08 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 28 03:27:08 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Jan 28 03:27:08 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 9546. Jan 28 03:27:08 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 03:27:08 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 03:27:08 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 03:27:08 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 28 03:27:08 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Jan 28 03:27:08 volumio systemd[1]: volumio.service: Consumed 55.714s CPU time. Jan 28 03:27:08 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Jan 28 03:27:08 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Jan 28 03:27:09 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Jan 28 03:27:09 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 03:27:09 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 03:27:09 volumio go-librespot[8370]: go-librespot daemon starting... Jan 28 03:27:09 volumio go-librespot[8371]: time="2026-01-28T03:27:09+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 03:27:09 volumio go-librespot[8371]: time="2026-01-28T03:27:09+07:00" level=debug msg="app state loaded" Jan 28 03:27:09 volumio go-librespot[8371]: time="2026-01-28T03:27:09+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 03:27:10 volumio go-librespot[8371]: time="2026-01-28T03:27:10+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 03:27:10 volumio go-librespot[8371]: time="2026-01-28T03:27:10+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]" Jan 28 03:27:10 volumio go-librespot[8371]: time="2026-01-28T03:27:10+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]" Jan 28 03:27:10 volumio go-librespot[8371]: time="2026-01-28T03:27:10+07:00" level=info msg="zeroconf server listening on port 40955" Jan 28 03:27:10 volumio go-librespot[8371]: time="2026-01-28T03:27:10+07:00" level=debug msg="obtained new client token: AABiTRDqCrsaj6QLDsHRKeviSKKpts7Wj4HFzdfEha0d3wRLpHbOq2BmqKRCeEuUxtsBgukrsDChOdSR2iC4cYYOLY7jXVMPgAgnHJYcPNjBTMarqBCh17o+ADZza5lfPz703arvCmXO+ntImYtRtvTBrEUf3tCvN7wup/YXP8PFE1ddxzcRVD6rlfDYXiOqjlRctJV9zZlWdZysRtxuNIWgJ33my/uLzOWmkzhdJRkatxj0jLJe5nuUYxk=" Jan 28 03:27:10 volumio go-librespot[8371]: time="2026-01-28T03:27:10+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 03:27:10 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 03:27:10 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 03:27:10 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 03:27:10 volumio go-librespot[8371]: time="2026-01-28T03:27:10+07:00" level=debug msg="completed keyexchange" Jan 28 03:27:10 volumio go-librespot[8371]: time="2026-01-28T03:27:10+07:00" level=debug msg="completed challenge" Jan 28 03:27:10 volumio go-librespot[8371]: time="2026-01-28T03:27:10+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 03:27:10 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 03:27:10 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 03:27:12 volumio volumio[8355]: info: ------------------------------------------- Jan 28 03:27:12 volumio volumio[8355]: info: ----- Volumio3 ---- Jan 28 03:27:12 volumio volumio[8355]: info: ------------------------------------------- Jan 28 03:27:12 volumio volumio[8355]: info: ----- System startup ---- Jan 28 03:27:12 volumio volumio[8355]: info: ------------------------------------------- Jan 28 03:27:12 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 03:27:12 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 03:27:12 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 03:27:13 volumio volumio-remote-updater[628]: [2026-01-28 03:27:13] [connect] Successful connection Jan 28 03:27:13 volumio volumio[8355]: info: MYVOLUMIO Environment detected Jan 28 03:27:13 volumio volumio[8355]: info: Plugin folders cleanup Jan 28 03:27:13 volumio volumio[8355]: info: Scanning into folder /volumio/app/plugins/ Jan 28 03:27:13 volumio volumio[8355]: info: Scanning category audio_interface Jan 28 03:27:13 volumio volumio[8355]: info: Scanning category miscellanea Jan 28 03:27:13 volumio volumio[8355]: info: Scanning category music_service Jan 28 03:27:13 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Jan 28 03:27:13 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 03:27:13 volumio volumio[8355]: info: Scanning category plugins.json Jan 28 03:27:13 volumio volumio[8355]: info: Scanning category system_controller Jan 28 03:27:13 volumio volumio[8355]: info: Scanning category user_interface Jan 28 03:27:13 volumio volumio[8355]: info: Scanning into folder /data/plugins/ Jan 28 03:27:13 volumio volumio[8355]: info: Scanning category music_service Jan 28 03:27:13 volumio volumio[8355]: info: Plugin folders cleanup completed Jan 28 03:27:13 volumio volumio[8355]: info: ------------------------------------------- Jan 28 03:27:13 volumio volumio[8355]: info: ----- Core plugins startup ---- Jan 28 03:27:13 volumio volumio[8355]: info: ------------------------------------------- Jan 28 03:27:13 volumio volumio[8355]: info: Loading plugins from folder /volumio/app/plugins/ Jan 28 03:27:13 volumio volumio[8355]: info: Adding plugin upnp to MyMusic Plugins Jan 28 03:27:13 volumio volumio[8355]: info: Adding plugin airplay_emulation to MyMusic Plugins Jan 28 03:27:13 volumio volumio[8355]: info: Adding plugin upnp_browser to MyMusic Plugins Jan 28 03:27:13 volumio volumio[8355]: info: Loading plugins from folder /data/plugins/ Jan 28 03:27:13 volumio volumio[8355]: info: Loading plugin "system"... Jan 28 03:27:13 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 03:27:13 volumio go-librespot[8391]: go-librespot daemon starting... Jan 28 03:27:13 volumio go-librespot[8392]: time="2026-01-28T03:27:13+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 03:27:13 volumio go-librespot[8392]: time="2026-01-28T03:27:13+07:00" level=debug msg="app state loaded" Jan 28 03:27:13 volumio go-librespot[8392]: time="2026-01-28T03:27:13+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 03:27:13 volumio volumio[8355]: info: Loading plugin "appearance"... Jan 28 03:27:14 volumio go-librespot[8392]: time="2026-01-28T03:27:14+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 28 03:27:14 volumio go-librespot[8392]: time="2026-01-28T03:27:14+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]" Jan 28 03:27:14 volumio go-librespot[8392]: time="2026-01-28T03:27:14+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]" Jan 28 03:27:14 volumio go-librespot[8392]: time="2026-01-28T03:27:14+07:00" level=info msg="zeroconf server listening on port 44007" Jan 28 03:27:14 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 03:27:14 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 03:27:14 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 03:27:14 volumio go-librespot[8392]: time="2026-01-28T03:27:14+07:00" level=debug msg="obtained new client token: AAD89hw/FmAnvFmRnv2GbJBjHfrBj+61H26g/ON8RwiB7FlJeUDsaX2PKbWRwtLnPzVarWYVFK7nf9w1AUQySIwu+bFx0jmVECPePdv4sMA/MU4mxawk4hIZEmO8FZyr55QDqxLnCckQuGTHqaHQJA4K1jBFZw+X9CM7qtOTT9oQmMxTQV6kNYJ23ZwGlOz8HmpcQKq1/pqTigimwYJ3ZRTxWVkbuzTzWYQsR2e+wxlWZ9XZNW8u372xBcU=" Jan 28 03:27:14 volumio go-librespot[8392]: time="2026-01-28T03:27:14+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 03:27:14 volumio go-librespot[8392]: time="2026-01-28T03:27:14+07:00" level=debug msg="completed keyexchange" Jan 28 03:27:14 volumio go-librespot[8392]: time="2026-01-28T03:27:14+07:00" level=debug msg="completed challenge" Jan 28 03:27:14 volumio go-librespot[8392]: time="2026-01-28T03:27:14+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 03:27:14 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 03:27:14 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 03:27:15 volumio volumio[8355]: info: Loading plugin "network"... Jan 28 03:27:15 volumio volumio[8355]: info: Refreshing Cached IP Addresses Jan 28 03:27:15 volumio sudo[8404]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 28 03:27:15 volumio sudo[8404]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 03:27:15 volumio sudo[8406]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 28 03:27:15 volumio volumio[8355]: info: Loading plugin "services"... Jan 28 03:27:15 volumio sudo[8404]: pam_unix(sudo:session): session closed for user root Jan 28 03:27:15 volumio sudo[8406]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 03:27:15 volumio volumio[8355]: info: Loading plugin "alsa_controller"... Jan 28 03:27:15 volumio sudo[8406]: pam_unix(sudo:session): session closed for user root Jan 28 03:27:16 volumio sudo[8413]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Jan 28 03:27:16 volumio sudo[8413]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 03:27:16 volumio volumio[8355]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 28 03:27:16 volumio volumio[8355]: info: Loading plugin "wizard"... Jan 28 03:27:16 volumio volumio[8355]: info: Loading plugin "networkfs"... Jan 28 03:27:16 volumio volumio[8355]: info: Starting Udev Watcher for removable devices Jan 28 03:27:16 volumio volumio[8355]: info: Ignoring mount for partition: boot Jan 28 03:27:16 volumio volumio[8355]: info: Ignoring mount for partition: volumio Jan 28 03:27:16 volumio volumio[8355]: info: Ignoring mount for partition: volumio_data Jan 28 03:27:16 volumio volumio[8355]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 28 03:27:16 volumio volumio[8355]: info: Loading plugin "volumio_command_line_client"... Jan 28 03:27:16 volumio volumio[8355]: info: Loading plugin "upnp"... Jan 28 03:27:16 volumio volumio[8355]: info: [1769545636281] Starting Upmpd Daemon Jan 28 03:27:16 volumio volumio[8355]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 28 03:27:16 volumio volumio[8355]: info: Loading plugin "my_music"... Jan 28 03:27:16 volumio volumio[8355]: info: Loading plugin "mpd"... Jan 28 03:27:16 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 03:27:16 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 03:27:16 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 03:27:16 volumio volumio[8355]: info: Loading plugin "upnp_browser"... Jan 28 03:27:17 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Jan 28 03:27:17 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 03:27:18 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 03:27:18 volumio go-librespot[8437]: go-librespot daemon starting... Jan 28 03:27:18 volumio go-librespot[8438]: time="2026-01-28T03:27:18+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 03:27:18 volumio go-librespot[8438]: time="2026-01-28T03:27:18+07:00" level=debug msg="app state loaded" Jan 28 03:27:18 volumio go-librespot[8438]: time="2026-01-28T03:27:18+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 03:27:18 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 03:27:18 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 03:27:18 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 03:27:18 volumio go-librespot[8438]: time="2026-01-28T03:27:18+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 03:27:18 volumio go-librespot[8438]: time="2026-01-28T03:27:18+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 28 03:27:18 volumio go-librespot[8438]: time="2026-01-28T03:27:18+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 28 03:27:18 volumio go-librespot[8438]: time="2026-01-28T03:27:18+07:00" level=info msg="zeroconf server listening on port 43103" Jan 28 03:27:18 volumio go-librespot[8438]: time="2026-01-28T03:27:18+07:00" level=debug msg="obtained new client token: AAD86vMq/CcDUyWPzViGkSGPHb/nFlAU9zP3ZZ/pbgUKblWKBTd1DEqwuqTj7T1IiNN1FlBYnxmkvanOcK7dYVFf1CBDXBx2j+u04tyXcNhF9VF9jRRDUHpy2F0/u/FllE+Ykop3vNBDWSNk5/7k5/W66fDCiXMM3YLT4QjJUredujVEx8c1ZkkYIY1P6wmwiQpjSklTTW1ToQKX5Jr6LsmEKxDfpMYFoBgAE7dUzFBZxHJEY1asdF53/aQ=" Jan 28 03:27:18 volumio sudo[8413]: pam_unix(sudo:session): session closed for user root Jan 28 03:27:18 volumio go-librespot[8438]: time="2026-01-28T03:27:18+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 03:27:19 volumio go-librespot[8438]: time="2026-01-28T03:27:19+07:00" level=debug msg="completed keyexchange" Jan 28 03:27:19 volumio go-librespot[8438]: time="2026-01-28T03:27:19+07:00" level=debug msg="completed challenge" Jan 28 03:27:19 volumio go-librespot[8438]: time="2026-01-28T03:27:19+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 03:27:19 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 03:27:19 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 03:27:19 volumio volumio[8355]: info: Starting UPNP Browser Jan 28 03:27:19 volumio volumio[8355]: info: Loading plugin "alarm-clock"... Jan 28 03:27:20 volumio volumio[8355]: info: Loading plugin "airplay_emulation"... Jan 28 03:27:20 volumio volumio[8355]: info: Starting Shairport Sync Jan 28 03:27:20 volumio volumio[8355]: info: Loading plugin "last_100"... Jan 28 03:27:20 volumio volumio[8355]: info: Loading plugin "webradio"... Jan 28 03:27:20 volumio volumio[8355]: info: Loading plugin "i2s_dacs"... Jan 28 03:27:20 volumio volumio[8355]: info: Loading plugin "volumiodiscovery"... Jan 28 03:27:20 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 03:27:20 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 03:27:20 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 03:27:20 volumio volumio[8355]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 28 03:27:20 volumio volumio[8355]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 03:27:20 volumio volumio[8355]: *** WARNING *** For more information see Jan 28 03:27:20 volumio volumio[8355]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 28 03:27:20 volumio volumio[8355]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 03:27:20 volumio volumio[8355]: *** WARNING *** For more information see Jan 28 03:27:20 volumio node[8355]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 28 03:27:20 volumio node[8355]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 03:27:20 volumio node[8355]: *** WARNING *** For more information see Jan 28 03:27:20 volumio node[8355]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 28 03:27:20 volumio node[8355]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 03:27:20 volumio node[8355]: *** WARNING *** For more information see Jan 28 03:27:20 volumio volumio[8355]: info: Applying required configuration parameters for plugin volumiodiscovery Jan 28 03:27:20 volumio volumio[8355]: info: Discovery: Started advertising with name: Volumio Jan 28 03:27:20 volumio volumio[8355]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 28 03:27:20 volumio volumio[8355]: info: Loading plugin "spop"... Jan 28 03:27:22 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Jan 28 03:27:22 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 03:27:22 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 03:27:22 volumio go-librespot[8447]: go-librespot daemon starting... Jan 28 03:27:22 volumio go-librespot[8448]: time="2026-01-28T03:27:22+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 03:27:22 volumio go-librespot[8448]: time="2026-01-28T03:27:22+07:00" level=debug msg="app state loaded" Jan 28 03:27:22 volumio go-librespot[8448]: time="2026-01-28T03:27:22+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 03:27:22 volumio volumio[8355]: info: Loading plugin "ytcr"... Jan 28 03:27:22 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 03:27:22 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 03:27:22 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 03:27:22 volumio go-librespot[8448]: time="2026-01-28T03:27:22+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 03:27:22 volumio go-librespot[8448]: time="2026-01-28T03:27:22+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 28 03:27:22 volumio go-librespot[8448]: time="2026-01-28T03:27:22+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 28 03:27:22 volumio go-librespot[8448]: time="2026-01-28T03:27:22+07:00" level=info msg="zeroconf server listening on port 41777" Jan 28 03:27:23 volumio go-librespot[8448]: time="2026-01-28T03:27:23+07:00" level=debug msg="obtained new client token: AABQep4Nj0OHUmDZteKKje6pF2Xl9RI9cNuzDF9M1ieYczP76BladDhpWjqgcptzbAV6FLRXSKmfuQPvn/1XDlPR/d0zLZI5X9V8qjvLET+hNDiMiV+dzvOJgorXgwGNpBp6DooLA7Xoqd3LRC44VvnRVK6jqr1PbgRxYvY83wKqtwUNHCn4ZdyPX1D2+Lu/vuFwxtQfjF/NOWzKuuU92P3qF4IdVQsZMjc58srS2pJFen6+7OqOUMtU" Jan 28 03:27:23 volumio go-librespot[8448]: time="2026-01-28T03:27:23+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 03:27:23 volumio go-librespot[8448]: time="2026-01-28T03:27:23+07:00" level=debug msg="completed keyexchange" Jan 28 03:27:23 volumio go-librespot[8448]: time="2026-01-28T03:27:23+07:00" level=debug msg="completed challenge" Jan 28 03:27:23 volumio go-librespot[8448]: time="2026-01-28T03:27:23+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 03:27:23 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 03:27:23 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 03:27:24 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 03:27:24 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 03:27:24 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 03:27:25 volumio volumio[8355]: info: Loading plugin "ytmusic"... Jan 28 03:27:25 volumio volumio-remote-updater[628]: [2026-01-28 03:27:25] [connect] Successful connection Jan 28 03:27:26 volumio volumio[8355]: info: Loading plugin "outputs"... Jan 28 03:27:26 volumio volumio[8355]: info: Loading plugin "albumart"... Jan 28 03:27:26 volumio volumio[8355]: info: Plugin example_plugin is not enabled Jan 28 03:27:26 volumio volumio[8355]: info: Loading plugin "inputs"... Jan 28 03:27:26 volumio volumio[8355]: info: Loading plugin "updater_comm"... Jan 28 03:27:26 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Jan 28 03:27:26 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 03:27:26 volumio volumio[8355]: info: Plugin mpdemulation is not enabled Jan 28 03:27:26 volumio volumio[8355]: info: Loading plugin "rest_api"... Jan 28 03:27:26 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 03:27:26 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 03:27:26 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 03:27:26 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 03:27:26 volumio go-librespot[8479]: go-librespot daemon starting... Jan 28 03:27:26 volumio volumio[8355]: info: Loading plugin "websocket"... Jan 28 03:27:26 volumio go-librespot[8481]: time="2026-01-28T03:27:26+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 03:27:26 volumio go-librespot[8481]: time="2026-01-28T03:27:26+07:00" level=debug msg="app state loaded" Jan 28 03:27:26 volumio go-librespot[8481]: time="2026-01-28T03:27:26+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 03:27:26 volumio volumio[8355]: info: Starting Socket.io Server version 1.7.4 Jan 28 03:27:26 volumio volumio[8355]: info: Loading plugin "RoonBridge"... Jan 28 03:27:27 volumio go-librespot[8481]: time="2026-01-28T03:27:27+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 03:27:27 volumio go-librespot[8481]: time="2026-01-28T03:27:27+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]" Jan 28 03:27:27 volumio go-librespot[8481]: time="2026-01-28T03:27:27+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]" Jan 28 03:27:27 volumio go-librespot[8481]: time="2026-01-28T03:27:27+07:00" level=info msg="zeroconf server listening on port 40949" Jan 28 03:27:27 volumio volumio[8355]: info: Applying required configuration parameters for plugin RoonBridge Jan 28 03:27:27 volumio volumio[8355]: info: Loading i18n strings for locale en Jan 28 03:27:27 volumio volumio[8355]: Updating browse sources language Jan 28 03:27:27 volumio volumio[8355]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 03:27:27 volumio go-librespot[8481]: time="2026-01-28T03:27:27+07:00" level=debug msg="obtained new client token: AAC8ZVpzVEN/p7EnXXYeoMvBdLx4d5OVB+h5nbbNHNfeFcTQZOPNKPURXUwg1SjOXdKa4Tr4fE6NJ5j38eIkGgiabmDEAbcfJiIEeDNNzGvPJMtAoC9SnxWg8ReZUR5x8IrQaHD0kVgU9kJKCOnVTPfDBC5+EIL436o8858Y1qUIfiE8zfCtQ8EfKdZ2mvgWP5D8fLipkIhQEQa1ltuYM4totipsxnucG/kpKlHl33z9SxfdriwJaeimZIk=" Jan 28 03:27:27 volumio volumio[8470]: Forking 3 albumart workers Jan 28 03:27:27 volumio go-librespot[8481]: time="2026-01-28T03:27:27+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 03:27:27 volumio volumio[8355]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 28 03:27:27 volumio volumio[8355]: info: CoreCommandRouter::initPlayerControls Jan 28 03:27:27 volumio volumio[8355]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 03:27:27 volumio volumio[8355]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 03:27:27 volumio volumio[8355]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 03:27:27 volumio volumio[8355]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 03:27:27 volumio volumio[8355]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 03:27:27 volumio volumio[8355]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 03:27:27 volumio volumio[8355]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 03:27:27 volumio volumio[8355]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 03:27:27 volumio volumio[8355]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 28 03:27:27 volumio volumio[8355]: Express server listening on port 3000 Jan 28 03:27:27 volumio volumio[8355]: [Metrics] WebUI: 16s 383.76ms Jan 28 03:27:27 volumio volumio[8355]: info: CoreStateMachine::resetVolumioState Jan 28 03:27:27 volumio volumio[8355]: info: CoreStateMachine::getcurrentVolume Jan 28 03:27:27 volumio volumio[8355]: info: CoreCommandRouter::volumioRetrievevolume Jan 28 03:27:27 volumio go-librespot[8481]: time="2026-01-28T03:27:27+07:00" level=debug msg="completed keyexchange" Jan 28 03:27:27 volumio go-librespot[8481]: time="2026-01-28T03:27:27+07:00" level=debug msg="completed challenge" Jan 28 03:27:27 volumio go-librespot[8481]: time="2026-01-28T03:27:27+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 03:27:27 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 03:27:27 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 03:27:27 volumio sudo[8523]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 28 03:27:27 volumio sudo[8521]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 28 03:27:27 volumio sudo[8521]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 03:27:27 volumio sudo[8523]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 03:27:27 volumio sudo[8521]: pam_unix(sudo:session): session closed for user root Jan 28 03:27:27 volumio sudo[8523]: pam_unix(sudo:session): session closed for user root Jan 28 03:27:28 volumio volumio[8355]: info: Volumio Network Manager: Network status updated: 1 Jan 28 03:27:28 volumio volumio[8355]: info: VolumeController:: Volume=100 Mute =false Jan 28 03:27:28 volumio volumio[8355]: info: CoreStateMachine::pushState Jan 28 03:27:28 volumio volumio[8355]: info: CorePlayQueue::getTrack 0 Jan 28 03:27:28 volumio volumio[8355]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 28 03:27:28 volumio volumio[8355]: info: CoreCommandRouter::volumioPushState Jan 28 03:27:28 volumio volumio[8355]: info: CoreStateMachine::updateTrackBlock Jan 28 03:27:28 volumio volumio[8355]: info: CorePlayQueue::getTrackBlock Jan 28 03:27:28 volumio volumio[8355]: info: CoreCommandRouter::volumioRetrievevolume Jan 28 03:27:28 volumio volumio-remote-updater[628]: [2026-01-28 03:27:28] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1769545645 101 Jan 28 03:27:28 volumio volumio[8355]: 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 Jan 28 03:27:28 volumio volumio[8355]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 03:27:28 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 03:27:28 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 03:27:28 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 03:27:28 volumio volumio[8355]: info: Reloading queue from file Jan 28 03:27:28 volumio volumio[8355]: info: CoreStateMachine::setRepeat null single undefined Jan 28 03:27:28 volumio volumio[8355]: info: CoreStateMachine::pushState Jan 28 03:27:28 volumio volumio[8355]: info: CorePlayQueue::getTrack 0 Jan 28 03:27:28 volumio volumio[8355]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 28 03:27:28 volumio volumio[8355]: info: CoreCommandRouter::volumioPushState Jan 28 03:27:28 volumio volumio[8355]: info: CoreStateMachine::setRandom null Jan 28 03:27:28 volumio volumio[8355]: info: CoreStateMachine::pushState Jan 28 03:27:28 volumio volumio[8355]: info: CorePlayQueue::getTrack 0 Jan 28 03:27:28 volumio volumio[8355]: info: CoreCommandRouter::volumioPushState Jan 28 03:27:28 volumio volumio[8355]: info: Setting Device type: Raspberry PI Jan 28 03:27:28 volumio volumio[8355]: info: Completed loading Core Plugins Jan 28 03:27:28 volumio volumio[8355]: info: Preparing to generate the ALSA configuration file Jan 28 03:27:28 volumio volumio[8355]: info: VolumeController:: Volume=100 Mute =false Jan 28 03:27:28 volumio volumio[8355]: info: CoreStateMachine::pushState Jan 28 03:27:28 volumio volumio[8355]: info: CorePlayQueue::getTrack 0 Jan 28 03:27:28 volumio volumio[8355]: info: CoreCommandRouter::volumioPushState Jan 28 03:27:28 volumio volumio[8355]: info: Asound.conf file unchanged, so no further update is needed Jan 28 03:27:28 volumio volumio[8355]: info: Output device has changed, restarting MPD Jan 28 03:27:29 volumio volumio[8355]: info: Output device has changed, restarting Shairport Sync Jan 28 03:27:29 volumio volumio[8355]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 03:27:29 volumio volumio[8355]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 03:27:29 volumio sudo[8539]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Jan 28 03:27:29 volumio sudo[8539]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 03:27:29 volumio sudo[8541]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 28 03:27:29 volumio sudo[8541]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 03:27:29 volumio sudo[8543]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 28 03:27:29 volumio sudo[8543]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 03:27:29 volumio sudo[8541]: pam_unix(sudo:session): session closed for user root Jan 28 03:27:29 volumio volumio[8355]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 28 03:27:29 volumio volumio[8355]: info: ___________ START PLUGINS ___________ Jan 28 03:27:29 volumio volumio[8355]: info: ControllerMpd::onStart: Initializing MPD Jan 28 03:27:29 volumio volumio[8355]: info: Creating MPD Configuration file Jan 28 03:27:29 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Jan 28 03:27:29 volumio sudo[8539]: pam_unix(sudo:session): session closed for user root Jan 28 03:27:29 volumio volumio[8355]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 28 03:27:29 volumio volumio[8355]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 03:27:29 volumio volumio[8355]: info: [1769545649295] CoreMusicLibrary::Adding element Media Servers Jan 28 03:27:29 volumio volumio[8355]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 03:27:29 volumio sudo[8554]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 28 03:27:29 volumio sudo[8554]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 03:27:29 volumio sudo[8552]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 28 03:27:29 volumio sudo[8552]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 03:27:29 volumio volumio[8355]: info: UPNP Browser: Client initialized successfully Jan 28 03:27:29 volumio sudo[8552]: pam_unix(sudo:session): session closed for user root Jan 28 03:27:29 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 28 03:27:29 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 28 03:27:29 volumio systemd[1]: mpd.service: Consumed 7.086s CPU time. Jan 28 03:27:29 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 28 03:27:29 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 28 03:27:29 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 28 03:27:29 volumio volumio[8355]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 03:27:29 volumio volumio[8355]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 03:27:29 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 28 03:27:29 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 28 03:27:29 volumio volumio[8355]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 28 03:27:29 volumio volumio[8355]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 03:27:29 volumio volumio[8355]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 03:27:29 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 28 03:27:29 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 28 03:27:29 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 28 03:27:29 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 28 03:27:29 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 28 03:27:29 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 28 03:27:29 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 28 03:27:29 volumio volumio[8355]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 28 03:27:29 volumio volumio[8355]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 03:27:29 volumio volumio[8355]: info: [1769545649647] CoreMusicLibrary::Adding element Last_100 Jan 28 03:27:29 volumio volumio[8355]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 03:27:29 volumio volumio[8355]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 03:27:29 volumio volumio[8355]: info: [1769545649660] CoreMusicLibrary::Adding element Webradio Jan 28 03:27:29 volumio volumio[8355]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 03:27:29 volumio volumio[8355]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 28 03:27:29 volumio volumio[8355]: info: Initializing BBC Radios Jan 28 03:27:29 volumio volumio[8355]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 28 03:27:29 volumio volumio[8355]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 03:27:29 volumio volumio[8355]: info: Creating Spotify config file Jan 28 03:27:29 volumio volumio[8355]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 03:27:30 volumio sudo[8568]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 28 03:27:30 volumio sudo[8568]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jan 28 03:27:30 volumio sudo[8568]: pam_unix(sudo:session): session closed for user root Jan 28 03:27:30 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 03:27:30 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 03:27:30 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 03:27:30 volumio volumio[8489]: Starting albumart workers Jan 28 03:27:30 volumio volumio[8491]: Starting albumart workers Jan 28 03:27:30 volumio volumio[8490]: Starting albumart workers Jan 28 03:27:30 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Jan 28 03:27:30 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 03:27:31 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 03:27:31 volumio go-librespot[8585]: go-librespot daemon starting... Jan 28 03:27:31 volumio volumio[8355]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 03:27:31 volumio volumio[8355]: info: [1769545651144] CoreMusicLibrary::Adding element YouTube Music Jan 28 03:27:31 volumio volumio[8355]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 03:27:31 volumio volumio[8355]: Cannot find translation for source YouTube Music Jan 28 03:27:31 volumio go-librespot[8586]: time="2026-01-28T03:27:31+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 03:27:31 volumio volumio[8355]: info: Volumio Calling Home Jan 28 03:27:31 volumio sudo[8593]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Jan 28 03:27:31 volumio sudo[8593]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 03:27:31 volumio sudo[8593]: pam_unix(sudo:session): session closed for user root Jan 28 03:27:31 volumio go-librespot[8586]: time="2026-01-28T03:27:31+07:00" level=info msg="zeroconf server listening on port 33969" Jan 28 03:27:32 volumio volumio[8355]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Jan 28 03:27:32 volumio volumio[8355]: info: Discovery: Found device Volumio Jan 28 03:27:32 volumio volumio[8355]: info: CoreCommandRouter::volumioGetState Jan 28 03:27:32 volumio volumio[8355]: info: CorePlayQueue::getTrack 0 Jan 28 03:27:32 volumio volumio[8355]: info: MPD Permissions set Jan 28 03:27:32 volumio volumio[8355]: info: MPD Permissions set Jan 28 03:27:32 volumio volumio[8355]: info: Upmpdcli Daemon Started Jan 28 03:27:32 volumio volumio[8355]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Jan 28 03:27:32 volumio volumio[8355]: info: Discovery: Found device Volumio Jan 28 03:27:32 volumio volumio[8355]: info: CoreCommandRouter::volumioGetState Jan 28 03:27:32 volumio volumio[8355]: info: CorePlayQueue::getTrack 0 Jan 28 03:27:32 volumio volumio[8355]: info: Volumio called home Jan 28 03:27:32 volumio volumio[8355]: info: Spotify config file written Jan 28 03:27:32 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 03:27:32 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 03:27:32 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 03:27:32 volumio sudo[8600]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jan 28 03:27:32 volumio sudo[8600]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 03:27:32 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Jan 28 03:27:32 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Jan 28 03:27:32 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 03:27:32 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 03:27:32 volumio go-librespot[8613]: go-librespot daemon starting... Jan 28 03:27:32 volumio sudo[8600]: pam_unix(sudo:session): session closed for user root Jan 28 03:27:32 volumio volumio[8355]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Jan 28 03:27:33 volumio volumio[8355]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 03:27:33 volumio volumio[8355]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 03:27:33 volumio volumio[8355]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 03:27:33 volumio volumio[8355]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 03:27:33 volumio volumio[8355]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 03:27:33 volumio volumio[8355]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 03:27:33 volumio volumio[8355]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 03:27:33 volumio volumio[8355]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 03:27:33 volumio go-librespot[8621]: time="2026-01-28T03:27:33+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 03:27:33 volumio go-librespot[8621]: time="2026-01-28T03:27:33+07:00" level=debug msg="app state loaded" Jan 28 03:27:33 volumio go-librespot[8621]: time="2026-01-28T03:27:33+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 03:27:33 volumio volumio[8355]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 03:27:33 volumio volumio[8355]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 03:27:33 volumio volumio[8355]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 03:27:33 volumio volumio[8355]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 03:27:33 volumio volumio[8355]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 03:27:33 volumio volumio[8355]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 03:27:33 volumio volumio[8355]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 03:27:33 volumio volumio[8355]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 03:27:33 volumio volumio[8355]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 03:27:33 volumio volumio[8355]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 03:27:33 volumio volumio[8355]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 03:27:33 volumio volumio[8355]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 03:27:33 volumio volumio[8355]: info: No need to fix Spotify hosts Jan 28 03:27:33 volumio go-librespot[8621]: time="2026-01-28T03:27:33+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 28 03:27:33 volumio go-librespot[8621]: time="2026-01-28T03:27:33+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]" Jan 28 03:27:33 volumio go-librespot[8621]: time="2026-01-28T03:27:33+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]" Jan 28 03:27:33 volumio go-librespot[8621]: time="2026-01-28T03:27:33+07:00" level=info msg="zeroconf server listening on port 40765" Jan 28 03:27:33 volumio volumio[8355]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 28 03:27:33 volumio volumio[8355]: SPOTIFY: BQCdfCqcImwgHdywmD0PPSXQBLG6hj_qUZHEL83dklq4kc0UHNGNaegHj28-Ctgpw2jb2qI6dBs7mNe4OLMk06_ygPPBgmvFXiBrmxVb4y2OaeDlWueaRUmj5a9aRdMg9tmtlwTCNsIBLdZ9Da8mHX79JTZlVeyUH1MrY9KkEw2RA4GIRNr5ArYayXCh3YP1QShMJ5ImKaiuuoZzNIUXYlW54l_8CmY5Z6ktdpZY0958zsx27DFFBASJapGr7a9jk5ewRQRmyCPn7y6zlXy3ZaO3pnC53YSkhVbWFVXqnU-fjmgYduNDYGMW Jan 28 03:27:33 volumio volumio[8355]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 28 03:27:33 volumio volumio[8355]: info: New Spotify access token = BQCdfCqcImwgHdywmD0PPSXQBLG6hj_qUZHEL83dklq4kc0UHNGNaegHj28-Ctgpw2jb2qI6dBs7mNe4OLMk06_ygPPBgmvFXiBrmxVb4y2OaeDlWueaRUmj5a9aRdMg9tmtlwTCNsIBLdZ9Da8mHX79JTZlVeyUH1MrY9KkEw2RA4GIRNr5ArYayXCh3YP1QShMJ5ImKaiuuoZzNIUXYlW54l_8CmY5Z6ktdpZY0958zsx27DFFBASJapGr7a9jk5ewRQRmyCPn7y6zlXy3ZaO3pnC53YSkhVbWFVXqnU-fjmgYduNDYGMW Jan 28 03:27:33 volumio volumio[8355]: info: Spotify credentials grant success - running version from March 24, 2019 Jan 28 03:27:33 volumio go-librespot[8621]: time="2026-01-28T03:27:33+07:00" level=debug msg="obtained new client token: AAA6m2RcbDrpG9jizCVjmuMwS9Dx0QWPvDwN/bc7ORDBoVxcqLcnfZOfPyf3j9ju2GfpPbSOOTDtYtq7bDgu7AIRGTnmrzQn6pY2LzIn9T6Aew5JEt8w/8ZFe2Rp3PkeayPSsJpKyeXullzU4qv6PkgkGnqO+np+mSfpd75tnyTmOLbK5VtmK4tEAenI6iL+1QblLgeXBJI7rtD6o7RgxL7T0Dt6f4uWeDmZjzshk6UcQh7GjuPfDJiLzAQ=" Jan 28 03:27:33 volumio volumio[8355]: info: Starting Shairport Sync Jan 28 03:27:33 volumio volumio[8355]: info: Starting Shairport Sync Jan 28 03:27:33 volumio volumio[8355]: info: Starting Shairport Sync Jan 28 03:27:33 volumio go-librespot[8621]: time="2026-01-28T03:27:33+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 03:27:33 volumio sudo[8639]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 28 03:27:33 volumio sudo[8639]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 03:27:34 volumio sudo[8643]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 28 03:27:34 volumio sudo[8643]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 03:27:34 volumio sudo[8641]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 28 03:27:34 volumio sudo[8641]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 03:27:34 volumio go-librespot[8621]: time="2026-01-28T03:27:34+07:00" level=debug msg="completed keyexchange" Jan 28 03:27:34 volumio go-librespot[8621]: time="2026-01-28T03:27:34+07:00" level=debug msg="completed challenge" Jan 28 03:27:34 volumio go-librespot[8621]: time="2026-01-28T03:27: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 " Jan 28 03:27:34 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 03:27:34 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 03:27:34 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 28 03:27:34 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Jan 28 03:27:34 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 28 03:27:34 volumio systemd[1]: shairport-sync.service: Consumed 2.326s CPU time. Jan 28 03:27:34 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 28 03:27:34 volumio sudo[8639]: pam_unix(sudo:session): session closed for user root Jan 28 03:27:34 volumio sudo[8641]: pam_unix(sudo:session): session closed for user root Jan 28 03:27:34 volumio sudo[8643]: pam_unix(sudo:session): session closed for user root Jan 28 03:27:34 volumio volumio[8355]: info: CoreCommandRouter::volumioGetState Jan 28 03:27:34 volumio volumio[8355]: info: CorePlayQueue::getTrack 0 Jan 28 03:27:34 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 03:27:34 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 03:27:34 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 03:27:34 volumio volumio[8355]: info: Shairport-Sync Started Jan 28 03:27:34 volumio volumio[8355]: Error adding Membership: Error: addMembership EINVAL Jan 28 03:27:34 volumio volumio[8355]: info: Shairport-Sync Started Jan 28 03:27:34 volumio volumio[8355]: info: Shairport-Sync Started Jan 28 03:27:34 volumio volumio[8355]: 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"} Jan 28 03:27:34 volumio volumio[8355]: info: Spotify Successfully logged in Jan 28 03:27:34 volumio volumio[8355]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 03:27:34 volumio volumio[8355]: info: [1769545654852] CoreMusicLibrary::Adding element Spotify Jan 28 03:27:34 volumio volumio[8355]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 03:27:34 volumio volumio[8355]: Cannot find translation for source YouTube Music Jan 28 03:27:34 volumio volumio[8355]: Cannot find translation for source Spotify Jan 28 03:27:35 volumio volumio[8355]: info: [yt-cast-receiver] DIAL server listening on port 8098 Jan 28 03:27:35 volumio volumio[8355]: info: CoreCommandRouter::volumioRetrievevolume Jan 28 03:27:35 volumio volumio[8355]: info: VolumeController:: Volume=100 Mute =false Jan 28 03:27:35 volumio volumio[8355]: info: CoreCommandRouter::volumioGetState Jan 28 03:27:35 volumio volumio[8355]: info: CorePlayQueue::getTrack 0 Jan 28 03:27:35 volumio volumio[8355]: info: CoreStateMachine::pushState Jan 28 03:27:35 volumio volumio[8355]: info: CorePlayQueue::getTrack 0 Jan 28 03:27:35 volumio volumio[8355]: info: CoreCommandRouter::volumioPushState Jan 28 03:27:36 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 03:27:36 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 03:27:36 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 03:27:36 volumio volumio[8355]: info: go-librespot daemon successfully initialized Jan 28 03:27:37 volumio mpd[8584]: 2026-01-28T03:27:37 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 28 03:27:37 volumio systemd[1]: Started mpd.service - Music Player Daemon. Jan 28 03:27:37 volumio sudo[8543]: pam_unix(sudo:session): session closed for user root Jan 28 03:27:37 volumio sudo[8554]: pam_unix(sudo:session): session closed for user root Jan 28 03:27:37 volumio volumio[8355]: error: MPD error: The expression evaluated to a falsy value: Jan 28 03:27:37 volumio volumio[8355]: assert.ok(self.idling) Jan 28 03:27:37 volumio volumio[8355]: error: The expression evaluated to a falsy value: Jan 28 03:27:37 volumio volumio[8355]: assert.ok(self.idling) Jan 28 03:27:37 volumio volumio[8355]: info: MPD running with PID8584 Jan 28 03:27:37 volumio volumio[8355]: ,establishing connection Jan 28 03:27:37 volumio volumio[8355]: error: updateQueue error: null Jan 28 03:27:37 volumio volumio[8355]: info: Completed starting Core Plugins Jan 28 03:27:37 volumio volumio[8355]: info: ------------------------------------------- Jan 28 03:27:37 volumio volumio[8355]: info: ----- MyVolumio plugins startup ---- Jan 28 03:27:37 volumio volumio[8355]: info: ------------------------------------------- Jan 28 03:27:37 volumio volumio[8355]: info: [MyVolumio PluginManager] Fetching plans data.... Jan 28 03:27:37 volumio volumio[8355]: error: updateQueue error: null Jan 28 03:27:37 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Jan 28 03:27:37 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 03:27:37 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 03:27:37 volumio go-librespot[8684]: go-librespot daemon starting... Jan 28 03:27:37 volumio go-librespot[8685]: time="2026-01-28T03:27:37+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 03:27:37 volumio go-librespot[8685]: time="2026-01-28T03:27:37+07:00" level=debug msg="app state loaded" Jan 28 03:27:37 volumio go-librespot[8685]: time="2026-01-28T03:27:37+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 03:27:38 volumio go-librespot[8685]: time="2026-01-28T03:27: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]" Jan 28 03:27:38 volumio go-librespot[8685]: time="2026-01-28T03:27: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]" Jan 28 03:27:38 volumio go-librespot[8685]: time="2026-01-28T03:27: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]" Jan 28 03:27:38 volumio go-librespot[8685]: time="2026-01-28T03:27:38+07:00" level=info msg="zeroconf server listening on port 35663" Jan 28 03:27:38 volumio go-librespot[8685]: time="2026-01-28T03:27:38+07:00" level=debug msg="obtained new client token: AAASb3p7vwWDrEhRyqs/59wfrMsYBFep1U9ThIVNVskR1LNFqhBzFxBIUTwyJTM+9nOyHmamDOQCCsQVb5MOrsnRnuuZd7/UDlwi5LTL7savpwhyUGuRzlBKokBVg5rJMysFYVYzIi5JSQJ5MxEBzl1gr2ZT6XlLJ7PK1p2N/nhAvDaDKZ+cdy06YSE6GRIxmOvpVdEjVXCO5pP0jDcsguSJZldW5pFweJeMXtcFcOgXAEo4MDt2s+7/Uvw=" Jan 28 03:27:38 volumio go-librespot[8685]: time="2026-01-28T03:27:38+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 03:27:38 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 03:27:38 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 03:27:38 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 03:27:38 volumio go-librespot[8685]: time="2026-01-28T03:27:38+07:00" level=debug msg="completed keyexchange" Jan 28 03:27:38 volumio go-librespot[8685]: time="2026-01-28T03:27:38+07:00" level=debug msg="completed challenge" Jan 28 03:27:38 volumio go-librespot[8685]: time="2026-01-28T03:27: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 " Jan 28 03:27:38 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 03:27:38 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 03:27:39 volumio volumio[8355]: info: Initializing connection to go-librespot Websocket Jan 28 03:27:39 volumio volumio[8355]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 28 03:27:40 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 03:27:40 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 03:27:40 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 03:27:41 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Jan 28 03:27:41 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 03:27:41 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 03:27:41 volumio go-librespot[8692]: go-librespot daemon starting... Jan 28 03:27:41 volumio go-librespot[8693]: time="2026-01-28T03:27:41+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 03:27:41 volumio go-librespot[8693]: time="2026-01-28T03:27:41+07:00" level=debug msg="app state loaded" Jan 28 03:27:41 volumio go-librespot[8693]: time="2026-01-28T03:27:41+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 03:27:42 volumio volumio[8355]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Jan 28 03:27:42 volumio go-librespot[8693]: time="2026-01-28T03:27:42+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]" Jan 28 03:27:42 volumio go-librespot[8693]: time="2026-01-28T03:27:42+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]" Jan 28 03:27:42 volumio go-librespot[8693]: time="2026-01-28T03:27:42+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]" Jan 28 03:27:42 volumio go-librespot[8693]: time="2026-01-28T03:27:42+07:00" level=info msg="zeroconf server listening on port 43295" Jan 28 03:27:42 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 03:27:42 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 03:27:42 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 03:27:42 volumio volumio[8355]: info: Initializing connection to go-librespot Websocket Jan 28 03:27:42 volumio go-librespot[8693]: time="2026-01-28T03:27:42+07:00" level=debug msg="new websocket client" Jan 28 03:27:42 volumio go-librespot[8693]: time="2026-01-28T03:27:42+07:00" level=debug msg="obtained new client token: AAB79I2Mr3zR8o7H5+knN87gLG7AWhFhnYUJMDpjb5tqwzjSOrfln6qEfpycAaKibI+PtGl4hhAJqCIVFFhdtzA09f2oD3WpbYPcuHDi7Yxx6LGLST+qARG3/7sKFxI+U9G1na3t4ZUZQS3p/AJz5dHuv+/OgUjzNsgDXpV2bX9nl76m3m3b2gvxHr/0kOlgxqyPa5NeeV4dq1hobwAg3UvP4jB6eQSTM/JlntRZwE587+r0p2fET42NCEE=" Jan 28 03:27:42 volumio volumio[8355]: info: Connection to go-librespot Websocket established Jan 28 03:27:42 volumio go-librespot[8693]: time="2026-01-28T03:27:42+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 03:27:42 volumio go-librespot[8693]: time="2026-01-28T03:27:42+07:00" level=debug msg="completed keyexchange" Jan 28 03:27:42 volumio go-librespot[8693]: time="2026-01-28T03:27:42+07:00" level=debug msg="completed challenge" Jan 28 03:27:42 volumio go-librespot[8693]: time="2026-01-28T03:27: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 " Jan 28 03:27:42 volumio volumio[8355]: info: Connection to go-librespot Websocket closed Jan 28 03:27:42 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 03:27:42 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 03:27:44 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 03:27:44 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 03:27:44 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 03:27:45 volumio volumio[8355]: info: Getting Spotify volume Jan 28 03:27:45 volumio volumio[8355]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 28 03:27:45 volumio volumio[8355]: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 28 03:27:45 volumio volumio[8355]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Jan 28 03:27:45 volumio volumio[8355]: errno: -111, Jan 28 03:27:45 volumio volumio[8355]: code: 'ECONNREFUSED', Jan 28 03:27:45 volumio volumio[8355]: syscall: 'connect', Jan 28 03:27:45 volumio volumio[8355]: address: '127.0.0.1', Jan 28 03:27:45 volumio volumio[8355]: port: 9879, Jan 28 03:27:45 volumio volumio[8355]: response: undefined Jan 28 03:27:45 volumio volumio[8355]: } Jan 28 03:27:45 volumio volumio[8355]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 28 03:27:45 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Jan 28 03:27:45 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 03:27:46 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 03:27:46 volumio go-librespot[8712]: go-librespot daemon starting... Jan 28 03:27:46 volumio go-librespot[8713]: time="2026-01-28T03:27:46+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 03:27:46 volumio go-librespot[8713]: time="2026-01-28T03:27:46+07:00" level=debug msg="app state loaded" Jan 28 03:27:46 volumio go-librespot[8713]: time="2026-01-28T03:27:46+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 03:27:46 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 03:27:46 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 03:27:46 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 03:27:46 volumio go-librespot[8713]: time="2026-01-28T03:27: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-gew4.spotify.com:80]" Jan 28 03:27:46 volumio go-librespot[8713]: time="2026-01-28T03:27:46+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]" Jan 28 03:27:46 volumio go-librespot[8713]: time="2026-01-28T03:27:46+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]" Jan 28 03:27:46 volumio go-librespot[8713]: time="2026-01-28T03:27:46+07:00" level=info msg="zeroconf server listening on port 36645" Jan 28 03:27:46 volumio go-librespot[8713]: time="2026-01-28T03:27:46+07:00" level=debug msg="obtained new client token: AADIHRCGYtqIqSaCW2RRNWMxa64cHezf565gGbx2SIxHqkwodwAX554xypG43DMsrHPz79uWc3tArQXRKMizQXKvPz8zEUBkFfGX+QvAIAHQehS3ZeM+fzyz9GbUWmz4GQqgJ0TAGmE0hjOzq9WUjxAJlfj+HI+N85Vj0KZ0hTuj/o7bDjHmp5sVY3bmMImMEnpVrX7UFGP1kvCqA1VVsCu39fTAYq7HNcBTaEw2BqE0VTIhQiGDdjH9kpk=" Jan 28 03:27:47 volumio go-librespot[8713]: time="2026-01-28T03:27:47+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" Jan 28 03:27:47 volumio go-librespot[8713]: time="2026-01-28T03:27:47+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Jan 28 03:27:47 volumio go-librespot[8713]: time="2026-01-28T03:27:47+07:00" level=debug msg="completed keyexchange" Jan 28 03:27:47 volumio go-librespot[8713]: time="2026-01-28T03:27:47+07:00" level=debug msg="completed challenge" Jan 28 03:27:47 volumio sudo[8737]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-01-28 03:26' Jan 28 03:27:47 volumio sudo[8737]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 03:27:47 volumio go-librespot[8713]: time="2026-01-28T03:27:47+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 " Jan 28 03:27:47 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 03:27:47 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. PRETTY_NAME="Raspbian GNU/Linux 12 (bookworm)" NAME="Raspbian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="b05a530ca81d05eb9a84d0acf82089f0a60b8ee6" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="4ad85e2147d972f0b838d33c21382d2d813b2ae8" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu Dec 25 09:13:19 UTC 2025" VOLUMIO_VERSION="4.084" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="792f09af7488531aecd1aadcaa9b175e"