Jan 26 22:38:00 volumio volumio[4803]: 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 26 22:38:00 volumio sudo[5032]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jan 26 22:38:00 volumio volumio[4803]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 22:38:00 volumio sudo[5032]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 22:38:00 volumio volumio[4803]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 22:38:00 volumio volumio[4803]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 22:38:00 volumio volumio[4803]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 22:38:00 volumio volumio[4803]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 22:38:00 volumio volumio[4803]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 22:38:00 volumio volumio[4803]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 22:38:00 volumio volumio[4803]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 22:38:00 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 18. Jan 26 22:38:00 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 26 22:38:00 volumio volumio[4803]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 22:38:00 volumio volumio[4803]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 22:38:00 volumio volumio[4803]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 22:38:00 volumio volumio[4803]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 22:38:00 volumio volumio[4803]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 22:38:00 volumio volumio[4803]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 22:38:00 volumio volumio[4803]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 22:38:00 volumio volumio[4803]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 22:38:00 volumio volumio[4803]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 22:38:00 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 26 22:38:00 volumio go-librespot[5051]: go-librespot daemon starting... Jan 26 22:38:00 volumio volumio[4803]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 22:38:00 volumio sudo[5032]: pam_unix(sudo:session): session closed for user root Jan 26 22:38:00 volumio volumio[4803]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 22:38:00 volumio go-librespot[5052]: time="2026-01-26T22:38:00+07:00" level=info msg="running go-librespot 0.4.0" Jan 26 22:38:00 volumio go-librespot[5052]: time="2026-01-26T22:38:00+07:00" level=debug msg="app state loaded" Jan 26 22:38:00 volumio go-librespot[5052]: time="2026-01-26T22:38:00+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 26 22:38:00 volumio volumio[4803]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 22:38:00 volumio volumio[4803]: info: No need to fix Spotify hosts Jan 26 22:38:00 volumio go-librespot[5052]: time="2026-01-26T22:38:00+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 26 22:38:00 volumio go-librespot[5052]: time="2026-01-26T22:38:00+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 26 22:38:00 volumio go-librespot[5052]: time="2026-01-26T22:38:00+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 26 22:38:00 volumio go-librespot[5052]: time="2026-01-26T22:38:00+07:00" level=info msg="zeroconf server listening on port 40601" Jan 26 22:38:00 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 22:38:00 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 22:38:00 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 22:38:01 volumio go-librespot[5052]: time="2026-01-26T22:38:01+07:00" level=debug msg="obtained new client token: AABTwi+ousoO6i4yNTyQqU+CABJ5ZIi4BisLvT3D/G9lheWXmJ58t0Zmx7yz/EI0b/C5l82dCulXrCBju+o5xH1KlSDBiWEomlqU/ETJH2AT15ZMSdcF9S2pv4ohjrBMJDq4MISTBaxDdQibqtTnT4ImRWy2QdWi2KqDpfZfgf6x+CiUYjX9O2/Fhd9sbsoA+0fpcF4xpNS17ce5nzH4T05UJ8ESvrrX3rgyy78ZsC8gTp8Phe5ge0+S" Jan 26 22:38:01 volumio go-librespot[5052]: time="2026-01-26T22:38:01+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 26 22:38:01 volumio volumio[4803]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 26 22:38:01 volumio volumio[4803]: SPOTIFY: BQBZwN1SD4lRBq1zjr5GpiolnI_DhxifqvetZchkJGzyL1m4fAj5pSmGtVbUW53JEyoeWEQTNaNeXDFukyBCHaHxuXXFjWtK-I7tlmHvHrkzxc8E2pZwEvYFH7FbOYK-6Muxj4rfX-UJJmLr4H1pKwFhlBC4X-illwpOns2hrxgwWDIa-ooDnbp8s3gQp31PagoESrBihDsPg9xZ9arppGPWOSdtGr7mrvKD79r3RNlpPDKuKbRVjHXW0uGd7rFmikVmScZKSridyBsCaPjHadLd8EtbyzmFFNLPlLOrp2GHtH55hX1YUQ1f Jan 26 22:38:01 volumio volumio[4803]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 26 22:38:01 volumio volumio[4803]: info: New Spotify access token = BQBZwN1SD4lRBq1zjr5GpiolnI_DhxifqvetZchkJGzyL1m4fAj5pSmGtVbUW53JEyoeWEQTNaNeXDFukyBCHaHxuXXFjWtK-I7tlmHvHrkzxc8E2pZwEvYFH7FbOYK-6Muxj4rfX-UJJmLr4H1pKwFhlBC4X-illwpOns2hrxgwWDIa-ooDnbp8s3gQp31PagoESrBihDsPg9xZ9arppGPWOSdtGr7mrvKD79r3RNlpPDKuKbRVjHXW0uGd7rFmikVmScZKSridyBsCaPjHadLd8EtbyzmFFNLPlLOrp2GHtH55hX1YUQ1f Jan 26 22:38:01 volumio volumio[4803]: info: Spotify credentials grant success - running version from March 24, 2019 Jan 26 22:38:01 volumio go-librespot[5052]: time="2026-01-26T22:38:01+07:00" level=debug msg="completed keyexchange" Jan 26 22:38:01 volumio go-librespot[5052]: time="2026-01-26T22:38:01+07:00" level=debug msg="completed challenge" Jan 26 22:38:01 volumio volumio[4803]: info: Starting Shairport Sync Jan 26 22:38:01 volumio volumio[4803]: info: Starting Shairport Sync Jan 26 22:38:01 volumio volumio[4803]: info: Starting Shairport Sync Jan 26 22:38:01 volumio go-librespot[5052]: time="2026-01-26T22:38:01+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 26 22:38:01 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 26 22:38:01 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 26 22:38:01 volumio sudo[5072]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 26 22:38:01 volumio sudo[5072]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 22:38:01 volumio sudo[5076]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 26 22:38:01 volumio sudo[5076]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 22:38:01 volumio sudo[5074]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 26 22:38:01 volumio sudo[5074]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 22:38:01 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 26 22:38:01 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Jan 26 22:38:01 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 26 22:38:01 volumio systemd[1]: shairport-sync.service: Consumed 2.426s CPU time. Jan 26 22:38:01 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 26 22:38:01 volumio sudo[5074]: pam_unix(sudo:session): session closed for user root Jan 26 22:38:01 volumio sudo[5076]: pam_unix(sudo:session): session closed for user root Jan 26 22:38:01 volumio sudo[5072]: pam_unix(sudo:session): session closed for user root Jan 26 22:38:02 volumio volumio[4803]: info: Shairport-Sync Started Jan 26 22:38:02 volumio volumio[4803]: Error adding Membership: Error: addMembership EINVAL Jan 26 22:38:02 volumio volumio[4803]: info: Shairport-Sync Started Jan 26 22:38:02 volumio volumio[4803]: info: Shairport-Sync Started Jan 26 22:38:02 volumio volumio[4803]: info: CoreCommandRouter::volumioGetState Jan 26 22:38:02 volumio volumio[4803]: info: CorePlayQueue::getTrack 0 Jan 26 22:38:02 volumio volumio[4803]: 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 26 22:38:02 volumio volumio[4803]: info: Spotify Successfully logged in Jan 26 22:38:02 volumio volumio[4803]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 26 22:38:02 volumio volumio[4803]: info: [1769441882293] CoreMusicLibrary::Adding element Spotify Jan 26 22:38:02 volumio volumio[4803]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 26 22:38:02 volumio volumio[4803]: Cannot find translation for source YouTube Music Jan 26 22:38:02 volumio volumio[4803]: Cannot find translation for source Spotify Jan 26 22:38:02 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 22:38:02 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 22:38:02 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 22:38:03 volumio volumio[4803]: info: [yt-cast-receiver] DIAL server listening on port 8098 Jan 26 22:38:03 volumio volumio[4803]: info: CoreCommandRouter::volumioRetrievevolume Jan 26 22:38:03 volumio volumio[4803]: info: VolumeController:: Volume=100 Mute =false Jan 26 22:38:03 volumio volumio[4803]: info: CoreCommandRouter::volumioGetState Jan 26 22:38:03 volumio volumio[4803]: info: CorePlayQueue::getTrack 0 Jan 26 22:38:03 volumio volumio[4803]: info: CoreStateMachine::pushState Jan 26 22:38:03 volumio volumio[4803]: info: CorePlayQueue::getTrack 0 Jan 26 22:38:03 volumio volumio[4803]: info: CoreCommandRouter::volumioPushState Jan 26 22:38:04 volumio volumio[4803]: info: go-librespot daemon successfully initialized Jan 26 22:38:04 volumio mpd[5024]: 2026-01-26T22:38:04 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 26 22:38:04 volumio systemd[1]: Started mpd.service - Music Player Daemon. Jan 26 22:38:04 volumio sudo[4984]: pam_unix(sudo:session): session closed for user root Jan 26 22:38:04 volumio sudo[4995]: pam_unix(sudo:session): session closed for user root Jan 26 22:38:04 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 19. Jan 26 22:38:04 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 26 22:38:04 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 26 22:38:04 volumio go-librespot[5114]: go-librespot daemon starting... Jan 26 22:38:04 volumio go-librespot[5117]: time="2026-01-26T22:38:04+07:00" level=info msg="running go-librespot 0.4.0" Jan 26 22:38:04 volumio go-librespot[5117]: time="2026-01-26T22:38:04+07:00" level=debug msg="app state loaded" Jan 26 22:38:04 volumio go-librespot[5117]: time="2026-01-26T22:38:04+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 26 22:38:04 volumio volumio[4803]: error: MPD error: The expression evaluated to a falsy value: Jan 26 22:38:04 volumio volumio[4803]: assert.ok(self.idling) Jan 26 22:38:04 volumio volumio[4803]: error: The expression evaluated to a falsy value: Jan 26 22:38:04 volumio volumio[4803]: assert.ok(self.idling) Jan 26 22:38:04 volumio volumio[4803]: error: updateQueue error: null Jan 26 22:38:04 volumio volumio[4803]: info: MPD running with PID5024 Jan 26 22:38:04 volumio volumio[4803]: ,establishing connection Jan 26 22:38:04 volumio volumio[4803]: info: Completed starting Core Plugins Jan 26 22:38:04 volumio volumio[4803]: info: ------------------------------------------- Jan 26 22:38:04 volumio volumio[4803]: info: ----- MyVolumio plugins startup ---- Jan 26 22:38:04 volumio volumio[4803]: info: ------------------------------------------- Jan 26 22:38:04 volumio volumio[4803]: info: [MyVolumio PluginManager] Fetching plans data.... Jan 26 22:38:04 volumio volumio[4803]: error: updateQueue error: null Jan 26 22:38:04 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 22:38:04 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 22:38:04 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 22:38:05 volumio go-librespot[5117]: time="2026-01-26T22:38:05+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 26 22:38:05 volumio go-librespot[5117]: time="2026-01-26T22:38:05+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 26 22:38:05 volumio go-librespot[5117]: time="2026-01-26T22:38:05+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 26 22:38:05 volumio go-librespot[5117]: time="2026-01-26T22:38:05+07:00" level=info msg="zeroconf server listening on port 33675" Jan 26 22:38:05 volumio go-librespot[5117]: time="2026-01-26T22:38:05+07:00" level=debug msg="obtained new client token: AABFc/+IzRqn/3y30PmU/zYGKLUlLToMXt0Yreuz7NhXly12NcmPve4JEJQYQwnzpf/obvJIKCmA2FPkG6SBz1D0672Sh+oUxV+gNOxUjwVaaYv6lJCIXB1HzZyVPmeNYEUBkCdiItQwv1D77hHNgAipxzY2jnG89E5G31Xmhl+ZWTABKuBglthh0cpFFxlj/J41kRl/khtHqdc4alOmlDCRMKqQ4dZNxn7mme8fKPL+sOyIvwz+Ptx2q2Q=" Jan 26 22:38:05 volumio go-librespot[5117]: time="2026-01-26T22:38:05+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 26 22:38:05 volumio go-librespot[5117]: time="2026-01-26T22:38:05+07:00" level=debug msg="completed keyexchange" Jan 26 22:38:05 volumio go-librespot[5117]: time="2026-01-26T22:38:05+07:00" level=debug msg="completed challenge" Jan 26 22:38:05 volumio go-librespot[5117]: time="2026-01-26T22:38:05+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 26 22:38:05 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 26 22:38:05 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 26 22:38:06 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 22:38:06 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 22:38:06 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 22:38:07 volumio volumio[4803]: info: Initializing connection to go-librespot Websocket Jan 26 22:38:07 volumio volumio[4803]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 26 22:38:08 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 20. Jan 26 22:38:08 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 26 22:38:08 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 26 22:38:08 volumio go-librespot[5124]: go-librespot daemon starting... Jan 26 22:38:08 volumio go-librespot[5125]: time="2026-01-26T22:38:08+07:00" level=info msg="running go-librespot 0.4.0" Jan 26 22:38:08 volumio go-librespot[5125]: time="2026-01-26T22:38:08+07:00" level=debug msg="app state loaded" Jan 26 22:38:08 volumio go-librespot[5125]: time="2026-01-26T22:38:08+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 26 22:38:08 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 22:38:08 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 22:38:08 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 22:38:09 volumio go-librespot[5125]: time="2026-01-26T22:38:09+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 26 22:38:09 volumio go-librespot[5125]: time="2026-01-26T22:38:09+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 26 22:38:09 volumio go-librespot[5125]: time="2026-01-26T22:38:09+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 26 22:38:09 volumio go-librespot[5125]: time="2026-01-26T22:38:09+07:00" level=info msg="zeroconf server listening on port 44789" Jan 26 22:38:09 volumio go-librespot[5125]: time="2026-01-26T22:38:09+07:00" level=debug msg="obtained new client token: AAAhtesP63SEICMiWygz7c5lDtnzBW9FzB5hDjFbCM6Nays47VH87VwZSJ/YOxCVE+sR3mlL0OMsx3XZ58upV5zEgFmhdo4teqwGM2vWTznBIELJuzMusxyR9F4EFp2rPMzmJAuYIHvKrExaitnU6NilHvzQj9ps+55ADNG6DGbCrwtyF/dj//w8Wzb9lG2/iQg+jzyWDYPqMiIcUglXy1Vt0GZr9d2Y4uy5z3PkDoZaoX2hoySa/y1ViGc=" Jan 26 22:38:09 volumio volumio[4803]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Jan 26 22:38:09 volumio go-librespot[5125]: time="2026-01-26T22:38:09+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 26 22:38:09 volumio go-librespot[5125]: time="2026-01-26T22:38:09+07:00" level=debug msg="completed keyexchange" Jan 26 22:38:09 volumio go-librespot[5125]: time="2026-01-26T22:38:09+07:00" level=debug msg="completed challenge" Jan 26 22:38:09 volumio go-librespot[5125]: time="2026-01-26T22:38:09+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 26 22:38:09 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 26 22:38:09 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 26 22:38:10 volumio volumio[4803]: info: Initializing connection to go-librespot Websocket Jan 26 22:38:10 volumio volumio[4803]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 26 22:38:10 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 22:38:10 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 22:38:10 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 22:38:12 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 22:38:12 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 22:38:12 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 22:38:12 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 21. Jan 26 22:38:12 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 26 22:38:13 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 26 22:38:13 volumio go-librespot[5132]: go-librespot daemon starting... Jan 26 22:38:13 volumio go-librespot[5133]: time="2026-01-26T22:38:13+07:00" level=info msg="running go-librespot 0.4.0" Jan 26 22:38:13 volumio go-librespot[5133]: time="2026-01-26T22:38:13+07:00" level=debug msg="app state loaded" Jan 26 22:38:13 volumio go-librespot[5133]: time="2026-01-26T22:38:13+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 26 22:38:13 volumio volumio[4803]: info: Initializing connection to go-librespot Websocket Jan 26 22:38:13 volumio go-librespot[5133]: time="2026-01-26T22:38:13+07:00" level=debug msg="new websocket client" Jan 26 22:38:13 volumio volumio[4803]: info: Connection to go-librespot Websocket established Jan 26 22:38:13 volumio go-librespot[5133]: time="2026-01-26T22:38:13+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 26 22:38:13 volumio go-librespot[5133]: time="2026-01-26T22:38:13+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 26 22:38:13 volumio go-librespot[5133]: time="2026-01-26T22:38:13+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 26 22:38:13 volumio volumio[4803]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Jan 26 22:38:13 volumio volumio[4803]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Jan 26 22:38:13 volumio volumio[4803]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Jan 26 22:38:13 volumio volumio[4803]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Jan 26 22:38:13 volumio volumio[4803]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Jan 26 22:38:13 volumio volumio[4803]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Jan 26 22:38:13 volumio volumio[4803]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Jan 26 22:38:13 volumio volumio[4803]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Jan 26 22:38:13 volumio volumio[4803]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Jan 26 22:38:13 volumio volumio[4803]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Jan 26 22:38:13 volumio volumio[4803]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Jan 26 22:38:13 volumio volumio[4803]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Jan 26 22:38:13 volumio volumio[4803]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Jan 26 22:38:13 volumio volumio[4803]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Jan 26 22:38:13 volumio volumio[4803]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Jan 26 22:38:13 volumio volumio[4803]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Jan 26 22:38:13 volumio volumio[4803]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Jan 26 22:38:13 volumio volumio[4803]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Jan 26 22:38:13 volumio volumio[4803]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Jan 26 22:38:13 volumio volumio[4803]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Jan 26 22:38:13 volumio volumio[4803]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Jan 26 22:38:13 volumio volumio[4803]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Jan 26 22:38:13 volumio volumio[4803]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Jan 26 22:38:13 volumio volumio[4803]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Jan 26 22:38:13 volumio volumio[4803]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Jan 26 22:38:13 volumio volumio[4803]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Jan 26 22:38:13 volumio volumio[4803]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Jan 26 22:38:13 volumio volumio[4803]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Jan 26 22:38:13 volumio volumio[4803]: info: Adding plugin bluetooth to MyMusic Plugins Jan 26 22:38:13 volumio volumio[4803]: info: Adding plugin multiroom to MyMusic Plugins Jan 26 22:38:13 volumio volumio[4803]: info: Adding plugin metavolumio to MyMusic Plugins Jan 26 22:38:13 volumio volumio[4803]: info: Adding plugin cd_controller to MyMusic Plugins Jan 26 22:38:13 volumio go-librespot[5133]: time="2026-01-26T22:38:13+07:00" level=info msg="zeroconf server listening on port 35189" Jan 26 22:38:13 volumio volumio[4803]: info: Adding plugin qobuzconnect to MyMusic Plugins Jan 26 22:38:13 volumio volumio[4803]: info: Adding plugin smart_inputs to MyMusic Plugins Jan 26 22:38:13 volumio volumio[4803]: info: Adding plugin tidalconnect to MyMusic Plugins Jan 26 22:38:13 volumio volumio[4803]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Jan 26 22:38:14 volumio go-librespot[5133]: time="2026-01-26T22:38:14+07:00" level=debug msg="obtained new client token: AAAy/mky1Pma5Gq0HuhSfR7gAg5rJ8fUFRAl2rU/ET666qQ5BWRYTio0cjRUUAHTS/FoJBi9VgFhRBYz8cAUAJN5baf6/6K5T1x53yRLW3XeHYfRWKrcq8Hzbk8u5J2YFLb0SmXtA/9t7k+fxsyWVDojfimuOQB5l2YsFScQ05ujgOoohq5K5pVi9uJG6uIglm90y3bvg1y2y84WEwUoT3yFbzoFMHk+O/knj8YgKHs73KFpf4J0KH/YpII=" Jan 26 22:38:14 volumio go-librespot[5133]: time="2026-01-26T22:38:14+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 26 22:38:14 volumio go-librespot[5133]: time="2026-01-26T22:38:14+07:00" level=debug msg="completed keyexchange" Jan 26 22:38:14 volumio go-librespot[5133]: time="2026-01-26T22:38:14+07:00" level=debug msg="completed challenge" Jan 26 22:38:14 volumio go-librespot[5133]: time="2026-01-26T22:38: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 26 22:38:14 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 26 22:38:14 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 26 22:38:14 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 22:38:14 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 22:38:14 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 22:38:15 volumio volumio[4803]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Jan 26 22:38:15 volumio volumio[4803]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Jan 26 22:38:15 volumio volumio[4803]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 22:38:15 volumio volumio[4803]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 22:38:15 volumio volumio[4803]: info: Starting MyVolumio Remote Streaming Endpoints Jan 26 22:38:15 volumio volumio[4803]: info: MyVolumio login type: Token Jan 26 22:38:15 volumio volumio[4803]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Jan 26 22:38:15 volumio volumio[4803]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Jan 26 22:38:16 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 22:38:16 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 22:38:16 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 22:38:17 volumio volumio[4803]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Jan 26 22:38:17 volumio volumio[4803]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Jan 26 22:38:17 volumio volumio[4803]: info: Streaming services startup Jan 26 22:38:17 volumio volumio[4803]: info: Starting Streaming Daemon Jan 26 22:38:17 volumio sudo[5156]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jan 26 22:38:17 volumio sudo[5156]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 22:38:17 volumio volumio[4803]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Jan 26 22:38:17 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 22. Jan 26 22:38:17 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 26 22:38:17 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 26 22:38:17 volumio go-librespot[5162]: go-librespot daemon starting... Jan 26 22:38:17 volumio go-librespot[5163]: time="2026-01-26T22:38:17+07:00" level=info msg="running go-librespot 0.4.0" Jan 26 22:38:17 volumio go-librespot[5163]: time="2026-01-26T22:38:17+07:00" level=debug msg="app state loaded" Jan 26 22:38:17 volumio sudo[5156]: pam_unix(sudo:session): session closed for user root Jan 26 22:38:17 volumio go-librespot[5163]: time="2026-01-26T22:38:17+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 26 22:38:17 volumio volumio[4803]: info: Getting Spotify volume Jan 26 22:38:17 volumio volumio[4803]: info: Connection to go-librespot Websocket closed Jan 26 22:38:17 volumio volumio[4803]: error: Cannot start Volumio Streaming Daemon Jan 26 22:38:17 volumio volumio[4803]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Jan 26 22:38:17 volumio volumio[4803]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Jan 26 22:38:17 volumio volumio[4803]: 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 26 22:38:18 volumio volumio[4803]: info: CoreCommandRouter::volumioGetState Jan 26 22:38:18 volumio volumio[4803]: info: CorePlayQueue::getTrack 0 Jan 26 22:38:18 volumio volumio[4803]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jan 26 22:38:18 volumio volumio[4803]: SPOTIFY: SPOTIFY VOLUME undefined Jan 26 22:38:18 volumio volumio[4803]: SPOTIFY: VOLUMIO VOLUME 100 Jan 26 22:38:18 volumio volumio[4803]: info: Aligning Spotify Volume to Volumio Volume Jan 26 22:38:18 volumio volumio[4803]: info: CoreCommandRouter::volumioGetState Jan 26 22:38:18 volumio volumio[4803]: info: CorePlayQueue::getTrack 0 Jan 26 22:38:18 volumio volumio[4803]: info: Setting Spotify Volume from Volumio: 100 Jan 26 22:38:18 volumio go-librespot[5163]: time="2026-01-26T22:38: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-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 26 22:38:18 volumio go-librespot[5163]: time="2026-01-26T22:38:18+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 26 22:38:18 volumio go-librespot[5163]: time="2026-01-26T22:38:18+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 26 22:38:18 volumio go-librespot[5163]: time="2026-01-26T22:38:18+07:00" level=info msg="zeroconf server listening on port 45405" Jan 26 22:38:18 volumio go-librespot[5163]: time="2026-01-26T22:38:18+07:00" level=debug msg="obtained new client token: AAD7q/jWORBZALjTx+Fj71CVJDDtaCZ73FA1diWWNvdoMQvZUCEd/ycaMii26PDEn6vSDwwBnogcr1h5stxpncsRh2OBXifkGBJXZq8rcTcSNSFXlsmT4o1Ba2E7KnUWB/cH2H+LINZSds9Ok7JvMnQL1FUr0d30L1huGMqnCLSuIgp3fjrK177m9fgfb/0cde7wgp4XVKvnRoLu1XcMamaHWxeSO+VoAdihjqOkQbnv8IrfpPnrpA2lubo=" Jan 26 22:38:18 volumio go-librespot[5163]: time="2026-01-26T22:38:18+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 26 22:38:18 volumio volumio[4803]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Jan 26 22:38:18 volumio go-librespot[5163]: time="2026-01-26T22:38:18+07:00" level=debug msg="completed keyexchange" Jan 26 22:38:18 volumio go-librespot[5163]: time="2026-01-26T22:38:18+07:00" level=debug msg="completed challenge" Jan 26 22:38:18 volumio go-librespot[5163]: time="2026-01-26T22:38:18+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 26 22:38:18 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 26 22:38:18 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 26 22:38:18 volumio volumio[4803]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 26 22:38:18 volumio volumio[4803]: Error: socket hang up Jan 26 22:38:18 volumio volumio[4803]: at connResetException (node:internal/errors:720:14) Jan 26 22:38:18 volumio volumio[4803]: at Socket.socketOnEnd (node:_http_client:519:23) Jan 26 22:38:18 volumio volumio[4803]: at Socket.emit (node:events:526:35) Jan 26 22:38:18 volumio volumio[4803]: at endReadableNT (node:internal/streams/readable:1376:12) Jan 26 22:38:18 volumio volumio[4803]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Jan 26 22:38:18 volumio volumio[4803]: code: 'ECONNRESET', Jan 26 22:38:18 volumio volumio[4803]: response: undefined Jan 26 22:38:18 volumio volumio[4803]: } Jan 26 22:38:18 volumio volumio[4803]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 26 22:38:18 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 22:38:18 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 22:38:18 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 22:38:20 volumio sudo[5191]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-01-26 22:37' Jan 26 22:38:20 volumio sudo[5191]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 22:38:20 volumio sudo[5191]: pam_unix(sudo:session): session closed for user root Jan 26 22:38:20 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 22:38:20 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 22:38:20 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 22:38:21 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 23. Jan 26 22:38:21 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 26 22:38:22 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 26 22:38:22 volumio go-librespot[5199]: go-librespot daemon starting... Jan 26 22:38:22 volumio volumio-remote-updater[628]: [2026-01-26 22:38:22] [error] handle_read_frame error: asio.system:104 (Connection reset by peer) Jan 26 22:38:22 volumio volumio-remote-updater[628]: [2026-01-26 22:38:22] [disconnect] Disconnect close local:[1006,Connection reset by peer] remote:[1006] Jan 26 22:38:22 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Jan 26 22:38:22 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Jan 26 22:38:22 volumio systemd[1]: volumio.service: Consumed 1min 10.719s CPU time. Jan 26 22:38:22 volumio go-librespot[5200]: time="2026-01-26T22:38:22+07:00" level=info msg="running go-librespot 0.4.0" Jan 26 22:38:22 volumio go-librespot[5200]: time="2026-01-26T22:38:22+07:00" level=debug msg="app state loaded" Jan 26 22:38:22 volumio go-librespot[5200]: time="2026-01-26T22:38:22+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 26 22:38:22 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 26 22:38:22 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Jan 26 22:38:22 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 7644. Jan 26 22:38:22 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 26 22:38:22 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Jan 26 22:38:22 volumio systemd[1]: volumio.service: Consumed 1min 10.719s CPU time. Jan 26 22:38:22 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Jan 26 22:38:22 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Jan 26 22:38:22 volumio go-librespot[5200]: time="2026-01-26T22:38:22+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 26 22:38:22 volumio go-librespot[5200]: time="2026-01-26T22:38:22+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 26 22:38:22 volumio go-librespot[5200]: time="2026-01-26T22:38:22+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 26 22:38:22 volumio go-librespot[5200]: time="2026-01-26T22:38:22+07:00" level=info msg="zeroconf server listening on port 43221" Jan 26 22:38:22 volumio go-librespot[5200]: time="2026-01-26T22:38:22+07:00" level=debug msg="obtained new client token: AAB7tzsvxNvpODQwCrMEwPeW1YPZPOX8s9W5/OOrgyUe0jiItSR60qOkut0lYEwnOf4ANyRoJ3eNacQcwKgCkxXRi3FlKpCAYDMCJ0vSZslxuL/96gSyY9yyVHqGikr7d9KTXoh9d4AmU6A38OUdTcJsBHp6JVGIYC+o54xZ3cTxmdLIJyhCglyFDuKWqfIqBovefeIY82QBY86CrXWijPr+YdhrF8ui2QjZDlBnR/mmBKjDAXYT7erb11Q=" Jan 26 22:38:22 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 22:38:22 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 22:38:22 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 22:38:23 volumio go-librespot[5200]: time="2026-01-26T22:38:23+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 26 22:38:23 volumio go-librespot[5200]: time="2026-01-26T22:38:23+07:00" level=debug msg="completed keyexchange" Jan 26 22:38:23 volumio go-librespot[5200]: time="2026-01-26T22:38:23+07:00" level=debug msg="completed challenge" Jan 26 22:38:23 volumio go-librespot[5200]: time="2026-01-26T22:38: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 26 22:38:23 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 26 22:38:23 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 26 22:38:24 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 22:38:24 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 22:38:24 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 22:38:26 volumio volumio[5218]: info: ------------------------------------------- Jan 26 22:38:26 volumio volumio[5218]: info: ----- Volumio3 ---- Jan 26 22:38:26 volumio volumio[5218]: info: ------------------------------------------- Jan 26 22:38:26 volumio volumio[5218]: info: ----- System startup ---- Jan 26 22:38:26 volumio volumio[5218]: info: ------------------------------------------- Jan 26 22:38:26 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 24. Jan 26 22:38:26 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 26 22:38:26 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 26 22:38:26 volumio go-librespot[5239]: go-librespot daemon starting... Jan 26 22:38:26 volumio go-librespot[5240]: time="2026-01-26T22:38:26+07:00" level=info msg="running go-librespot 0.4.0" Jan 26 22:38:26 volumio go-librespot[5240]: time="2026-01-26T22:38:26+07:00" level=debug msg="app state loaded" Jan 26 22:38:26 volumio go-librespot[5240]: time="2026-01-26T22:38:26+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 26 22:38:26 volumio go-librespot[5240]: time="2026-01-26T22:38:26+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 26 22:38:26 volumio go-librespot[5240]: time="2026-01-26T22:38:26+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 26 22:38:26 volumio go-librespot[5240]: time="2026-01-26T22:38:26+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 26 22:38:26 volumio go-librespot[5240]: time="2026-01-26T22:38:26+07:00" level=info msg="zeroconf server listening on port 38557" Jan 26 22:38:26 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 22:38:26 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 22:38:26 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 22:38:27 volumio volumio-remote-updater[628]: [2026-01-26 22:38:27] [connect] Successful connection Jan 26 22:38:27 volumio go-librespot[5240]: time="2026-01-26T22:38:27+07:00" level=debug msg="obtained new client token: AADOsBAzaMCdnueS799KDykbzdX2aGLhtqF5AUXxNpjcX892CqbPj6UgLx/lGQ3MEbafEvDrsRAvY7R0bVPlMZSfiWU31g+ONT6mpHmSz+fJwSPeb4Tk9A+cnEgDcxElBtzeV+CzlDEebdKoZ4wC3+ZGUQ/yvCJH2wCYmThQTNIHI7zxTOTGVF66Bpkb9DDZKlaNZwaAHARUPYXU7rZ1hYPn1trp2Xk/rRRkrQ1uunmzuxsj0xsR4zlt" Jan 26 22:38:27 volumio go-librespot[5240]: time="2026-01-26T22:38:27+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 26 22:38:27 volumio go-librespot[5240]: time="2026-01-26T22:38:27+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Jan 26 22:38:27 volumio go-librespot[5240]: time="2026-01-26T22:38:27+07:00" level=debug msg="completed keyexchange" Jan 26 22:38:27 volumio go-librespot[5240]: time="2026-01-26T22:38:27+07:00" level=debug msg="completed challenge" Jan 26 22:38:27 volumio go-librespot[5240]: time="2026-01-26T22:38: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 26 22:38:27 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 26 22:38:27 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 26 22:38:27 volumio volumio[5218]: info: MYVOLUMIO Environment detected Jan 26 22:38:27 volumio volumio[5218]: info: Plugin folders cleanup Jan 26 22:38:27 volumio volumio[5218]: info: Scanning into folder /volumio/app/plugins/ Jan 26 22:38:27 volumio volumio[5218]: info: Scanning category audio_interface Jan 26 22:38:27 volumio volumio[5218]: info: Scanning category miscellanea Jan 26 22:38:27 volumio volumio[5218]: info: Scanning category music_service Jan 26 22:38:27 volumio volumio[5218]: info: Scanning category plugins.json Jan 26 22:38:27 volumio volumio[5218]: info: Scanning category system_controller Jan 26 22:38:27 volumio volumio[5218]: info: Scanning category user_interface Jan 26 22:38:27 volumio volumio[5218]: info: Scanning into folder /data/plugins/ Jan 26 22:38:27 volumio volumio[5218]: info: Scanning category music_service Jan 26 22:38:27 volumio volumio[5218]: info: Plugin folders cleanup completed Jan 26 22:38:27 volumio volumio[5218]: info: ------------------------------------------- Jan 26 22:38:27 volumio volumio[5218]: info: ----- Core plugins startup ---- Jan 26 22:38:27 volumio volumio[5218]: info: ------------------------------------------- Jan 26 22:38:27 volumio volumio[5218]: info: Loading plugins from folder /volumio/app/plugins/ Jan 26 22:38:27 volumio volumio[5218]: info: Adding plugin upnp to MyMusic Plugins Jan 26 22:38:27 volumio volumio[5218]: info: Adding plugin airplay_emulation to MyMusic Plugins Jan 26 22:38:27 volumio volumio[5218]: info: Adding plugin upnp_browser to MyMusic Plugins Jan 26 22:38:27 volumio volumio[5218]: info: Loading plugins from folder /data/plugins/ Jan 26 22:38:27 volumio volumio[5218]: info: Loading plugin "system"... Jan 26 22:38:27 volumio volumio[5218]: info: Loading plugin "appearance"... Jan 26 22:38:28 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 22:38:28 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 22:38:28 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 22:38:29 volumio volumio[5218]: info: Loading plugin "network"... Jan 26 22:38:29 volumio volumio[5218]: info: Refreshing Cached IP Addresses Jan 26 22:38:29 volumio sudo[5254]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 26 22:38:29 volumio sudo[5254]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 22:38:29 volumio sudo[5256]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 26 22:38:29 volumio sudo[5256]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 22:38:29 volumio sudo[5254]: pam_unix(sudo:session): session closed for user root Jan 26 22:38:29 volumio volumio[5218]: info: Loading plugin "services"... Jan 26 22:38:29 volumio sudo[5256]: pam_unix(sudo:session): session closed for user root Jan 26 22:38:29 volumio volumio[5218]: info: Loading plugin "alsa_controller"... Jan 26 22:38:29 volumio sudo[5268]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Jan 26 22:38:29 volumio sudo[5268]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 22:38:29 volumio volumio[5218]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 26 22:38:29 volumio volumio[5218]: info: Loading plugin "wizard"... Jan 26 22:38:29 volumio volumio[5218]: info: Loading plugin "networkfs"... Jan 26 22:38:30 volumio volumio[5218]: info: Starting Udev Watcher for removable devices Jan 26 22:38:30 volumio volumio[5218]: info: Ignoring mount for partition: boot Jan 26 22:38:30 volumio volumio[5218]: info: Ignoring mount for partition: volumio Jan 26 22:38:30 volumio volumio[5218]: info: Ignoring mount for partition: volumio_data Jan 26 22:38:30 volumio volumio[5218]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 26 22:38:30 volumio volumio[5218]: info: Loading plugin "volumio_command_line_client"... Jan 26 22:38:30 volumio volumio[5218]: info: Loading plugin "upnp"... Jan 26 22:38:30 volumio volumio[5218]: info: [1769441910122] Starting Upmpd Daemon Jan 26 22:38:30 volumio volumio[5218]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 26 22:38:30 volumio volumio[5218]: info: Loading plugin "my_music"... Jan 26 22:38:30 volumio volumio[5218]: info: Loading plugin "mpd"... Jan 26 22:38:30 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 25. Jan 26 22:38:30 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 26 22:38:30 volumio volumio[5218]: info: Loading plugin "upnp_browser"... Jan 26 22:38:30 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 26 22:38:30 volumio go-librespot[5287]: go-librespot daemon starting... Jan 26 22:38:30 volumio go-librespot[5288]: time="2026-01-26T22:38:30+07:00" level=info msg="running go-librespot 0.4.0" Jan 26 22:38:30 volumio go-librespot[5288]: time="2026-01-26T22:38:30+07:00" level=debug msg="app state loaded" Jan 26 22:38:30 volumio go-librespot[5288]: time="2026-01-26T22:38:30+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 26 22:38:31 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 22:38:31 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 22:38:31 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 22:38:31 volumio go-librespot[5288]: time="2026-01-26T22:38:31+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 26 22:38:31 volumio go-librespot[5288]: time="2026-01-26T22:38:31+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 26 22:38:31 volumio go-librespot[5288]: time="2026-01-26T22:38:31+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 26 22:38:31 volumio go-librespot[5288]: time="2026-01-26T22:38:31+07:00" level=info msg="zeroconf server listening on port 45575" Jan 26 22:38:31 volumio go-librespot[5288]: time="2026-01-26T22:38:31+07:00" level=debug msg="obtained new client token: AAAg7abgtrdXlT8LhC4Huc4kLNW/xvl2t7xelijD1TTzamPrKS9vG/6CkWzctFyI3ClADIIwhT+c2JTk7gGNVojv7+CwQbDgyVujW+jsBo92ScTYLmQ9BzR8Owd5UADETXl+KgoDjonZO7rK3kz7gQKyZ1KdztEyAnollFPxI+SyfiJLeKX1yXn0flxS2Wxnyf9QKEU79Vs9WY1bP05QE3xcwpDRJyb39gei99YArP+ZdLw6vdp58Ebljk0=" Jan 26 22:38:31 volumio go-librespot[5288]: time="2026-01-26T22:38:31+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 26 22:38:31 volumio go-librespot[5288]: time="2026-01-26T22:38:31+07:00" level=debug msg="completed keyexchange" Jan 26 22:38:31 volumio go-librespot[5288]: time="2026-01-26T22:38:31+07:00" level=debug msg="completed challenge" Jan 26 22:38:31 volumio go-librespot[5288]: time="2026-01-26T22:38:31+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 26 22:38:31 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 26 22:38:31 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 26 22:38:32 volumio sudo[5268]: pam_unix(sudo:session): session closed for user root Jan 26 22:38:33 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 22:38:33 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 22:38:33 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 22:38:33 volumio volumio[5218]: info: Starting UPNP Browser Jan 26 22:38:33 volumio volumio[5218]: info: Loading plugin "alarm-clock"... Jan 26 22:38:34 volumio volumio[5218]: info: Loading plugin "airplay_emulation"... Jan 26 22:38:34 volumio volumio[5218]: info: Starting Shairport Sync Jan 26 22:38:34 volumio volumio[5218]: info: Loading plugin "last_100"... Jan 26 22:38:34 volumio volumio[5218]: info: Loading plugin "webradio"... Jan 26 22:38:34 volumio volumio[5218]: info: Loading plugin "i2s_dacs"... Jan 26 22:38:34 volumio volumio[5218]: info: Loading plugin "volumiodiscovery"... Jan 26 22:38:34 volumio volumio[5218]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 26 22:38:34 volumio volumio[5218]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 26 22:38:34 volumio node[5218]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 26 22:38:34 volumio volumio[5218]: *** WARNING *** For more information see Jan 26 22:38:34 volumio volumio[5218]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 26 22:38:34 volumio volumio[5218]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 26 22:38:34 volumio volumio[5218]: *** WARNING *** For more information see Jan 26 22:38:34 volumio node[5218]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 26 22:38:34 volumio node[5218]: *** WARNING *** For more information see Jan 26 22:38:34 volumio node[5218]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 26 22:38:34 volumio node[5218]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 26 22:38:34 volumio node[5218]: *** WARNING *** For more information see Jan 26 22:38:34 volumio volumio[5218]: info: Applying required configuration parameters for plugin volumiodiscovery Jan 26 22:38:34 volumio volumio[5218]: info: Discovery: Started advertising with name: Volumio Jan 26 22:38:34 volumio volumio[5218]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 26 22:38:34 volumio volumio[5218]: info: Loading plugin "spop"... Jan 26 22:38:34 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 26. Jan 26 22:38:34 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 26 22:38:35 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 22:38:35 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 22:38:35 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 22:38:35 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 26 22:38:35 volumio go-librespot[5297]: go-librespot daemon starting... Jan 26 22:38:35 volumio go-librespot[5298]: time="2026-01-26T22:38:35+07:00" level=info msg="running go-librespot 0.4.0" Jan 26 22:38:35 volumio go-librespot[5298]: time="2026-01-26T22:38:35+07:00" level=debug msg="app state loaded" Jan 26 22:38:35 volumio go-librespot[5298]: time="2026-01-26T22:38:35+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 26 22:38:35 volumio go-librespot[5298]: time="2026-01-26T22:38:35+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 26 22:38:35 volumio go-librespot[5298]: time="2026-01-26T22:38:35+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 26 22:38:35 volumio go-librespot[5298]: time="2026-01-26T22:38:35+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 26 22:38:35 volumio go-librespot[5298]: time="2026-01-26T22:38:35+07:00" level=info msg="zeroconf server listening on port 37303" Jan 26 22:38:35 volumio go-librespot[5298]: time="2026-01-26T22:38:35+07:00" level=debug msg="obtained new client token: AACd1oh9R34CJJNRSJQIC6MAL2dpW7n9VmCzdbtzn6DFP/syRfpPX66bV1o8ImG+gzXI0vBit/xSPJl/wuhRviP54IpkLGYftAkwapLB52mLgniHTD3wvIs4wu/5NBn86NXgfxSFNN3/SXPuOyPWRHzt+X5gcUQP7L9pG5QY2M8aXLEMkWpgWMOEquw/KFcvXl7g5LQBi8nqRP4R/+S+Ewvg/HZAFQVr0GjS3b0wO8nrk5GbASTvrRudTV8=" Jan 26 22:38:35 volumio go-librespot[5298]: time="2026-01-26T22:38:35+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 26 22:38:36 volumio go-librespot[5298]: time="2026-01-26T22:38:36+07:00" level=debug msg="completed keyexchange" Jan 26 22:38:36 volumio go-librespot[5298]: time="2026-01-26T22:38:36+07:00" level=debug msg="completed challenge" Jan 26 22:38:36 volumio go-librespot[5298]: time="2026-01-26T22:38:36+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 26 22:38:36 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 26 22:38:36 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 26 22:38:36 volumio volumio[5218]: info: Loading plugin "ytcr"... Jan 26 22:38:37 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 22:38:37 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 22:38:37 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 22:38:39 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 22:38:39 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 22:38:39 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 22:38:39 volumio volumio[5218]: info: Loading plugin "ytmusic"... Jan 26 22:38:39 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 27. Jan 26 22:38:39 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 26 22:38:39 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 26 22:38:39 volumio go-librespot[5305]: go-librespot daemon starting... Jan 26 22:38:39 volumio go-librespot[5306]: time="2026-01-26T22:38:39+07:00" level=info msg="running go-librespot 0.4.0" Jan 26 22:38:39 volumio go-librespot[5306]: time="2026-01-26T22:38:39+07:00" level=debug msg="app state loaded" Jan 26 22:38:39 volumio go-librespot[5306]: time="2026-01-26T22:38:39+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 26 22:38:39 volumio volumio-remote-updater[628]: [2026-01-26 22:38:39] [connect] Successful connection Jan 26 22:38:39 volumio go-librespot[5306]: time="2026-01-26T22:38:39+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 26 22:38:39 volumio go-librespot[5306]: time="2026-01-26T22:38:39+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 26 22:38:39 volumio go-librespot[5306]: time="2026-01-26T22:38:39+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 26 22:38:39 volumio go-librespot[5306]: time="2026-01-26T22:38:39+07:00" level=info msg="zeroconf server listening on port 44769" Jan 26 22:38:40 volumio volumio[5218]: info: Loading plugin "outputs"... Jan 26 22:38:40 volumio go-librespot[5306]: time="2026-01-26T22:38:40+07:00" level=debug msg="obtained new client token: AADPH9681+mUyc10n4EAPbke0iggNn7R1AM+cSZj1eLNpt3FbFRjN0S7lWjgoS+dR8D7l7qmJ+oOb+8ksSTPaGY6RUVU9f3aXB1Lcy0e1gYz+fN8HRaTHVdTiO5kDRU06q84gAyZ/K3+SJS/YwMdXSyKFVy6mhzkbHKyTJC3h9bhZbQjGWI/y31INe2tDqSL4g8YpUhUW3y0wGtCptp4ssRjBcdOe7nAs89pUlUoSsziYbMjNo6jnRx9" Jan 26 22:38:40 volumio volumio[5218]: info: Loading plugin "albumart"... Jan 26 22:38:40 volumio volumio[5218]: info: Plugin example_plugin is not enabled Jan 26 22:38:40 volumio volumio[5218]: info: Loading plugin "inputs"... Jan 26 22:38:40 volumio volumio[5218]: info: Loading plugin "updater_comm"... Jan 26 22:38:40 volumio go-librespot[5306]: time="2026-01-26T22:38:40+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 26 22:38:40 volumio go-librespot[5306]: time="2026-01-26T22:38:40+07:00" level=debug msg="completed keyexchange" Jan 26 22:38:40 volumio go-librespot[5306]: time="2026-01-26T22:38:40+07:00" level=debug msg="completed challenge" Jan 26 22:38:40 volumio volumio[5218]: info: Plugin mpdemulation is not enabled Jan 26 22:38:40 volumio volumio[5218]: info: Loading plugin "rest_api"... Jan 26 22:38:40 volumio volumio[5218]: info: Loading plugin "websocket"... Jan 26 22:38:40 volumio go-librespot[5306]: time="2026-01-26T22:38:40+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 26 22:38:40 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 26 22:38:40 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 26 22:38:40 volumio volumio[5218]: info: Starting Socket.io Server version 1.7.4 Jan 26 22:38:40 volumio volumio[5218]: info: Loading plugin "RoonBridge"... Jan 26 22:38:41 volumio volumio[5218]: info: Applying required configuration parameters for plugin RoonBridge Jan 26 22:38:41 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 22:38:41 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 22:38:41 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 22:38:41 volumio volumio[5218]: info: Loading i18n strings for locale en Jan 26 22:38:41 volumio volumio[5218]: Updating browse sources language Jan 26 22:38:41 volumio volumio[5218]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 26 22:38:41 volumio volumio[5328]: Forking 3 albumart workers Jan 26 22:38:41 volumio volumio[5218]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 26 22:38:41 volumio volumio[5218]: info: CoreCommandRouter::initPlayerControls Jan 26 22:38:41 volumio volumio[5218]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 22:38:41 volumio volumio[5218]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 22:38:41 volumio volumio[5218]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 22:38:41 volumio volumio[5218]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 22:38:41 volumio volumio[5218]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 22:38:41 volumio volumio[5218]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 22:38:41 volumio volumio[5218]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 22:38:41 volumio volumio[5218]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 22:38:41 volumio volumio[5218]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 26 22:38:41 volumio volumio[5218]: Express server listening on port 3000 Jan 26 22:38:41 volumio volumio[5218]: [Metrics] WebUI: 16s 136.50ms Jan 26 22:38:41 volumio volumio[5218]: info: CoreStateMachine::resetVolumioState Jan 26 22:38:41 volumio volumio[5218]: info: CoreStateMachine::getcurrentVolume Jan 26 22:38:41 volumio volumio[5218]: info: CoreCommandRouter::volumioRetrievevolume Jan 26 22:38:41 volumio sudo[5373]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 26 22:38:41 volumio sudo[5373]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 22:38:41 volumio sudo[5373]: pam_unix(sudo:session): session closed for user root Jan 26 22:38:41 volumio sudo[5375]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 26 22:38:41 volumio sudo[5375]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 22:38:41 volumio volumio[5218]: info: Volumio Network Manager: Network status updated: 1 Jan 26 22:38:41 volumio sudo[5375]: pam_unix(sudo:session): session closed for user root Jan 26 22:38:41 volumio volumio[5218]: info: VolumeController:: Volume=100 Mute =false Jan 26 22:38:41 volumio volumio[5218]: info: CoreStateMachine::pushState Jan 26 22:38:41 volumio volumio[5218]: info: CorePlayQueue::getTrack 0 Jan 26 22:38:41 volumio volumio[5218]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 26 22:38:41 volumio volumio[5218]: info: CoreCommandRouter::volumioPushState Jan 26 22:38:41 volumio volumio[5218]: info: CoreStateMachine::updateTrackBlock Jan 26 22:38:42 volumio volumio[5218]: info: CorePlayQueue::getTrackBlock Jan 26 22:38:42 volumio volumio[5218]: info: CoreCommandRouter::volumioRetrievevolume Jan 26 22:38:42 volumio volumio-remote-updater[628]: [2026-01-26 22:38:42] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1769441919 101 Jan 26 22:38:42 volumio volumio[5218]: 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 26 22:38:42 volumio volumio[5218]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 22:38:42 volumio volumio[5218]: info: Reloading queue from file Jan 26 22:38:42 volumio volumio[5218]: info: CoreStateMachine::setRepeat null single undefined Jan 26 22:38:42 volumio volumio[5218]: info: CoreStateMachine::pushState Jan 26 22:38:42 volumio volumio[5218]: info: CorePlayQueue::getTrack 0 Jan 26 22:38:42 volumio volumio[5218]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 26 22:38:42 volumio volumio[5218]: info: CoreCommandRouter::volumioPushState Jan 26 22:38:42 volumio volumio[5218]: info: CoreStateMachine::setRandom null Jan 26 22:38:42 volumio volumio[5218]: info: CoreStateMachine::pushState Jan 26 22:38:42 volumio volumio[5218]: info: CorePlayQueue::getTrack 0 Jan 26 22:38:42 volumio volumio[5218]: info: CoreCommandRouter::volumioPushState Jan 26 22:38:42 volumio volumio[5218]: info: Setting Device type: Raspberry PI Jan 26 22:38:42 volumio volumio[5218]: info: Completed loading Core Plugins Jan 26 22:38:42 volumio volumio[5218]: info: Preparing to generate the ALSA configuration file Jan 26 22:38:42 volumio volumio[5218]: info: VolumeController:: Volume=100 Mute =false Jan 26 22:38:42 volumio volumio[5218]: info: CoreStateMachine::pushState Jan 26 22:38:42 volumio volumio[5218]: info: CorePlayQueue::getTrack 0 Jan 26 22:38:42 volumio volumio[5218]: info: CoreCommandRouter::volumioPushState Jan 26 22:38:42 volumio volumio[5218]: info: Asound.conf file unchanged, so no further update is needed Jan 26 22:38:42 volumio volumio[5218]: info: Output device has changed, restarting MPD Jan 26 22:38:42 volumio sudo[5388]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Jan 26 22:38:42 volumio sudo[5388]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 22:38:42 volumio volumio[5218]: info: Output device has changed, restarting Shairport Sync Jan 26 22:38:42 volumio volumio[5218]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 22:38:42 volumio volumio[5218]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 22:38:42 volumio sudo[5390]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 26 22:38:42 volumio sudo[5390]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 22:38:42 volumio sudo[5390]: pam_unix(sudo:session): session closed for user root Jan 26 22:38:42 volumio volumio[5218]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 26 22:38:42 volumio volumio[5218]: info: ___________ START PLUGINS ___________ Jan 26 22:38:42 volumio sudo[5388]: pam_unix(sudo:session): session closed for user root Jan 26 22:38:42 volumio volumio[5218]: info: ControllerMpd::onStart: Initializing MPD Jan 26 22:38:42 volumio volumio[5218]: info: Creating MPD Configuration file Jan 26 22:38:42 volumio sudo[5393]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 26 22:38:42 volumio sudo[5393]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 22:38:42 volumio volumio[5218]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 26 22:38:42 volumio volumio[5218]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 26 22:38:42 volumio volumio[5218]: info: [1769441922819] CoreMusicLibrary::Adding element Media Servers Jan 26 22:38:42 volumio volumio[5218]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 26 22:38:42 volumio volumio[5218]: info: UPNP Browser: Client initialized successfully Jan 26 22:38:42 volumio sudo[5401]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 26 22:38:42 volumio sudo[5401]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 22:38:42 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Jan 26 22:38:42 volumio sudo[5401]: pam_unix(sudo:session): session closed for user root Jan 26 22:38:42 volumio volumio[5218]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 22:38:42 volumio volumio[5218]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 22:38:42 volumio sudo[5403]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 26 22:38:42 volumio sudo[5403]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 22:38:42 volumio volumio[5218]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 26 22:38:42 volumio volumio[5218]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 22:38:42 volumio volumio[5218]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 22:38:43 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 26 22:38:43 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 26 22:38:43 volumio systemd[1]: mpd.service: Consumed 7.237s CPU time. Jan 26 22:38:43 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 26 22:38:43 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 22:38:43 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 22:38:43 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 22:38:43 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 26 22:38:43 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 26 22:38:43 volumio volumio[5218]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 26 22:38:43 volumio volumio[5218]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 26 22:38:43 volumio volumio[5218]: info: [1769441923046] CoreMusicLibrary::Adding element Last_100 Jan 26 22:38:43 volumio volumio[5218]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 26 22:38:43 volumio volumio[5218]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 26 22:38:43 volumio volumio[5218]: info: [1769441923057] CoreMusicLibrary::Adding element Webradio Jan 26 22:38:43 volumio volumio[5218]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 26 22:38:43 volumio volumio[5218]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 26 22:38:43 volumio volumio[5218]: info: Initializing BBC Radios Jan 26 22:38:43 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 26 22:38:43 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 26 22:38:43 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 26 22:38:43 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 26 22:38:43 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 26 22:38:43 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 26 22:38:43 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 26 22:38:43 volumio volumio[5218]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 26 22:38:43 volumio volumio[5218]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 22:38:43 volumio volumio[5218]: info: Creating Spotify config file Jan 26 22:38:43 volumio volumio[5218]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 22:38:43 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 26 22:38:43 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 26 22:38:43 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 28. Jan 26 22:38:43 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 26 22:38:43 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 26 22:38:43 volumio go-librespot[5431]: go-librespot daemon starting... Jan 26 22:38:43 volumio go-librespot[5432]: time="2026-01-26T22:38:43+07:00" level=info msg="running go-librespot 0.4.0" Jan 26 22:38:43 volumio sudo[5430]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 26 22:38:43 volumio sudo[5430]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jan 26 22:38:43 volumio sudo[5430]: pam_unix(sudo:session): session closed for user root Jan 26 22:38:44 volumio go-librespot[5432]: time="2026-01-26T22:38:44+07:00" level=info msg="zeroconf server listening on port 34207" Jan 26 22:38:44 volumio volumio[5338]: Starting albumart workers Jan 26 22:38:44 volumio volumio[5339]: Starting albumart workers Jan 26 22:38:44 volumio volumio[5340]: Starting albumart workers Jan 26 22:38:44 volumio volumio[5218]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 26 22:38:44 volumio volumio[5218]: info: [1769441924774] CoreMusicLibrary::Adding element YouTube Music Jan 26 22:38:44 volumio volumio[5218]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 26 22:38:44 volumio volumio[5218]: Cannot find translation for source YouTube Music Jan 26 22:38:44 volumio volumio[5218]: info: Volumio Calling Home Jan 26 22:38:44 volumio sudo[5443]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Jan 26 22:38:44 volumio sudo[5443]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 22:38:45 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 22:38:45 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 22:38:45 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 22:38:45 volumio sudo[5443]: pam_unix(sudo:session): session closed for user root Jan 26 22:38:45 volumio volumio[5218]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Jan 26 22:38:45 volumio volumio[5218]: info: Discovery: Found device Volumio Jan 26 22:38:45 volumio volumio[5218]: info: CoreCommandRouter::volumioGetState Jan 26 22:38:45 volumio volumio[5218]: info: CorePlayQueue::getTrack 0 Jan 26 22:38:45 volumio volumio[5218]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Jan 26 22:38:45 volumio volumio[5218]: info: Discovery: Found device Volumio Jan 26 22:38:45 volumio volumio[5218]: info: CoreCommandRouter::volumioGetState Jan 26 22:38:45 volumio volumio[5218]: info: CorePlayQueue::getTrack 0 Jan 26 22:38:45 volumio volumio[5218]: info: MPD Permissions set Jan 26 22:38:45 volumio volumio[5218]: info: MPD Permissions set Jan 26 22:38:45 volumio volumio[5218]: info: Upmpdcli Daemon Started Jan 26 22:38:45 volumio volumio[5218]: info: Volumio called home Jan 26 22:38:45 volumio volumio[5218]: info: Spotify config file written Jan 26 22:38:46 volumio sudo[5449]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jan 26 22:38:46 volumio sudo[5449]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 22:38:46 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Jan 26 22:38:46 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Jan 26 22:38:46 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 26 22:38:46 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 26 22:38:46 volumio go-librespot[5451]: go-librespot daemon starting... Jan 26 22:38:46 volumio sudo[5449]: pam_unix(sudo:session): session closed for user root Jan 26 22:38:46 volumio go-librespot[5453]: time="2026-01-26T22:38:46+07:00" level=info msg="running go-librespot 0.4.0" Jan 26 22:38:46 volumio go-librespot[5453]: time="2026-01-26T22:38:46+07:00" level=debug msg="app state loaded" Jan 26 22:38:46 volumio go-librespot[5453]: time="2026-01-26T22:38:46+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 26 22:38:46 volumio volumio[5218]: 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 26 22:38:46 volumio volumio[5218]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 22:38:46 volumio volumio[5218]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 22:38:46 volumio volumio[5218]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 22:38:46 volumio volumio[5218]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 22:38:46 volumio volumio[5218]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 22:38:46 volumio volumio[5218]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 22:38:46 volumio volumio[5218]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 22:38:46 volumio volumio[5218]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 22:38:46 volumio volumio[5218]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 22:38:46 volumio volumio[5218]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 22:38:46 volumio volumio[5218]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 22:38:46 volumio volumio[5218]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 22:38:46 volumio volumio[5218]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 22:38:46 volumio volumio[5218]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 22:38:46 volumio volumio[5218]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 22:38:46 volumio volumio[5218]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 22:38:46 volumio volumio[5218]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 22:38:46 volumio volumio[5218]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 22:38:46 volumio volumio[5218]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 22:38:46 volumio volumio[5218]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 22:38:46 volumio volumio[5218]: info: No need to fix Spotify hosts Jan 26 22:38:47 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 22:38:47 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 22:38:47 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 22:38:47 volumio go-librespot[5453]: time="2026-01-26T22:38:47+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 26 22:38:47 volumio go-librespot[5453]: time="2026-01-26T22:38:47+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 26 22:38:47 volumio go-librespot[5453]: time="2026-01-26T22:38:47+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 26 22:38:47 volumio go-librespot[5453]: time="2026-01-26T22:38:47+07:00" level=info msg="zeroconf server listening on port 43427" Jan 26 22:38:47 volumio go-librespot[5453]: time="2026-01-26T22:38:47+07:00" level=debug msg="obtained new client token: AAByoEJfK1Wx3w0L8Ri51NG7XhkA8enVlfeCTXVU7c1zknY08USvE9XdhnLhJzMIS7/F19AlKLF9p2W8tZ+pIGR7RRGtzwLswhmASaQzRQrHCIDrsgPKrzn4tv2lIDGrtzlzL4PdM/9sH0cuJgwXRVQjufo2tO1uWrF1dfWyUIGwefdBbp1wHeoSPOk4KWxmPv2pths9EenlyCrCHFZ2dVBSyHvSNfOpqWYsgL7zs8+gcrh8XldA9rImKgo=" Jan 26 22:38:47 volumio volumio[5218]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 26 22:38:47 volumio volumio[5218]: SPOTIFY: BQBTP2VUwGylIfzbXN90DUKv4tp36NrUiJNpb9o49nuZbLsM9GlkVefwy60532PRDp-2Vfk6oUujwrocFDDBYiRclgmE43z8qhHy5cEgh2qeOsIehhHlR-YkaBCkarhwivQpzHZZKicwHauJskE5MPxD_PJNX-y09_4xNmQlO3Cme-IZ3_mOM8CqLhAFaldmTj0SJ-IakIlhRJA6VlDQUeqIRby5s0UU4N0oWwd4ZqCR_Q5eGJRraPCZJIu9OSHRC1kU0rAn-4cm7MC7PbCP7b-8SXigZY-J4sh_auid55hsHYg6x3o6o558 Jan 26 22:38:47 volumio volumio[5218]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 26 22:38:47 volumio volumio[5218]: info: New Spotify access token = BQBTP2VUwGylIfzbXN90DUKv4tp36NrUiJNpb9o49nuZbLsM9GlkVefwy60532PRDp-2Vfk6oUujwrocFDDBYiRclgmE43z8qhHy5cEgh2qeOsIehhHlR-YkaBCkarhwivQpzHZZKicwHauJskE5MPxD_PJNX-y09_4xNmQlO3Cme-IZ3_mOM8CqLhAFaldmTj0SJ-IakIlhRJA6VlDQUeqIRby5s0UU4N0oWwd4ZqCR_Q5eGJRraPCZJIu9OSHRC1kU0rAn-4cm7MC7PbCP7b-8SXigZY-J4sh_auid55hsHYg6x3o6o558 Jan 26 22:38:47 volumio volumio[5218]: info: Spotify credentials grant success - running version from March 24, 2019 Jan 26 22:38:47 volumio go-librespot[5453]: time="2026-01-26T22:38:47+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 26 22:38:47 volumio go-librespot[5453]: time="2026-01-26T22:38:47+07:00" level=debug msg="completed keyexchange" Jan 26 22:38:47 volumio go-librespot[5453]: time="2026-01-26T22:38:47+07:00" level=debug msg="completed challenge" Jan 26 22:38:47 volumio volumio[5218]: info: Starting Shairport Sync Jan 26 22:38:47 volumio volumio[5218]: info: Starting Shairport Sync Jan 26 22:38:47 volumio volumio[5218]: info: Starting Shairport Sync Jan 26 22:38:47 volumio go-librespot[5453]: time="2026-01-26T22:38: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 26 22:38:47 volumio sudo[5489]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 26 22:38:47 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 26 22:38:47 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 26 22:38:47 volumio sudo[5489]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 22:38:47 volumio sudo[5491]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 26 22:38:47 volumio sudo[5491]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 22:38:47 volumio sudo[5493]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 26 22:38:47 volumio sudo[5493]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 22:38:47 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 26 22:38:47 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Jan 26 22:38:47 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 26 22:38:47 volumio systemd[1]: shairport-sync.service: Consumed 2.394s CPU time. Jan 26 22:38:47 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 26 22:38:47 volumio sudo[5489]: pam_unix(sudo:session): session closed for user root Jan 26 22:38:47 volumio sudo[5491]: pam_unix(sudo:session): session closed for user root Jan 26 22:38:48 volumio volumio[5218]: info: Shairport-Sync Started Jan 26 22:38:48 volumio volumio[5218]: Error adding Membership: Error: addMembership EINVAL Jan 26 22:38:48 volumio volumio[5218]: info: CoreCommandRouter::volumioGetState Jan 26 22:38:48 volumio volumio[5218]: info: CorePlayQueue::getTrack 0 Jan 26 22:38:48 volumio volumio[5218]: info: Shairport-Sync Started Jan 26 22:38:48 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 26 22:38:48 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Jan 26 22:38:48 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 26 22:38:48 volumio volumio[5218]: 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 26 22:38:48 volumio volumio[5218]: info: Spotify Successfully logged in Jan 26 22:38:48 volumio volumio[5218]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 26 22:38:48 volumio volumio[5218]: info: [1769441928184] CoreMusicLibrary::Adding element Spotify Jan 26 22:38:48 volumio volumio[5218]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 26 22:38:48 volumio volumio[5218]: Cannot find translation for source YouTube Music Jan 26 22:38:48 volumio volumio[5218]: Cannot find translation for source Spotify Jan 26 22:38:48 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 26 22:38:48 volumio sudo[5493]: pam_unix(sudo:session): session closed for user root Jan 26 22:38:48 volumio volumio[5218]: info: Shairport-Sync Started Jan 26 22:38:48 volumio volumio[5218]: info: [yt-cast-receiver] DIAL server listening on port 8098 Jan 26 22:38:48 volumio volumio[5218]: info: CoreCommandRouter::volumioRetrievevolume Jan 26 22:38:49 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 22:38:49 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 22:38:49 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 22:38:49 volumio volumio[5218]: info: VolumeController:: Volume=100 Mute =false Jan 26 22:38:49 volumio volumio[5218]: info: CoreCommandRouter::volumioGetState Jan 26 22:38:49 volumio volumio[5218]: info: CorePlayQueue::getTrack 0 Jan 26 22:38:49 volumio volumio[5218]: info: CoreStateMachine::pushState Jan 26 22:38:49 volumio volumio[5218]: info: CorePlayQueue::getTrack 0 Jan 26 22:38:49 volumio volumio[5218]: info: CoreCommandRouter::volumioPushState Jan 26 22:38:50 volumio volumio[5218]: info: go-librespot daemon successfully initialized Jan 26 22:38:50 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Jan 26 22:38:50 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 26 22:38:50 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 26 22:38:50 volumio go-librespot[5543]: go-librespot daemon starting... Jan 26 22:38:50 volumio go-librespot[5544]: time="2026-01-26T22:38:50+07:00" level=info msg="running go-librespot 0.4.0" Jan 26 22:38:50 volumio go-librespot[5544]: time="2026-01-26T22:38:50+07:00" level=debug msg="app state loaded" Jan 26 22:38:50 volumio go-librespot[5544]: time="2026-01-26T22:38:50+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 26 22:38:51 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 22:38:51 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 22:38:51 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 22:38:51 volumio mpd[5439]: 2026-01-26T22:38:51 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 26 22:38:51 volumio systemd[1]: Started mpd.service - Music Player Daemon. Jan 26 22:38:51 volumio sudo[5393]: pam_unix(sudo:session): session closed for user root Jan 26 22:38:51 volumio sudo[5403]: pam_unix(sudo:session): session closed for user root Jan 26 22:38:51 volumio go-librespot[5544]: time="2026-01-26T22:38:51+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 26 22:38:51 volumio go-librespot[5544]: time="2026-01-26T22:38:51+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 26 22:38:51 volumio go-librespot[5544]: time="2026-01-26T22:38:51+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 26 22:38:51 volumio go-librespot[5544]: time="2026-01-26T22:38:51+07:00" level=info msg="zeroconf server listening on port 44623" Jan 26 22:38:51 volumio volumio[5218]: error: MPD error: The expression evaluated to a falsy value: Jan 26 22:38:51 volumio volumio[5218]: assert.ok(self.idling) Jan 26 22:38:51 volumio volumio[5218]: error: The expression evaluated to a falsy value: Jan 26 22:38:51 volumio volumio[5218]: assert.ok(self.idling) Jan 26 22:38:51 volumio volumio[5218]: error: updateQueue error: null Jan 26 22:38:51 volumio volumio[5218]: info: MPD running with PID5439 Jan 26 22:38:51 volumio volumio[5218]: ,establishing connection Jan 26 22:38:51 volumio volumio[5218]: info: Completed starting Core Plugins Jan 26 22:38:51 volumio volumio[5218]: info: ------------------------------------------- Jan 26 22:38:51 volumio volumio[5218]: info: ----- MyVolumio plugins startup ---- Jan 26 22:38:51 volumio volumio[5218]: info: ------------------------------------------- Jan 26 22:38:51 volumio volumio[5218]: info: [MyVolumio PluginManager] Fetching plans data.... Jan 26 22:38:51 volumio volumio[5218]: error: updateQueue error: null Jan 26 22:38:51 volumio go-librespot[5544]: time="2026-01-26T22:38:51+07:00" level=debug msg="obtained new client token: AAC/gx4/vgB/4tIbYSEkz1u1ZVcMxlzwXN3gPwft9fD2wAdDla6upJRfXcbsxTNcZdnJAPgxtkIEpugTmU2WrxpgbaFxvg9NZ0VJqbSdvqtMUQkY+nnT0mgzKSeG5snsUXIgwivQaSTtQA11p+qSJ44TLxTbCiL9huk4Dc0MFkWPhi7Rs4PnlJIOTbC5tPDo7jqBEoTPvn3C7+ujVotA7Oet1QzR3IV6k09w7fhIrs8eTJtV+30v7K18O4I=" Jan 26 22:38:51 volumio go-librespot[5544]: time="2026-01-26T22:38:51+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 26 22:38:51 volumio go-librespot[5544]: time="2026-01-26T22:38:51+07:00" level=debug msg="completed keyexchange" Jan 26 22:38:51 volumio go-librespot[5544]: time="2026-01-26T22:38:51+07:00" level=debug msg="completed challenge" Jan 26 22:38:52 volumio go-librespot[5544]: time="2026-01-26T22:38:52+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 26 22:38:52 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 26 22:38:52 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 26 22:38:53 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 22:38:53 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 22:38:53 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 22:38:53 volumio volumio[5218]: info: Initializing connection to go-librespot Websocket Jan 26 22:38:53 volumio volumio[5218]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 26 22:38:55 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 22:38:55 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 22:38:55 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 22:38:55 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Jan 26 22:38:55 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 26 22:38:55 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 26 22:38:55 volumio go-librespot[5555]: go-librespot daemon starting... Jan 26 22:38:55 volumio go-librespot[5556]: time="2026-01-26T22:38:55+07:00" level=info msg="running go-librespot 0.4.0" Jan 26 22:38:55 volumio go-librespot[5556]: time="2026-01-26T22:38:55+07:00" level=debug msg="app state loaded" Jan 26 22:38:55 volumio go-librespot[5556]: time="2026-01-26T22:38:55+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 26 22:38:55 volumio go-librespot[5556]: time="2026-01-26T22:38:55+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 26 22:38:55 volumio go-librespot[5556]: time="2026-01-26T22:38:55+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 26 22:38:55 volumio go-librespot[5556]: time="2026-01-26T22:38:55+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 26 22:38:55 volumio go-librespot[5556]: time="2026-01-26T22:38:55+07:00" level=info msg="zeroconf server listening on port 46513" Jan 26 22:38:56 volumio go-librespot[5556]: time="2026-01-26T22:38:56+07:00" level=debug msg="obtained new client token: AAD/nyHQ1CYr9fCWoUXwYzsGJBHa5UPcAYg2RpWj7tCZSQ314yJomM3htQRAikpGYzTr7E6uZPitAFgC/tHBom4LoJuvvq9ElvysXJIanw0mvHpoiHBxD7q1x8Qc6Ho5iRQoZD6/Duxr5Xi2PNwj5aFRfMN4Zw9d1OsiM42Y8ZWAMbtDVnZx/0DBs5Rn0zJCiNUiqBlathp4EoqjvzHUFkncyUDgZui7sbZBiOoTEiGt5kK6lpexk80y" Jan 26 22:38:56 volumio go-librespot[5556]: time="2026-01-26T22:38:56+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 26 22:38:56 volumio volumio[5218]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Jan 26 22:38:56 volumio volumio[5218]: info: Initializing connection to go-librespot Websocket Jan 26 22:38:56 volumio go-librespot[5556]: time="2026-01-26T22:38:56+07:00" level=debug msg="completed keyexchange" Jan 26 22:38:56 volumio go-librespot[5556]: time="2026-01-26T22:38:56+07:00" level=debug msg="completed challenge" Jan 26 22:38:56 volumio go-librespot[5556]: time="2026-01-26T22:38:56+07:00" level=debug msg="new websocket client" Jan 26 22:38:56 volumio volumio[5218]: info: Connection to go-librespot Websocket established Jan 26 22:38:56 volumio go-librespot[5556]: time="2026-01-26T22:38:56+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 26 22:38:56 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 26 22:38:56 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 26 22:38:56 volumio volumio[5218]: info: Connection to go-librespot Websocket closed Jan 26 22:38:57 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 22:38:57 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 22:38:57 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 22:38:59 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 22:38:59 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 22:38:59 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 22:38:59 volumio volumio[5218]: info: Getting Spotify volume Jan 26 22:38:59 volumio volumio[5218]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 26 22:38:59 volumio volumio[5218]: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 26 22:38:59 volumio volumio[5218]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Jan 26 22:38:59 volumio volumio[5218]: errno: -111, Jan 26 22:38:59 volumio volumio[5218]: code: 'ECONNREFUSED', Jan 26 22:38:59 volumio volumio[5218]: syscall: 'connect', Jan 26 22:38:59 volumio volumio[5218]: address: '127.0.0.1', Jan 26 22:38:59 volumio volumio[5218]: port: 9879, Jan 26 22:38:59 volumio volumio[5218]: response: undefined Jan 26 22:38:59 volumio volumio[5218]: } Jan 26 22:38:59 volumio volumio[5218]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 26 22:38:59 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Jan 26 22:38:59 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 26 22:38:59 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 26 22:38:59 volumio go-librespot[5575]: go-librespot daemon starting... Jan 26 22:38:59 volumio go-librespot[5577]: time="2026-01-26T22:38:59+07:00" level=info msg="running go-librespot 0.4.0" Jan 26 22:38:59 volumio go-librespot[5577]: time="2026-01-26T22:38:59+07:00" level=debug msg="app state loaded" Jan 26 22:38:59 volumio go-librespot[5577]: time="2026-01-26T22:38:59+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 26 22:39:00 volumio go-librespot[5577]: time="2026-01-26T22:39:00+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 26 22:39:00 volumio go-librespot[5577]: time="2026-01-26T22:39:00+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 26 22:39:00 volumio go-librespot[5577]: time="2026-01-26T22:39:00+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 26 22:39:00 volumio go-librespot[5577]: time="2026-01-26T22:39:00+07:00" level=info msg="zeroconf server listening on port 41845" Jan 26 22:39:00 volumio go-librespot[5577]: time="2026-01-26T22:39:00+07:00" level=debug msg="obtained new client token: AAAgg6gfQBVEERH4xZJ1SL4vGdsmUW7BEdXobgMjy53KKkBglOSSn1EzZCGYU06gi/PhvdE2wWMIyuiQemk/lMd6HtOuZwjAyqFwg6NKb09W9aANmIp5cQUGDWuOBw0fJQ+Qx+sXvTJOHmzb/AiGdUK2M9qwqD5OSSym+elU3egTasxabi9pCJLu2P/BNQDaw5t415lcLCHatnl6/VYBY4hBB8XxeuM32ElpHXkg6IInJZf9n+uCuWJv0sU=" Jan 26 22:39:00 volumio go-librespot[5577]: time="2026-01-26T22:39:00+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 26 22:39:00 volumio go-librespot[5577]: time="2026-01-26T22:39:00+07:00" level=debug msg="completed keyexchange" Jan 26 22:39:00 volumio go-librespot[5577]: time="2026-01-26T22:39:00+07:00" level=debug msg="completed challenge" Jan 26 22:39:00 volumio go-librespot[5577]: time="2026-01-26T22:39: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 26 22:39:00 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 26 22:39:00 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 26 22:39:01 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 22:39:01 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 22:39:01 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 22:39:01 volumio sudo[5602]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-01-26 22:38' Jan 26 22:39:01 volumio sudo[5602]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) PRETTY_NAME="Raspbian GNU/Linux 12 (bookworm)" NAME="Raspbian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="b05a530ca81d05eb9a84d0acf82089f0a60b8ee6" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="4ad85e2147d972f0b838d33c21382d2d813b2ae8" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu Dec 25 09:13:19 UTC 2025" VOLUMIO_VERSION="4.084" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="792f09af7488531aecd1aadcaa9b175e"