Jan 27 14:14:00 volumio volumio[1162]: 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 27 14:14:00 volumio volumio[1162]: info: Volumio called home Jan 27 14:14:00 volumio volumio[1162]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 14:14:00 volumio volumio[1162]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 14:14:00 volumio volumio[1162]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 14:14:00 volumio volumio[1162]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 14:14:00 volumio volumio[1162]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 14:14:00 volumio volumio[1162]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 14:14:00 volumio volumio[1162]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 14:14:00 volumio volumio[1162]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 14:14:00 volumio sudo[1411]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jan 27 14:14:00 volumio sudo[1411]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 14:14:00 volumio volumio[1162]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 14:14:00 volumio volumio[1162]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 14:14:00 volumio volumio[1162]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 14:14:00 volumio volumio[1162]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 14:14:00 volumio volumio[1162]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 14:14:00 volumio volumio[1162]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 14:14:00 volumio volumio[1162]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 14:14:00 volumio volumio[1162]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 14:14:00 volumio volumio[1162]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 14:14:00 volumio volumio[1162]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 14:14:00 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Jan 27 14:14:00 volumio systemd[1]: go-librespot-daemon.service: Killing process 1397 (go-librespot) with signal SIGKILL. Jan 27 14:14:00 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Jan 27 14:14:00 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 14:14:00 volumio volumio[1162]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 14:14:00 volumio volumio[1162]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 14:14:00 volumio volumio[1162]: info: No need to fix Spotify hosts Jan 27 14:14:00 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 14:14:00 volumio go-librespot[1424]: go-librespot daemon starting... Jan 27 14:14:00 volumio sudo[1411]: pam_unix(sudo:session): session closed for user root Jan 27 14:14:00 volumio go-librespot[1425]: time="2026-01-27T14:14:00+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 14:14:00 volumio go-librespot[1425]: time="2026-01-27T14:14:00+07:00" level=debug msg="app state loaded" Jan 27 14:14:00 volumio go-librespot[1425]: time="2026-01-27T14:14:00+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 14:14:01 volumio go-librespot[1425]: time="2026-01-27T14:14:01+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 27 14:14:01 volumio go-librespot[1425]: time="2026-01-27T14:14:01+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 27 14:14:01 volumio go-librespot[1425]: time="2026-01-27T14:14:01+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 27 14:14:01 volumio go-librespot[1425]: time="2026-01-27T14:14:01+07:00" level=info msg="zeroconf server listening on port 42393" Jan 27 14:14:01 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 14:14:01 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 14:14:01 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 14:14:01 volumio go-librespot[1425]: time="2026-01-27T14:14:01+07:00" level=debug msg="obtained new client token: AACxlMTuMKkJ3duyTtIdfAqBpTe84mJKMPRQRZ94iqHqk/1ImZqZRAAIksX06mR4T/5vg5jr2u64Bwhl7RokVsi77/gYzrERAFXxe2fO5wN/tWdOFlf8+BSkE1zuBecwnRXjPcV1K8cwm/l3Exm0h2BMa3bTRxl3BMAoZn8AAUs5URVDXDahTKbhUpAaOXscEOW/hgPMUslHj/QnZfO9X8UoMvfyHg6piYrnbhymsqIZseMyfyWlJdxC1mI=" Jan 27 14:14:01 volumio volumio[1162]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 27 14:14:01 volumio volumio[1162]: SPOTIFY: BQCT9auXd04b1fknaPN7V2gLomusftar6tTS3Nd-rCx0igh_xUOgFixOJDrZ9qMrNWPk3yQBe7Y21VKVAd4ewXO7F6JdBEQCHJRiKLG5ISdXn5BEvwvnxtky59EpnQkYnwDZN4FI5ql3hU4rYMT3seY_QzcLYTmq6vjrlK4qv0O2UHITwQhMaMbK0SMG9hj2D878p7e8VKk9hl-9NKsfZCABfywFfwr5GWsRu_5mpSPTYgaO8ZI6HqDyIVACoa4_u_vqIN3qWWOXRD3NH18tquiD6Aa_-7Pekqur8lI20UhQiCsRQFqcXVXo Jan 27 14:14:01 volumio volumio[1162]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 27 14:14:01 volumio volumio[1162]: info: New Spotify access token = BQCT9auXd04b1fknaPN7V2gLomusftar6tTS3Nd-rCx0igh_xUOgFixOJDrZ9qMrNWPk3yQBe7Y21VKVAd4ewXO7F6JdBEQCHJRiKLG5ISdXn5BEvwvnxtky59EpnQkYnwDZN4FI5ql3hU4rYMT3seY_QzcLYTmq6vjrlK4qv0O2UHITwQhMaMbK0SMG9hj2D878p7e8VKk9hl-9NKsfZCABfywFfwr5GWsRu_5mpSPTYgaO8ZI6HqDyIVACoa4_u_vqIN3qWWOXRD3NH18tquiD6Aa_-7Pekqur8lI20UhQiCsRQFqcXVXo Jan 27 14:14:01 volumio volumio[1162]: info: Spotify credentials grant success - running version from March 24, 2019 Jan 27 14:14:01 volumio go-librespot[1425]: time="2026-01-27T14:14:01+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 14:14:01 volumio volumio[1162]: info: Starting Shairport Sync Jan 27 14:14:01 volumio go-librespot[1425]: time="2026-01-27T14:14:01+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Jan 27 14:14:01 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 14:14:01 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 14:14:01 volumio volumio[1162]: info: Starting Shairport Sync Jan 27 14:14:01 volumio volumio[1162]: info: Starting Shairport Sync Jan 27 14:14:01 volumio sudo[1446]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 27 14:14:01 volumio sudo[1446]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 14:14:01 volumio sudo[1448]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 27 14:14:01 volumio sudo[1448]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 14:14:01 volumio sudo[1450]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 27 14:14:01 volumio sudo[1450]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 14:14:02 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 27 14:14:02 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Jan 27 14:14:02 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 27 14:14:02 volumio systemd[1]: shairport-sync.service: Consumed 2.539s CPU time. Jan 27 14:14:02 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 27 14:14:02 volumio sudo[1450]: pam_unix(sudo:session): session closed for user root Jan 27 14:14:02 volumio sudo[1448]: pam_unix(sudo:session): session closed for user root Jan 27 14:14:02 volumio sudo[1446]: pam_unix(sudo:session): session closed for user root Jan 27 14:14:02 volumio volumio[1162]: info: Shairport-Sync Started Jan 27 14:14:02 volumio volumio[1162]: Error adding Membership: Error: addMembership EINVAL Jan 27 14:14:02 volumio volumio[1162]: info: Shairport-Sync Started Jan 27 14:14:02 volumio volumio[1162]: info: Shairport-Sync Started Jan 27 14:14:02 volumio volumio[1162]: info: CoreCommandRouter::volumioGetState Jan 27 14:14:02 volumio volumio[1162]: info: CorePlayQueue::getTrack 0 Jan 27 14:14:02 volumio volumio[1162]: 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 27 14:14:02 volumio volumio[1162]: info: Spotify Successfully logged in Jan 27 14:14:02 volumio volumio[1162]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 27 14:14:02 volumio volumio[1162]: info: [1769498042759] CoreMusicLibrary::Adding element Spotify Jan 27 14:14:02 volumio volumio[1162]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 27 14:14:02 volumio volumio[1162]: Cannot find translation for source YouTube Music Jan 27 14:14:02 volumio volumio[1162]: Cannot find translation for source Spotify Jan 27 14:14:03 volumio volumio[1162]: info: [yt-cast-receiver] DIAL server listening on port 8098 Jan 27 14:14:03 volumio volumio[1162]: info: CoreCommandRouter::volumioRetrievevolume Jan 27 14:14:03 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 14:14:03 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 14:14:03 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 14:14:03 volumio volumio[1162]: info: VolumeController:: Volume=100 Mute =false Jan 27 14:14:03 volumio volumio[1162]: info: CoreCommandRouter::volumioGetState Jan 27 14:14:03 volumio volumio[1162]: info: CorePlayQueue::getTrack 0 Jan 27 14:14:03 volumio volumio[1162]: info: CoreStateMachine::pushState Jan 27 14:14:03 volumio volumio[1162]: info: CorePlayQueue::getTrack 0 Jan 27 14:14:03 volumio volumio[1162]: info: CoreCommandRouter::volumioPushState Jan 27 14:14:04 volumio volumio[1162]: info: go-librespot daemon successfully initialized Jan 27 14:14:04 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Jan 27 14:14:04 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 14:14:04 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 14:14:04 volumio go-librespot[1486]: go-librespot daemon starting... Jan 27 14:14:04 volumio go-librespot[1488]: time="2026-01-27T14:14:04+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 14:14:04 volumio go-librespot[1488]: time="2026-01-27T14:14:04+07:00" level=debug msg="app state loaded" Jan 27 14:14:04 volumio go-librespot[1488]: time="2026-01-27T14:14:04+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 14:14:05 volumio mpd[1395]: 2026-01-27T14:14:05 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 27 14:14:05 volumio systemd[1]: Started mpd.service - Music Player Daemon. Jan 27 14:14:05 volumio sudo[1342]: pam_unix(sudo:session): session closed for user root Jan 27 14:14:05 volumio sudo[1353]: pam_unix(sudo:session): session closed for user root Jan 27 14:14:05 volumio go-librespot[1488]: time="2026-01-27T14:14:05+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 27 14:14:05 volumio go-librespot[1488]: time="2026-01-27T14:14:05+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Jan 27 14:14:05 volumio go-librespot[1488]: time="2026-01-27T14:14:05+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Jan 27 14:14:05 volumio volumio[1162]: error: MPD error: The expression evaluated to a falsy value: Jan 27 14:14:05 volumio volumio[1162]: assert.ok(self.idling) Jan 27 14:14:05 volumio volumio[1162]: error: The expression evaluated to a falsy value: Jan 27 14:14:05 volumio volumio[1162]: assert.ok(self.idling) Jan 27 14:14:05 volumio go-librespot[1488]: time="2026-01-27T14:14:05+07:00" level=info msg="zeroconf server listening on port 40177" Jan 27 14:14:05 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 14:14:05 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 14:14:05 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 14:14:05 volumio volumio[1162]: error: updateQueue error: null Jan 27 14:14:05 volumio volumio[1162]: info: MPD running with PID1395 Jan 27 14:14:05 volumio volumio[1162]: ,establishing connection Jan 27 14:14:05 volumio volumio[1162]: info: Completed starting Core Plugins Jan 27 14:14:05 volumio volumio[1162]: info: ------------------------------------------- Jan 27 14:14:05 volumio volumio[1162]: info: ----- MyVolumio plugins startup ---- Jan 27 14:14:05 volumio volumio[1162]: info: ------------------------------------------- Jan 27 14:14:05 volumio volumio[1162]: info: [MyVolumio PluginManager] Fetching plans data.... Jan 27 14:14:05 volumio volumio[1162]: error: updateQueue error: null Jan 27 14:14:05 volumio go-librespot[1488]: time="2026-01-27T14:14:05+07:00" level=debug msg="obtained new client token: AACfJzBo0uvk7i5WtDu9zXsC3FuHtgCW6ZRC+/l7rnAKWh5QchuuVTic66j3sSoJ6CEjiM1UCe/ZlIQu4BP9f5LbN1yfZymoAtIfn66rpyP32MX5UkNqiX/JcfxBiVygxvUK1ZCf96vTSiVx0AkWma63TdEpWVdvpljsDVHFdw7FoTaN48T3Xxwih51fuhNDSzsOYa7pLdEcb/MVhoc+FynP+KmqvMgeg6Dmg9PhVdOcHBA/ADbRCF4Fgms=" Jan 27 14:14:05 volumio go-librespot[1488]: time="2026-01-27T14:14:05+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 14:14:06 volumio go-librespot[1488]: time="2026-01-27T14:14:06+07:00" level=debug msg="completed keyexchange" Jan 27 14:14:06 volumio go-librespot[1488]: time="2026-01-27T14:14:06+07:00" level=debug msg="completed challenge" Jan 27 14:14:06 volumio go-librespot[1488]: time="2026-01-27T14:14:06+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 27 14:14:06 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 14:14:06 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 14:14:07 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 14:14:07 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 14:14:07 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 14:14:07 volumio volumio[1162]: info: Initializing connection to go-librespot Websocket Jan 27 14:14:07 volumio volumio[1162]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 27 14:14:09 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Jan 27 14:14:09 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 14:14:09 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 14:14:09 volumio go-librespot[1507]: go-librespot daemon starting... Jan 27 14:14:09 volumio go-librespot[1508]: time="2026-01-27T14:14:09+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 14:14:09 volumio go-librespot[1508]: time="2026-01-27T14:14:09+07:00" level=debug msg="app state loaded" Jan 27 14:14:09 volumio go-librespot[1508]: time="2026-01-27T14:14:09+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 14:14:09 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 14:14:09 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 14:14:09 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 14:14:09 volumio go-librespot[1508]: time="2026-01-27T14:14: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 27 14:14:09 volumio go-librespot[1508]: time="2026-01-27T14:14: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 27 14:14:09 volumio go-librespot[1508]: time="2026-01-27T14:14: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 27 14:14:09 volumio go-librespot[1508]: time="2026-01-27T14:14:09+07:00" level=info msg="zeroconf server listening on port 38261" Jan 27 14:14:10 volumio go-librespot[1508]: time="2026-01-27T14:14:10+07:00" level=debug msg="obtained new client token: AABlqZkvLWxceqUqrMoUwOpGLisDhwDReuM/laKm0UAA0SKbGtkvNq7ZbSlhSL28t0If3sxtWZkTrXFo7laLcj0zghMv6jZYEkBxpnlF5dwxF5q8w5CAebm8RV5HQyE3n/1XC7hTkJWVayl8x7yBCdAyWUzXtx3vZypPdQQ/MNjFdb7o5N0hhlE1rtYu5Hlfdz31/UoUvRvC4qF701pHOHHVOyAPJabgFmzAufM8gRQRJ/upcoaiSCZx" Jan 27 14:14:10 volumio go-librespot[1508]: time="2026-01-27T14:14:10+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 14:14:10 volumio volumio[1162]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Jan 27 14:14:10 volumio go-librespot[1508]: time="2026-01-27T14:14:10+07:00" level=debug msg="completed keyexchange" Jan 27 14:14:10 volumio go-librespot[1508]: time="2026-01-27T14:14:10+07:00" level=debug msg="completed challenge" Jan 27 14:14:10 volumio go-librespot[1508]: time="2026-01-27T14:14:10+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 27 14:14:10 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 14:14:10 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 14:14:10 volumio volumio[1162]: info: Initializing connection to go-librespot Websocket Jan 27 14:14:10 volumio volumio[1162]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 27 14:14:11 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 14:14:11 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 14:14:11 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 14:14:13 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 14:14:13 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 14:14:13 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 14:14:13 volumio volumio[1162]: info: Initializing connection to go-librespot Websocket Jan 27 14:14:13 volumio volumio[1162]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 27 14:14:13 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Jan 27 14:14:13 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 14:14:13 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 14:14:13 volumio go-librespot[1515]: go-librespot daemon starting... Jan 27 14:14:13 volumio go-librespot[1516]: time="2026-01-27T14:14:13+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 14:14:13 volumio go-librespot[1516]: time="2026-01-27T14:14:13+07:00" level=debug msg="app state loaded" Jan 27 14:14:13 volumio go-librespot[1516]: time="2026-01-27T14:14:13+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 14:14:14 volumio go-librespot[1516]: time="2026-01-27T14:14:14+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 27 14:14:14 volumio go-librespot[1516]: time="2026-01-27T14:14:14+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 27 14:14:14 volumio go-librespot[1516]: time="2026-01-27T14:14:14+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 27 14:14:14 volumio go-librespot[1516]: time="2026-01-27T14:14:14+07:00" level=info msg="zeroconf server listening on port 37689" Jan 27 14:14:14 volumio volumio[1162]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Jan 27 14:14:14 volumio volumio[1162]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Jan 27 14:14:14 volumio volumio[1162]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Jan 27 14:14:14 volumio volumio[1162]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Jan 27 14:14:14 volumio volumio[1162]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Jan 27 14:14:14 volumio volumio[1162]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Jan 27 14:14:14 volumio volumio[1162]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Jan 27 14:14:14 volumio volumio[1162]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Jan 27 14:14:14 volumio volumio[1162]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Jan 27 14:14:14 volumio volumio[1162]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Jan 27 14:14:14 volumio volumio[1162]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Jan 27 14:14:14 volumio volumio[1162]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Jan 27 14:14:14 volumio volumio[1162]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Jan 27 14:14:14 volumio volumio[1162]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Jan 27 14:14:14 volumio volumio[1162]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Jan 27 14:14:14 volumio volumio[1162]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Jan 27 14:14:14 volumio volumio[1162]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Jan 27 14:14:14 volumio volumio[1162]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Jan 27 14:14:14 volumio volumio[1162]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Jan 27 14:14:14 volumio volumio[1162]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Jan 27 14:14:14 volumio volumio[1162]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Jan 27 14:14:14 volumio volumio[1162]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Jan 27 14:14:14 volumio volumio[1162]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Jan 27 14:14:14 volumio volumio[1162]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Jan 27 14:14:14 volumio volumio[1162]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Jan 27 14:14:14 volumio volumio[1162]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Jan 27 14:14:14 volumio volumio[1162]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Jan 27 14:14:14 volumio volumio[1162]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Jan 27 14:14:14 volumio volumio[1162]: info: Adding plugin bluetooth to MyMusic Plugins Jan 27 14:14:14 volumio volumio[1162]: info: Adding plugin multiroom to MyMusic Plugins Jan 27 14:14:14 volumio volumio[1162]: info: Adding plugin metavolumio to MyMusic Plugins Jan 27 14:14:14 volumio volumio[1162]: info: Adding plugin cd_controller to MyMusic Plugins Jan 27 14:14:14 volumio volumio[1162]: info: Adding plugin qobuzconnect to MyMusic Plugins Jan 27 14:14:14 volumio volumio[1162]: info: Adding plugin smart_inputs to MyMusic Plugins Jan 27 14:14:14 volumio volumio[1162]: info: Adding plugin tidalconnect to MyMusic Plugins Jan 27 14:14:14 volumio volumio[1162]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Jan 27 14:14:14 volumio go-librespot[1516]: time="2026-01-27T14:14:14+07:00" level=debug msg="obtained new client token: AADMDwBK3LmXqLsjcZpvkkjVHs9Kqc/yzn0QQnOZepU0f6Baghv/3L7HJvcH0HbBIAH7cypz7NYTHR+NR1EYKToxhYs4D3NiZHpIvujZ1hIN0yDMwcrojtajYYDhLhj76OlNpBOsvPmhOgkXc+Wl6q7OErluvvZk4hg/tuZgh3dI5GBTfKwpEhi4NqDHg5/aFgK3H1IoKmRMZ8m2PJW/WiyOqn88fZHhf0tTP70hYIdQTf4pf4Z/s01zUkI=" Jan 27 14:14:14 volumio go-librespot[1516]: time="2026-01-27T14:14:14+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 14:14:14 volumio go-librespot[1516]: time="2026-01-27T14:14:14+07:00" level=debug msg="completed keyexchange" Jan 27 14:14:14 volumio go-librespot[1516]: time="2026-01-27T14:14:14+07:00" level=debug msg="completed challenge" Jan 27 14:14:15 volumio go-librespot[1516]: time="2026-01-27T14:14:15+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 27 14:14:15 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 14:14:15 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 14:14:15 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 14:14:15 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 14:14:15 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 14:14:16 volumio volumio[1162]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Jan 27 14:14:16 volumio volumio[1162]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Jan 27 14:14:16 volumio volumio[1162]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 14:14:16 volumio volumio[1162]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 14:14:16 volumio volumio[1162]: info: Starting MyVolumio Remote Streaming Endpoints Jan 27 14:14:16 volumio volumio[1162]: info: MyVolumio login type: Token Jan 27 14:14:16 volumio volumio[1162]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Jan 27 14:14:16 volumio volumio[1162]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Jan 27 14:14:17 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 14:14:17 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 14:14:17 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 14:14:18 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Jan 27 14:14:18 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 14:14:18 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 14:14:18 volumio go-librespot[1546]: go-librespot daemon starting... Jan 27 14:14:18 volumio volumio[1162]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Jan 27 14:14:18 volumio volumio[1162]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Jan 27 14:14:18 volumio volumio[1162]: info: Streaming services startup Jan 27 14:14:18 volumio volumio[1162]: info: Starting Streaming Daemon Jan 27 14:14:18 volumio go-librespot[1547]: time="2026-01-27T14:14:18+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 14:14:18 volumio go-librespot[1547]: time="2026-01-27T14:14:18+07:00" level=debug msg="app state loaded" Jan 27 14:14:18 volumio go-librespot[1547]: time="2026-01-27T14:14:18+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 14:14:18 volumio sudo[1554]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jan 27 14:14:18 volumio sudo[1554]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 14:14:18 volumio volumio[1162]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Jan 27 14:14:18 volumio sudo[1554]: pam_unix(sudo:session): session closed for user root Jan 27 14:14:18 volumio volumio[1162]: info: Initializing connection to go-librespot Websocket Jan 27 14:14:18 volumio volumio[1162]: error: Cannot start Volumio Streaming Daemon Jan 27 14:14:18 volumio volumio[1162]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Jan 27 14:14:18 volumio volumio[1162]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Jan 27 14:14:18 volumio go-librespot[1547]: time="2026-01-27T14:14:18+07:00" level=debug msg="new websocket client" Jan 27 14:14:18 volumio volumio[1162]: info: Connection to go-librespot Websocket established Jan 27 14:14:18 volumio go-librespot[1547]: time="2026-01-27T14:14:18+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 27 14:14:18 volumio go-librespot[1547]: time="2026-01-27T14:14:18+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 27 14:14:18 volumio go-librespot[1547]: time="2026-01-27T14:14:18+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 27 14:14:18 volumio go-librespot[1547]: time="2026-01-27T14:14:18+07:00" level=info msg="zeroconf server listening on port 43449" Jan 27 14:14:19 volumio go-librespot[1547]: time="2026-01-27T14:14:19+07:00" level=debug msg="obtained new client token: AACCaDtCLNfp2j1QmjHrVHbmKZvz4gHjxbWJufaPvNSgpQpsLrms3H8I+IRXjZnG/YoOJdszyZxN+Q8YJ7f6awbE6fEi5EGhIYf/sax6GUavtQnPxlxGEKLGug3SoUUuZngdiRIMBOy+2jx6d2/yDbH0Gq0fOTMboDbjyBsdtguUKi/uKZS7UwAAcnqQEaiwStfbgVL4D4tgtjas9InkZUITTaw0Luc9y8s9OcgQv5Cm4I2aPtWyKjpB" Jan 27 14:14:19 volumio go-librespot[1547]: time="2026-01-27T14:14:19+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 14:14:19 volumio go-librespot[1547]: time="2026-01-27T14:14:19+07:00" level=debug msg="completed keyexchange" Jan 27 14:14:19 volumio go-librespot[1547]: time="2026-01-27T14:14:19+07:00" level=debug msg="completed challenge" Jan 27 14:14:19 volumio go-librespot[1547]: time="2026-01-27T14:14:19+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 27 14:14:19 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 14:14:19 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 14:14:19 volumio volumio[1162]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Jan 27 14:14:19 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 14:14:19 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 14:14:19 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 14:14:19 volumio volumio[1162]: info: Connection to go-librespot Websocket closed Jan 27 14:14:20 volumio volumio[1162]: info: MyVolumio token set successfully Jan 27 14:14:20 volumio volumio[1162]: info: MYVOLUMIO: Adding device Jan 27 14:14:20 volumio volumio[1162]: info: MYVOLUMIO: Evaluating Server Jan 27 14:14:20 volumio volumio[1162]: info: MyVolumio status changed Jan 27 14:14:20 volumio volumio[1162]: info: Streaming services startup Jan 27 14:14:20 volumio volumio[1162]: info: Starting Streaming Daemon Jan 27 14:14:21 volumio volumio[1162]: info: Removing browser output: myVolumio user plan is not superstar Jan 27 14:14:21 volumio volumio[1162]: info: Removing audio output: Jan 27 14:14:21 volumio volumio[1162]: info: Stoppping Tunnel 1 Jan 27 14:14:21 volumio sudo[1585]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jan 27 14:14:21 volumio sudo[1585]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 14:14:21 volumio sudo[1587]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Jan 27 14:14:21 volumio sudo[1587]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 14:14:21 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jan 27 14:14:21 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jan 27 14:14:21 volumio volumio[1162]: info: Setting Geolocation for MyVolumio to as1 Jan 27 14:14:21 volumio volumio[1162]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 14:14:21 volumio volumio[1162]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 14:14:21 volumio volumio[1162]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 14:14:21 volumio sudo[1585]: pam_unix(sudo:session): session closed for user root Jan 27 14:14:21 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jan 27 14:14:21 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jan 27 14:14:21 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jan 27 14:14:21 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jan 27 14:14:21 volumio sudo[1587]: pam_unix(sudo:session): session closed for user root Jan 27 14:14:21 volumio volumio[1162]: info: Remote SSH Stopped Jan 27 14:14:21 volumio volumio[1162]: error: Cannot start Volumio Streaming Daemon Jan 27 14:14:21 volumio volumio[1162]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Jan 27 14:14:21 volumio volumio[1162]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Jan 27 14:14:21 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 14:14:21 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 14:14:21 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 14:14:21 volumio volumio[1162]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Jan 27 14:14:21 volumio volumio[1162]: info: Getting Spotify volume Jan 27 14:14:21 volumio volumio[1162]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 27 14:14:21 volumio volumio[1162]: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 27 14:14:21 volumio volumio[1162]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Jan 27 14:14:21 volumio volumio[1162]: errno: -111, Jan 27 14:14:21 volumio volumio[1162]: code: 'ECONNREFUSED', Jan 27 14:14:21 volumio volumio[1162]: syscall: 'connect', Jan 27 14:14:21 volumio volumio[1162]: address: '127.0.0.1', Jan 27 14:14:21 volumio volumio[1162]: port: 9879, Jan 27 14:14:21 volumio volumio[1162]: response: undefined Jan 27 14:14:21 volumio volumio[1162]: } Jan 27 14:14:21 volumio volumio[1162]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 27 14:14:22 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Jan 27 14:14:22 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 14:14:22 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 14:14:22 volumio go-librespot[1603]: go-librespot daemon starting... Jan 27 14:14:22 volumio go-librespot[1604]: time="2026-01-27T14:14:22+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 14:14:22 volumio go-librespot[1604]: time="2026-01-27T14:14:22+07:00" level=debug msg="app state loaded" Jan 27 14:14:22 volumio go-librespot[1604]: time="2026-01-27T14:14:22+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 14:14:23 volumio sudo[1613]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-01-27 14:13' Jan 27 14:14:23 volumio sudo[1613]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 14:14:23 volumio go-librespot[1604]: time="2026-01-27T14:14:23+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 27 14:14:23 volumio go-librespot[1604]: time="2026-01-27T14:14:23+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 27 14:14:23 volumio go-librespot[1604]: time="2026-01-27T14:14:23+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 27 14:14:23 volumio go-librespot[1604]: time="2026-01-27T14:14:23+07:00" level=info msg="zeroconf server listening on port 38415" Jan 27 14:14:23 volumio sudo[1613]: pam_unix(sudo:session): session closed for user root Jan 27 14:14:23 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 14:14:23 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 14:14:23 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 14:14:23 volumio go-librespot[1604]: time="2026-01-27T14:14:23+07:00" level=debug msg="obtained new client token: AABDuktlxaGuXK7omBziuOHkaUEd4h/FymJo5Ad1F/fiWd0NVCo0qs7NUC++JqZLXTgHCE9FTog+O+WwFuZZ0tcPOHfuEuZt0x1sMAM47bdfdz6dA/ncbWifOZXAsWq/kjzfVddFQGjeZRDUwxjnd4oItsne8BH6rWj3hqObTlwYHNKZZ/H7LiNDmTnVRxqrj786mRd8HJpi0K2f4wK+AvIqPw75AyqSkwj4lQKOzTL8TFf/G21kuf0MXDc=" Jan 27 14:14:23 volumio go-librespot[1604]: time="2026-01-27T14:14:23+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 14:14:23 volumio go-librespot[1604]: time="2026-01-27T14:14:23+07:00" level=debug msg="completed keyexchange" Jan 27 14:14:23 volumio go-librespot[1604]: time="2026-01-27T14:14:23+07:00" level=debug msg="completed challenge" Jan 27 14:14:23 volumio go-librespot[1604]: time="2026-01-27T14:14: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 27 14:14:23 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 14:14:23 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 14:14:25 volumio volumio-remote-updater[628]: [2026-01-27 14:14:25] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Jan 27 14:14:25 volumio volumio-remote-updater[628]: [2026-01-27 14:14:25] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Jan 27 14:14:25 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Jan 27 14:14:25 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Jan 27 14:14:25 volumio systemd[1]: volumio.service: Consumed 1min 14.472s CPU time. Jan 27 14:14:25 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 27 14:14:25 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Jan 27 14:14:25 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 8661. Jan 27 14:14:25 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 27 14:14:25 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Jan 27 14:14:25 volumio systemd[1]: volumio.service: Consumed 1min 14.472s CPU time. Jan 27 14:14:25 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Jan 27 14:14:25 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Jan 27 14:14:25 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 14:14:25 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 14:14:25 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 14:14:26 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Jan 27 14:14:26 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 14:14:27 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 14:14:27 volumio go-librespot[1660]: go-librespot daemon starting... Jan 27 14:14:27 volumio go-librespot[1661]: time="2026-01-27T14:14:27+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 14:14:27 volumio go-librespot[1661]: time="2026-01-27T14:14:27+07:00" level=debug msg="app state loaded" Jan 27 14:14:27 volumio go-librespot[1661]: time="2026-01-27T14:14:27+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 14:14:27 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 14:14:27 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 14:14:27 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 14:14:27 volumio go-librespot[1661]: time="2026-01-27T14:14:27+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 27 14:14:27 volumio go-librespot[1661]: time="2026-01-27T14:14:27+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 27 14:14:27 volumio go-librespot[1661]: time="2026-01-27T14:14:27+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 27 14:14:27 volumio go-librespot[1661]: time="2026-01-27T14:14:27+07:00" level=info msg="zeroconf server listening on port 39907" Jan 27 14:14:27 volumio go-librespot[1661]: time="2026-01-27T14:14:27+07:00" level=debug msg="obtained new client token: AAANFafI+y2sCr9lG8OY8Dc2Ho70kbqzInzPW4uubzc9QA4pv02eELzSXacjUM5y9+hRkte46eT3mbWSxJFAue6ysP81ftaK/Yli0HR+HtsPnP+/SuKfM6F/hgFp+0aSvXDdR7f7AACRoJAWHliRZwaphkhUAPo6rj7/+zr+oqExG8DTyaQ3HTuvLWH+Ry8qlIT5xQHk3zqissMbPN0JCYbNrjPmC5W70v3z6RriiWPQMi82CNTMHWTUoPs=" Jan 27 14:14:28 volumio go-librespot[1661]: time="2026-01-27T14:14:28+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 14:14:28 volumio go-librespot[1661]: time="2026-01-27T14:14:28+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Jan 27 14:14:28 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 14:14:28 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 14:14:28 volumio volumio[1645]: info: ------------------------------------------- Jan 27 14:14:28 volumio volumio[1645]: info: ----- Volumio3 ---- Jan 27 14:14:28 volumio volumio[1645]: info: ------------------------------------------- Jan 27 14:14:28 volumio volumio[1645]: info: ----- System startup ---- Jan 27 14:14:28 volumio volumio[1645]: info: ------------------------------------------- Jan 27 14:14:29 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 14:14:29 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 14:14:29 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 14:14:30 volumio volumio-remote-updater[628]: [2026-01-27 14:14:30] [connect] Successful connection Jan 27 14:14:30 volumio volumio[1645]: info: MYVOLUMIO Environment detected Jan 27 14:14:30 volumio volumio[1645]: info: Plugin folders cleanup Jan 27 14:14:30 volumio volumio[1645]: info: Scanning into folder /volumio/app/plugins/ Jan 27 14:14:30 volumio volumio[1645]: info: Scanning category audio_interface Jan 27 14:14:30 volumio volumio[1645]: info: Scanning category miscellanea Jan 27 14:14:30 volumio volumio[1645]: info: Scanning category music_service Jan 27 14:14:30 volumio volumio[1645]: info: Scanning category plugins.json Jan 27 14:14:30 volumio volumio[1645]: info: Scanning category system_controller Jan 27 14:14:30 volumio volumio[1645]: info: Scanning category user_interface Jan 27 14:14:30 volumio volumio[1645]: info: Scanning into folder /data/plugins/ Jan 27 14:14:30 volumio volumio[1645]: info: Scanning category music_service Jan 27 14:14:30 volumio volumio[1645]: info: Plugin folders cleanup completed Jan 27 14:14:30 volumio volumio[1645]: info: ------------------------------------------- Jan 27 14:14:30 volumio volumio[1645]: info: ----- Core plugins startup ---- Jan 27 14:14:30 volumio volumio[1645]: info: ------------------------------------------- Jan 27 14:14:30 volumio volumio[1645]: info: Loading plugins from folder /volumio/app/plugins/ Jan 27 14:14:30 volumio volumio[1645]: info: Adding plugin upnp to MyMusic Plugins Jan 27 14:14:30 volumio volumio[1645]: info: Adding plugin airplay_emulation to MyMusic Plugins Jan 27 14:14:30 volumio volumio[1645]: info: Adding plugin upnp_browser to MyMusic Plugins Jan 27 14:14:30 volumio volumio[1645]: info: Loading plugins from folder /data/plugins/ Jan 27 14:14:30 volumio volumio[1645]: info: Loading plugin "system"... Jan 27 14:14:30 volumio volumio[1645]: info: Loading plugin "appearance"... Jan 27 14:14:31 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Jan 27 14:14:31 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 14:14:31 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 14:14:31 volumio go-librespot[1680]: go-librespot daemon starting... Jan 27 14:14:31 volumio go-librespot[1681]: time="2026-01-27T14:14:31+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 14:14:31 volumio go-librespot[1681]: time="2026-01-27T14:14:31+07:00" level=debug msg="app state loaded" Jan 27 14:14:31 volumio go-librespot[1681]: time="2026-01-27T14:14:31+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 14:14:31 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 14:14:31 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 14:14:31 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 14:14:31 volumio go-librespot[1681]: time="2026-01-27T14:14: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-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 27 14:14:31 volumio go-librespot[1681]: time="2026-01-27T14:14:31+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 27 14:14:31 volumio go-librespot[1681]: time="2026-01-27T14:14:31+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 27 14:14:31 volumio go-librespot[1681]: time="2026-01-27T14:14:31+07:00" level=info msg="zeroconf server listening on port 38417" Jan 27 14:14:32 volumio go-librespot[1681]: time="2026-01-27T14:14:32+07:00" level=debug msg="obtained new client token: AADcSgxktlBXOdWqZwXquCFxG5gFjsqSuFz8SBsl/SrFl7YIdiLBnUF2eYQHVkKWeuesbnAynWEbbv8QJzqb0jg/u5693rZOhokARRQc/ELLA5IogB8ISRUkOyny57oPUNPtNpu6QyfTp6nUYSaDIoXzhM5iPgM1M+Awn3gkNKGionK7MoVbOjfzPyM258rmx9RFLmsP58B0MXJjuLVYOYf8aQJ+HtSuYO0ee3yimsmbIi00RNNZAFnb" Jan 27 14:14:32 volumio go-librespot[1681]: time="2026-01-27T14:14:32+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 14:14:32 volumio volumio[1645]: info: Loading plugin "network"... Jan 27 14:14:32 volumio volumio[1645]: info: Refreshing Cached IP Addresses Jan 27 14:14:32 volumio go-librespot[1681]: time="2026-01-27T14:14:32+07:00" level=debug msg="completed keyexchange" Jan 27 14:14:32 volumio go-librespot[1681]: time="2026-01-27T14:14:32+07:00" level=debug msg="completed challenge" Jan 27 14:14:32 volumio sudo[1689]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 27 14:14:32 volumio sudo[1691]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 27 14:14:32 volumio sudo[1691]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 14:14:32 volumio sudo[1689]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 14:14:32 volumio volumio[1645]: info: Loading plugin "services"... Jan 27 14:14:32 volumio sudo[1691]: pam_unix(sudo:session): session closed for user root Jan 27 14:14:32 volumio volumio[1645]: info: Loading plugin "alsa_controller"... Jan 27 14:14:32 volumio sudo[1689]: pam_unix(sudo:session): session closed for user root Jan 27 14:14:32 volumio go-librespot[1681]: time="2026-01-27T14:14:32+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 27 14:14:32 volumio sudo[1699]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Jan 27 14:14:32 volumio sudo[1699]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 14:14:32 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 14:14:32 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 14:14:32 volumio volumio[1645]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 27 14:14:32 volumio volumio[1645]: info: Loading plugin "wizard"... Jan 27 14:14:32 volumio volumio[1645]: info: Loading plugin "networkfs"... Jan 27 14:14:32 volumio volumio[1645]: info: Starting Udev Watcher for removable devices Jan 27 14:14:32 volumio volumio[1645]: info: Ignoring mount for partition: boot Jan 27 14:14:32 volumio volumio[1645]: info: Ignoring mount for partition: volumio Jan 27 14:14:32 volumio volumio[1645]: info: Ignoring mount for partition: volumio_data Jan 27 14:14:32 volumio volumio[1645]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 27 14:14:32 volumio volumio[1645]: info: Loading plugin "volumio_command_line_client"... Jan 27 14:14:32 volumio volumio[1645]: info: Loading plugin "upnp"... Jan 27 14:14:32 volumio volumio[1645]: info: [1769498072762] Starting Upmpd Daemon Jan 27 14:14:32 volumio volumio[1645]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 27 14:14:32 volumio volumio[1645]: info: Loading plugin "my_music"... Jan 27 14:14:32 volumio volumio[1645]: info: Loading plugin "mpd"... Jan 27 14:14:33 volumio volumio[1645]: info: Loading plugin "upnp_browser"... Jan 27 14:14:33 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 14:14:33 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 14:14:33 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 14:14:35 volumio sudo[1699]: pam_unix(sudo:session): session closed for user root Jan 27 14:14:35 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 14:14:35 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 14:14:35 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 14:14:35 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Jan 27 14:14:35 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 14:14:35 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 14:14:35 volumio go-librespot[1723]: go-librespot daemon starting... Jan 27 14:14:35 volumio go-librespot[1724]: time="2026-01-27T14:14:35+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 14:14:35 volumio go-librespot[1724]: time="2026-01-27T14:14:35+07:00" level=debug msg="app state loaded" Jan 27 14:14:35 volumio go-librespot[1724]: time="2026-01-27T14:14:35+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 14:14:36 volumio volumio[1645]: info: Starting UPNP Browser Jan 27 14:14:36 volumio volumio[1645]: info: Loading plugin "alarm-clock"... Jan 27 14:14:36 volumio go-librespot[1724]: time="2026-01-27T14:14:36+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 27 14:14:36 volumio go-librespot[1724]: time="2026-01-27T14:14:36+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 27 14:14:36 volumio go-librespot[1724]: time="2026-01-27T14:14:36+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 27 14:14:36 volumio go-librespot[1724]: time="2026-01-27T14:14:36+07:00" level=info msg="zeroconf server listening on port 41293" Jan 27 14:14:36 volumio volumio[1645]: info: Loading plugin "airplay_emulation"... Jan 27 14:14:36 volumio volumio[1645]: info: Starting Shairport Sync Jan 27 14:14:36 volumio volumio[1645]: info: Loading plugin "last_100"... Jan 27 14:14:36 volumio go-librespot[1724]: time="2026-01-27T14:14:36+07:00" level=debug msg="obtained new client token: AABLMErNd4YwiCfhSJEr+JHO/bhxWeve0pnH27F2ftXKm7JdydOgp6LNyxJHLbLZXfFJSwRwhuWGocfI9MKCTXtEOikeGhZ0alpIC7gZ7OjF4HPS++bIYpCVQFASjG/VihDEyv/88Yl8Zs7PxD16TRT/1FwxcbyUsVMCOJ0zE47TIIeNLZwKUH1Gkqyrft82ca51nuDeYjQXXRw8jUxe7GXfS0z5T9DJCQcbXmIVQ2T6oObnS3eNwiBqJ4g=" Jan 27 14:14:36 volumio volumio[1645]: info: Loading plugin "webradio"... Jan 27 14:14:36 volumio go-librespot[1724]: time="2026-01-27T14:14:36+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 14:14:36 volumio go-librespot[1724]: time="2026-01-27T14:14:36+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Jan 27 14:14:36 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 14:14:36 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 14:14:36 volumio volumio[1645]: info: Loading plugin "i2s_dacs"... Jan 27 14:14:36 volumio volumio[1645]: info: Loading plugin "volumiodiscovery"... Jan 27 14:14:37 volumio volumio[1645]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 27 14:14:37 volumio volumio[1645]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 27 14:14:37 volumio volumio[1645]: *** WARNING *** For more information see Jan 27 14:14:37 volumio volumio[1645]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 27 14:14:37 volumio volumio[1645]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 27 14:14:37 volumio volumio[1645]: *** WARNING *** For more information see Jan 27 14:14:37 volumio node[1645]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 27 14:14:37 volumio node[1645]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 27 14:14:37 volumio node[1645]: *** WARNING *** For more information see Jan 27 14:14:37 volumio node[1645]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 27 14:14:37 volumio node[1645]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 27 14:14:37 volumio node[1645]: *** WARNING *** For more information see Jan 27 14:14:37 volumio volumio[1645]: info: Applying required configuration parameters for plugin volumiodiscovery Jan 27 14:14:37 volumio volumio[1645]: info: Discovery: Started advertising with name: Volumio Jan 27 14:14:37 volumio volumio[1645]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 27 14:14:37 volumio volumio[1645]: info: Loading plugin "spop"... Jan 27 14:14:37 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 14:14:37 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 14:14:37 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 14:14:38 volumio volumio[1645]: info: Loading plugin "ytcr"... Jan 27 14:14:39 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 14:14:39 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 14:14:39 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 14:14:39 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Jan 27 14:14:39 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 14:14:40 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 14:14:40 volumio go-librespot[1733]: go-librespot daemon starting... Jan 27 14:14:40 volumio go-librespot[1734]: time="2026-01-27T14:14:40+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 14:14:40 volumio go-librespot[1734]: time="2026-01-27T14:14:40+07:00" level=debug msg="app state loaded" Jan 27 14:14:40 volumio go-librespot[1734]: time="2026-01-27T14:14:40+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 14:14:40 volumio go-librespot[1734]: time="2026-01-27T14:14:40+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 27 14:14:40 volumio go-librespot[1734]: time="2026-01-27T14:14:40+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 27 14:14:40 volumio go-librespot[1734]: time="2026-01-27T14:14:40+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 27 14:14:40 volumio go-librespot[1734]: time="2026-01-27T14:14:40+07:00" level=info msg="zeroconf server listening on port 39969" Jan 27 14:14:40 volumio go-librespot[1734]: time="2026-01-27T14:14:40+07:00" level=debug msg="obtained new client token: AAD2x+v/W+7E3birnOGj07ZJpHXqv/HgOztUd+F0Zao4fZMOKWYGFE1HxYzgylFfpngZMue0whRmeAvAcUsYO6yQwzCE2ml/D07iQcFChCGQpsFal40pPffRGv1sprCvyMRt03je+6SZTjDlqo5h2JtjuJqKIf0R818W+czkduFPBdm49fPrPI6RYdAzUx+qpZCim6Wu4r6iwPRdl+ChSxn8yULZLhIxRSIdWPez0C+7XQOBkjEslRN2Sy0=" Jan 27 14:14:40 volumio go-librespot[1734]: time="2026-01-27T14:14:40+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 14:14:41 volumio go-librespot[1734]: time="2026-01-27T14:14:41+07:00" level=debug msg="completed keyexchange" Jan 27 14:14:41 volumio go-librespot[1734]: time="2026-01-27T14:14:41+07:00" level=debug msg="completed challenge" Jan 27 14:14:41 volumio go-librespot[1734]: time="2026-01-27T14:14:41+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 27 14:14:41 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 14:14:41 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 14:14:41 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 14:14:41 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 14:14:41 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 14:14:41 volumio volumio[1645]: info: Loading plugin "ytmusic"... Jan 27 14:14:42 volumio volumio-remote-updater[628]: [2026-01-27 14:14:42] [connect] Successful connection Jan 27 14:14:42 volumio volumio[1645]: info: Loading plugin "outputs"... Jan 27 14:14:42 volumio volumio[1645]: info: Loading plugin "albumart"... Jan 27 14:14:42 volumio volumio[1645]: info: Plugin example_plugin is not enabled Jan 27 14:14:42 volumio volumio[1645]: info: Loading plugin "inputs"... Jan 27 14:14:42 volumio volumio[1645]: info: Loading plugin "updater_comm"... Jan 27 14:14:42 volumio volumio[1645]: info: Plugin mpdemulation is not enabled Jan 27 14:14:42 volumio volumio[1645]: info: Loading plugin "rest_api"... Jan 27 14:14:42 volumio volumio[1645]: info: Loading plugin "websocket"... Jan 27 14:14:42 volumio volumio[1645]: info: Starting Socket.io Server version 1.7.4 Jan 27 14:14:42 volumio volumio[1645]: info: Loading plugin "RoonBridge"... Jan 27 14:14:43 volumio volumio[1645]: info: Applying required configuration parameters for plugin RoonBridge Jan 27 14:14:43 volumio volumio[1645]: info: Loading i18n strings for locale en Jan 27 14:14:43 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 14:14:43 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 14:14:43 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 14:14:43 volumio volumio[1645]: Updating browse sources language Jan 27 14:14:43 volumio volumio[1645]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 27 14:14:43 volumio volumio[1755]: Forking 3 albumart workers Jan 27 14:14:43 volumio volumio[1645]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 27 14:14:43 volumio volumio[1645]: info: CoreCommandRouter::initPlayerControls Jan 27 14:14:43 volumio volumio[1645]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 14:14:43 volumio volumio[1645]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 14:14:43 volumio volumio[1645]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 14:14:43 volumio volumio[1645]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 14:14:43 volumio volumio[1645]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 14:14:43 volumio volumio[1645]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 14:14:43 volumio volumio[1645]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 14:14:43 volumio volumio[1645]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 14:14:43 volumio volumio[1645]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 27 14:14:43 volumio volumio[1645]: Express server listening on port 3000 Jan 27 14:14:43 volumio volumio[1645]: [Metrics] WebUI: 15s 990.91ms Jan 27 14:14:43 volumio volumio[1645]: info: CoreStateMachine::resetVolumioState Jan 27 14:14:43 volumio volumio[1645]: info: CoreStateMachine::getcurrentVolume Jan 27 14:14:43 volumio volumio[1645]: info: CoreCommandRouter::volumioRetrievevolume Jan 27 14:14:44 volumio sudo[1799]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 27 14:14:44 volumio sudo[1799]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 14:14:44 volumio sudo[1799]: pam_unix(sudo:session): session closed for user root Jan 27 14:14:44 volumio sudo[1802]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 27 14:14:44 volumio sudo[1802]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 14:14:44 volumio sudo[1802]: pam_unix(sudo:session): session closed for user root Jan 27 14:14:44 volumio volumio[1645]: info: Volumio Network Manager: Network status updated: 1 Jan 27 14:14:44 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Jan 27 14:14:44 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 14:14:44 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 14:14:44 volumio go-librespot[1809]: go-librespot daemon starting... Jan 27 14:14:44 volumio go-librespot[1810]: time="2026-01-27T14:14:44+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 14:14:44 volumio go-librespot[1810]: time="2026-01-27T14:14:44+07:00" level=debug msg="app state loaded" Jan 27 14:14:44 volumio go-librespot[1810]: time="2026-01-27T14:14:44+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 14:14:44 volumio volumio[1645]: info: VolumeController:: Volume=100 Mute =false Jan 27 14:14:44 volumio volumio[1645]: info: CoreStateMachine::pushState Jan 27 14:14:44 volumio volumio[1645]: info: CorePlayQueue::getTrack 0 Jan 27 14:14:44 volumio volumio[1645]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 27 14:14:44 volumio volumio[1645]: info: CoreCommandRouter::volumioPushState Jan 27 14:14:44 volumio volumio[1645]: info: CoreStateMachine::updateTrackBlock Jan 27 14:14:44 volumio volumio[1645]: info: CorePlayQueue::getTrackBlock Jan 27 14:14:44 volumio volumio[1645]: info: CoreCommandRouter::volumioRetrievevolume Jan 27 14:14:44 volumio volumio-remote-updater[628]: [2026-01-27 14:14:44] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1769498082 101 Jan 27 14:14:44 volumio volumio[1645]: 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 27 14:14:44 volumio volumio[1645]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 14:14:44 volumio volumio[1645]: info: Reloading queue from file Jan 27 14:14:44 volumio volumio[1645]: info: CoreStateMachine::setRepeat null single undefined Jan 27 14:14:44 volumio volumio[1645]: info: CoreStateMachine::pushState Jan 27 14:14:44 volumio volumio[1645]: info: CorePlayQueue::getTrack 0 Jan 27 14:14:44 volumio volumio[1645]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 27 14:14:44 volumio volumio[1645]: info: CoreCommandRouter::volumioPushState Jan 27 14:14:44 volumio volumio[1645]: info: CoreStateMachine::setRandom null Jan 27 14:14:44 volumio volumio[1645]: info: CoreStateMachine::pushState Jan 27 14:14:44 volumio volumio[1645]: info: CorePlayQueue::getTrack 0 Jan 27 14:14:44 volumio volumio[1645]: info: CoreCommandRouter::volumioPushState Jan 27 14:14:44 volumio volumio[1645]: info: Setting Device type: Raspberry PI Jan 27 14:14:44 volumio volumio[1645]: info: Completed loading Core Plugins Jan 27 14:14:44 volumio volumio[1645]: info: Preparing to generate the ALSA configuration file Jan 27 14:14:45 volumio go-librespot[1810]: time="2026-01-27T14:14:45+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 27 14:14:45 volumio go-librespot[1810]: time="2026-01-27T14:14:45+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 27 14:14:45 volumio go-librespot[1810]: time="2026-01-27T14:14:45+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 27 14:14:45 volumio go-librespot[1810]: time="2026-01-27T14:14:45+07:00" level=info msg="zeroconf server listening on port 45021" Jan 27 14:14:45 volumio volumio[1645]: info: VolumeController:: Volume=100 Mute =false Jan 27 14:14:45 volumio volumio[1645]: info: CoreStateMachine::pushState Jan 27 14:14:45 volumio volumio[1645]: info: CorePlayQueue::getTrack 0 Jan 27 14:14:45 volumio volumio[1645]: info: CoreCommandRouter::volumioPushState Jan 27 14:14:45 volumio volumio[1645]: info: Asound.conf file unchanged, so no further update is needed Jan 27 14:14:45 volumio volumio[1645]: info: Output device has changed, restarting MPD Jan 27 14:14:45 volumio sudo[1827]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Jan 27 14:14:45 volumio sudo[1827]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 14:14:45 volumio sudo[1829]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 27 14:14:45 volumio sudo[1829]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 14:14:45 volumio volumio[1645]: info: Output device has changed, restarting Shairport Sync Jan 27 14:14:45 volumio volumio[1645]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 14:14:45 volumio volumio[1645]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 14:14:45 volumio sudo[1829]: pam_unix(sudo:session): session closed for user root Jan 27 14:14:45 volumio go-librespot[1810]: time="2026-01-27T14:14:45+07:00" level=debug msg="obtained new client token: AAApN7ADi8ad1pATummhHKgFdVh94GMcF30Iz/Wh1JCchigP0bU6TryjONk9tz0+ZSjoMEtDZ3ETQVH2bntEGlF8IinZZxTkxidCcdggUeObp1YOJ4D4WXT+kbBxbB0y8Jw3m8lOFXMzhY03/wCGDQ21Qqkdub61p1BK/pARH8Qa5/C0sLNWB6tHpPaUbRlT9bhpE/8lMBuUF8wBkXE9QovJFFgZ1SOKx3xG3lqkYzKNJ8OJHGZWGm0Q" Jan 27 14:14:45 volumio sudo[1832]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 27 14:14:45 volumio sudo[1832]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 14:14:45 volumio volumio[1645]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 27 14:14:45 volumio volumio[1645]: info: ___________ START PLUGINS ___________ Jan 27 14:14:45 volumio go-librespot[1810]: time="2026-01-27T14:14:45+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 14:14:45 volumio sudo[1827]: pam_unix(sudo:session): session closed for user root Jan 27 14:14:45 volumio volumio[1645]: info: ControllerMpd::onStart: Initializing MPD Jan 27 14:14:45 volumio volumio[1645]: info: Creating MPD Configuration file Jan 27 14:14:45 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Jan 27 14:14:45 volumio go-librespot[1810]: time="2026-01-27T14:14:45+07:00" level=debug msg="completed keyexchange" Jan 27 14:14:45 volumio go-librespot[1810]: time="2026-01-27T14:14:45+07:00" level=debug msg="completed challenge" Jan 27 14:14:45 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 14:14:45 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 14:14:45 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 14:14:45 volumio sudo[1840]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 27 14:14:45 volumio sudo[1840]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 14:14:45 volumio sudo[1840]: pam_unix(sudo:session): session closed for user root Jan 27 14:14:45 volumio go-librespot[1810]: time="2026-01-27T14:14:45+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 27 14:14:45 volumio volumio[1645]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 27 14:14:45 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 14:14:45 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 14:14:45 volumio volumio[1645]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 27 14:14:45 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 27 14:14:45 volumio volumio[1645]: info: [1769498085650] CoreMusicLibrary::Adding element Media Servers Jan 27 14:14:45 volumio volumio[1645]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 27 14:14:45 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 27 14:14:45 volumio systemd[1]: mpd.service: Consumed 7.468s CPU time. Jan 27 14:14:45 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 27 14:14:45 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 27 14:14:45 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 27 14:14:45 volumio sudo[1843]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 27 14:14:45 volumio sudo[1843]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 14:14:45 volumio volumio[1645]: info: UPNP Browser: Client initialized successfully Jan 27 14:14:45 volumio volumio[1645]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 14:14:45 volumio volumio[1645]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 14:14:45 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 27 14:14:45 volumio volumio[1645]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 27 14:14:45 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 27 14:14:45 volumio volumio[1645]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 14:14:45 volumio volumio[1645]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 14:14:45 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 27 14:14:45 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 27 14:14:45 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 27 14:14:45 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 27 14:14:45 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 27 14:14:45 volumio volumio[1645]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 27 14:14:45 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 27 14:14:45 volumio volumio[1645]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 27 14:14:45 volumio volumio[1645]: info: [1769498085982] CoreMusicLibrary::Adding element Last_100 Jan 27 14:14:45 volumio volumio[1645]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 27 14:14:45 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 27 14:14:45 volumio volumio[1645]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 27 14:14:46 volumio volumio[1645]: info: [1769498086002] CoreMusicLibrary::Adding element Webradio Jan 27 14:14:46 volumio volumio[1645]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 27 14:14:46 volumio volumio[1645]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 27 14:14:46 volumio volumio[1645]: info: Initializing BBC Radios Jan 27 14:14:46 volumio volumio[1645]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 27 14:14:46 volumio volumio[1645]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 14:14:46 volumio volumio[1645]: info: Creating Spotify config file Jan 27 14:14:46 volumio volumio[1645]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 14:14:46 volumio sudo[1856]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 27 14:14:46 volumio sudo[1856]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jan 27 14:14:46 volumio sudo[1856]: pam_unix(sudo:session): session closed for user root Jan 27 14:14:47 volumio volumio[1767]: Starting albumart workers Jan 27 14:14:47 volumio volumio[1766]: Starting albumart workers Jan 27 14:14:47 volumio volumio[1768]: Starting albumart workers Jan 27 14:14:47 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 14:14:47 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 14:14:47 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 14:14:47 volumio volumio[1645]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 27 14:14:47 volumio volumio[1645]: info: [1769498087799] CoreMusicLibrary::Adding element YouTube Music Jan 27 14:14:47 volumio volumio[1645]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 27 14:14:47 volumio volumio[1645]: Cannot find translation for source YouTube Music Jan 27 14:14:47 volumio volumio[1645]: info: Volumio Calling Home Jan 27 14:14:48 volumio sudo[1873]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Jan 27 14:14:48 volumio sudo[1873]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 14:14:48 volumio sudo[1873]: pam_unix(sudo:session): session closed for user root Jan 27 14:14:48 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 11. Jan 27 14:14:48 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 14:14:48 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 14:14:48 volumio go-librespot[1885]: go-librespot daemon starting... Jan 27 14:14:48 volumio volumio[1645]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Jan 27 14:14:48 volumio volumio[1645]: info: Discovery: Found device Volumio Jan 27 14:14:48 volumio volumio[1645]: info: CoreCommandRouter::volumioGetState Jan 27 14:14:48 volumio volumio[1645]: info: CorePlayQueue::getTrack 0 Jan 27 14:14:48 volumio go-librespot[1892]: time="2026-01-27T14:14:48+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 14:14:48 volumio go-librespot[1892]: time="2026-01-27T14:14:48+07:00" level=debug msg="app state loaded" Jan 27 14:14:48 volumio go-librespot[1892]: time="2026-01-27T14:14:48+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 14:14:49 volumio volumio[1645]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Jan 27 14:14:49 volumio volumio[1645]: info: Discovery: Found device Volumio Jan 27 14:14:49 volumio volumio[1645]: info: CoreCommandRouter::volumioGetState Jan 27 14:14:49 volumio volumio[1645]: info: CorePlayQueue::getTrack 0 Jan 27 14:14:49 volumio volumio[1645]: info: MPD Permissions set Jan 27 14:14:49 volumio volumio[1645]: info: MPD Permissions set Jan 27 14:14:49 volumio volumio[1645]: info: Upmpdcli Daemon Started Jan 27 14:14:49 volumio volumio[1645]: info: Volumio called home Jan 27 14:14:49 volumio volumio[1645]: info: Spotify config file written Jan 27 14:14:49 volumio sudo[1904]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jan 27 14:14:49 volumio sudo[1904]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 14:14:49 volumio volumio[1645]: 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 27 14:14:49 volumio volumio[1645]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 14:14:49 volumio volumio[1645]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 14:14:49 volumio volumio[1645]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 14:14:49 volumio volumio[1645]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 14:14:49 volumio volumio[1645]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 14:14:49 volumio volumio[1645]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 14:14:49 volumio volumio[1645]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 14:14:49 volumio volumio[1645]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 14:14:49 volumio volumio[1645]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 14:14:49 volumio volumio[1645]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 14:14:49 volumio volumio[1645]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 14:14:49 volumio volumio[1645]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 14:14:49 volumio volumio[1645]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 14:14:49 volumio volumio[1645]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 14:14:49 volumio volumio[1645]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 14:14:49 volumio volumio[1645]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 14:14:49 volumio volumio[1645]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 14:14:49 volumio volumio[1645]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 14:14:49 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Jan 27 14:14:49 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Jan 27 14:14:49 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 14:14:49 volumio volumio[1645]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 14:14:49 volumio volumio[1645]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 14:14:49 volumio volumio[1645]: info: No need to fix Spotify hosts Jan 27 14:14:49 volumio go-librespot[1921]: go-librespot daemon starting... Jan 27 14:14:49 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 14:14:49 volumio sudo[1904]: pam_unix(sudo:session): session closed for user root Jan 27 14:14:49 volumio go-librespot[1922]: time="2026-01-27T14:14:49+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 14:14:49 volumio go-librespot[1922]: time="2026-01-27T14:14:49+07:00" level=debug msg="app state loaded" Jan 27 14:14:49 volumio go-librespot[1922]: time="2026-01-27T14:14:49+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 14:14:49 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 14:14:49 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 14:14:49 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 14:14:50 volumio go-librespot[1922]: time="2026-01-27T14:14:50+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 27 14:14:50 volumio go-librespot[1922]: time="2026-01-27T14:14:50+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 27 14:14:50 volumio go-librespot[1922]: time="2026-01-27T14:14:50+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 27 14:14:50 volumio go-librespot[1922]: time="2026-01-27T14:14:50+07:00" level=info msg="zeroconf server listening on port 45749" Jan 27 14:14:50 volumio volumio[1645]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 27 14:14:50 volumio volumio[1645]: SPOTIFY: BQARq7dzLTb_TNaIxuej19zc4HsLYffsLllnZ_MT5eL9Z7ejU-ZOSwAOxNPbdM30qTnGw04hWDNz8G7bG6a6xjhXJbLZTX51r-JhQpGX2HDHAFFDoFhFzocImVvy6dE_IYveXqqBrZ6s-UZs-07BHoTCXiOzfGjRmPuuLgTrsV6cpO_Fi1Ljyy1Tw84xk9LrFe7fZaPDwQwJWAHdQ1TNrUzs_T3g7wgR_YumXs6UIBsYyXBa1fr57n7C4mjku6QDlwsBFbwhxnrv6KtRL678ZGzHsAE4ydh3vFMpUwmtkn9zHClG3uoqepDB Jan 27 14:14:50 volumio volumio[1645]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 27 14:14:50 volumio volumio[1645]: info: New Spotify access token = BQARq7dzLTb_TNaIxuej19zc4HsLYffsLllnZ_MT5eL9Z7ejU-ZOSwAOxNPbdM30qTnGw04hWDNz8G7bG6a6xjhXJbLZTX51r-JhQpGX2HDHAFFDoFhFzocImVvy6dE_IYveXqqBrZ6s-UZs-07BHoTCXiOzfGjRmPuuLgTrsV6cpO_Fi1Ljyy1Tw84xk9LrFe7fZaPDwQwJWAHdQ1TNrUzs_T3g7wgR_YumXs6UIBsYyXBa1fr57n7C4mjku6QDlwsBFbwhxnrv6KtRL678ZGzHsAE4ydh3vFMpUwmtkn9zHClG3uoqepDB Jan 27 14:14:50 volumio volumio[1645]: info: Spotify credentials grant success - running version from March 24, 2019 Jan 27 14:14:50 volumio go-librespot[1922]: time="2026-01-27T14:14:50+07:00" level=debug msg="obtained new client token: AAArHbCOuPBszDUredqXcfWjNUxBQt7FGGjO6Qm4HesZ9zGBHyNsTiGasrHmOE1yr2rEU89uuoSdR1HT426XqbKRzkWSVLEhlCthU67l1h8LvLNNTKgcE1b9nv8U5AHum36Fxwy9SiAuPMg7aewbq4s2LIJlOr0DaHH3ZEc/MbKma7mmbkyD93BkTqr23jxr8VHo2maYry6Xav3kVvb5GY58eohMO35CZAo/hOplyJVia99Fu/sT27U5" Jan 27 14:14:50 volumio volumio[1645]: info: Starting Shairport Sync Jan 27 14:14:50 volumio volumio[1645]: info: Starting Shairport Sync Jan 27 14:14:50 volumio volumio[1645]: info: Starting Shairport Sync Jan 27 14:14:50 volumio sudo[1932]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 27 14:14:50 volumio sudo[1932]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 14:14:50 volumio go-librespot[1922]: time="2026-01-27T14:14:50+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 14:14:50 volumio sudo[1934]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 27 14:14:50 volumio sudo[1934]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 14:14:50 volumio sudo[1937]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 27 14:14:50 volumio sudo[1937]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 14:14:50 volumio go-librespot[1922]: time="2026-01-27T14:14:50+07:00" level=debug msg="completed keyexchange" Jan 27 14:14:50 volumio go-librespot[1922]: time="2026-01-27T14:14:50+07:00" level=debug msg="completed challenge" Jan 27 14:14:50 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 27 14:14:50 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Jan 27 14:14:50 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 27 14:14:50 volumio systemd[1]: shairport-sync.service: Consumed 2.453s CPU time. Jan 27 14:14:50 volumio go-librespot[1922]: time="2026-01-27T14:14:50+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 27 14:14:50 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 27 14:14:50 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 14:14:50 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 14:14:50 volumio sudo[1932]: pam_unix(sudo:session): session closed for user root Jan 27 14:14:50 volumio sudo[1934]: pam_unix(sudo:session): session closed for user root Jan 27 14:14:50 volumio sudo[1937]: pam_unix(sudo:session): session closed for user root Jan 27 14:14:50 volumio volumio[1645]: info: Shairport-Sync Started Jan 27 14:14:50 volumio volumio[1645]: Error adding Membership: Error: addMembership EINVAL Jan 27 14:14:50 volumio volumio[1645]: info: Shairport-Sync Started Jan 27 14:14:50 volumio volumio[1645]: info: Shairport-Sync Started Jan 27 14:14:50 volumio volumio[1645]: info: CoreCommandRouter::volumioGetState Jan 27 14:14:50 volumio volumio[1645]: info: CorePlayQueue::getTrack 0 Jan 27 14:14:51 volumio volumio[1645]: 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 27 14:14:51 volumio volumio[1645]: info: Spotify Successfully logged in Jan 27 14:14:51 volumio volumio[1645]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 27 14:14:51 volumio volumio[1645]: info: [1769498091122] CoreMusicLibrary::Adding element Spotify Jan 27 14:14:51 volumio volumio[1645]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 27 14:14:51 volumio volumio[1645]: Cannot find translation for source YouTube Music Jan 27 14:14:51 volumio volumio[1645]: Cannot find translation for source Spotify Jan 27 14:14:51 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 14:14:51 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 14:14:51 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 14:14:51 volumio volumio[1645]: info: [yt-cast-receiver] DIAL server listening on port 8098 Jan 27 14:14:51 volumio volumio[1645]: info: CoreCommandRouter::volumioRetrievevolume Jan 27 14:14:52 volumio volumio[1645]: info: VolumeController:: Volume=100 Mute =false Jan 27 14:14:52 volumio volumio[1645]: info: CoreCommandRouter::volumioGetState Jan 27 14:14:52 volumio volumio[1645]: info: CorePlayQueue::getTrack 0 Jan 27 14:14:52 volumio volumio[1645]: info: CoreStateMachine::pushState Jan 27 14:14:52 volumio volumio[1645]: info: CorePlayQueue::getTrack 0 Jan 27 14:14:52 volumio volumio[1645]: info: CoreCommandRouter::volumioPushState Jan 27 14:14:53 volumio volumio[1645]: info: go-librespot daemon successfully initialized Jan 27 14:14:53 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 14:14:53 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 14:14:53 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 14:14:53 volumio mpd[1871]: 2026-01-27T14:14:53 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 27 14:14:53 volumio systemd[1]: Started mpd.service - Music Player Daemon. Jan 27 14:14:53 volumio sudo[1832]: pam_unix(sudo:session): session closed for user root Jan 27 14:14:53 volumio sudo[1843]: pam_unix(sudo:session): session closed for user root Jan 27 14:14:53 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Jan 27 14:14:53 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 14:14:53 volumio go-librespot[1983]: go-librespot daemon starting... Jan 27 14:14:53 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 14:14:53 volumio go-librespot[1984]: time="2026-01-27T14:14:53+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 14:14:53 volumio go-librespot[1984]: time="2026-01-27T14:14:53+07:00" level=debug msg="app state loaded" Jan 27 14:14:53 volumio go-librespot[1984]: time="2026-01-27T14:14:53+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 14:14:53 volumio volumio[1645]: error: MPD error: The expression evaluated to a falsy value: Jan 27 14:14:53 volumio volumio[1645]: assert.ok(self.idling) Jan 27 14:14:53 volumio volumio[1645]: error: The expression evaluated to a falsy value: Jan 27 14:14:53 volumio volumio[1645]: assert.ok(self.idling) Jan 27 14:14:53 volumio volumio[1645]: error: updateQueue error: null Jan 27 14:14:53 volumio volumio[1645]: info: MPD running with PID1871 Jan 27 14:14:53 volumio volumio[1645]: ,establishing connection Jan 27 14:14:54 volumio volumio[1645]: info: Completed starting Core Plugins Jan 27 14:14:54 volumio volumio[1645]: info: ------------------------------------------- Jan 27 14:14:54 volumio volumio[1645]: info: ----- MyVolumio plugins startup ---- Jan 27 14:14:54 volumio volumio[1645]: info: ------------------------------------------- Jan 27 14:14:54 volumio volumio[1645]: info: [MyVolumio PluginManager] Fetching plans data.... Jan 27 14:14:54 volumio volumio[1645]: error: updateQueue error: null Jan 27 14:14:54 volumio go-librespot[1984]: time="2026-01-27T14:14:54+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 27 14:14:54 volumio go-librespot[1984]: time="2026-01-27T14:14:54+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 27 14:14:54 volumio go-librespot[1984]: time="2026-01-27T14:14:54+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 27 14:14:54 volumio go-librespot[1984]: time="2026-01-27T14:14:54+07:00" level=info msg="zeroconf server listening on port 40085" Jan 27 14:14:54 volumio go-librespot[1984]: time="2026-01-27T14:14:54+07:00" level=debug msg="obtained new client token: AABdvNw6gvRqFr1ZBCuvthrua9tjiXoBmljOsCa3MHwmkN721GRarK72sXSSOVdTXF0K9GXMQ/4ZL3zr2/nOCUV8YtGEjSFqcuJW7k3zwcBBM5MrVM3qD66iF6TIHqqJ1iDOAiOlKFAoG+PGi1+RThW3B5SRlZbP6FBshNAIo5NeIO4xguQV2eJT8PRKLRfpjtU80dFr+aDsH2o7AxviKcM8KrSUQGHf2k0K8pdHTLxnNRi8FtvPKfBXhGE=" Jan 27 14:14:54 volumio go-librespot[1984]: time="2026-01-27T14:14:54+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 14:14:54 volumio go-librespot[1984]: time="2026-01-27T14:14:54+07:00" level=debug msg="completed keyexchange" Jan 27 14:14:54 volumio go-librespot[1984]: time="2026-01-27T14:14:54+07:00" level=debug msg="completed challenge" Jan 27 14:14:55 volumio go-librespot[1984]: time="2026-01-27T14:14:55+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 27 14:14:55 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 14:14:55 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 14:14:55 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 14:14:55 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 14:14:55 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 14:14:56 volumio volumio[1645]: info: Initializing connection to go-librespot Websocket Jan 27 14:14:56 volumio volumio[1645]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 27 14:14:57 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 14:14:57 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 14:14:57 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 14:14:58 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Jan 27 14:14:58 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 14:14:58 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 14:14:58 volumio go-librespot[1991]: go-librespot daemon starting... Jan 27 14:14:58 volumio go-librespot[1992]: time="2026-01-27T14:14:58+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 14:14:58 volumio go-librespot[1992]: time="2026-01-27T14:14:58+07:00" level=debug msg="app state loaded" Jan 27 14:14:58 volumio go-librespot[1992]: time="2026-01-27T14:14:58+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 14:14:58 volumio volumio[1645]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Jan 27 14:14:58 volumio go-librespot[1992]: time="2026-01-27T14:14:58+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 27 14:14:58 volumio go-librespot[1992]: time="2026-01-27T14:14:58+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 27 14:14:58 volumio go-librespot[1992]: time="2026-01-27T14:14:58+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 27 14:14:58 volumio go-librespot[1992]: time="2026-01-27T14:14:58+07:00" level=info msg="zeroconf server listening on port 33791" Jan 27 14:14:59 volumio go-librespot[1992]: time="2026-01-27T14:14:59+07:00" level=debug msg="obtained new client token: AABD1ZM7pfcT5Y2DunhUYjdjQmw6vKx2+dzR67KkdiNRiyLAfEUditXHrEZ5W3QYPuzbdhdKIStinJxwVrsITIfgPB0DYX0C8Hk/fkY52brDB+pDA2iz3Q72Q1Nh195KWUNr7T/GiD/lnR3BPvEmob14lDtH6WqXsSOvz/WfuvyyxQOTIM6bRJ3IfeNC5tNC64hCf+Q0vVfmCIkUVvXaMPLrYWZXHUKqSDRKKSX86yKCPw2o+0DmpAgw" Jan 27 14:14:59 volumio volumio[1645]: info: Initializing connection to go-librespot Websocket Jan 27 14:14:59 volumio go-librespot[1992]: time="2026-01-27T14:14:59+07:00" level=debug msg="new websocket client" Jan 27 14:14:59 volumio go-librespot[1992]: time="2026-01-27T14:14:59+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 14:14:59 volumio volumio[1645]: info: Connection to go-librespot Websocket established Jan 27 14:14:59 volumio go-librespot[1992]: time="2026-01-27T14:14:59+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Jan 27 14:14:59 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 14:14:59 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 14:14:59 volumio volumio[1645]: info: Connection to go-librespot Websocket closed Jan 27 14:14:59 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 14:14:59 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 14:14:59 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 14:15:01 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 14:15:01 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 14:15:01 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 14:15:02 volumio volumio[1645]: info: Getting Spotify volume Jan 27 14:15:02 volumio volumio[1645]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 27 14:15:02 volumio volumio[1645]: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 27 14:15:02 volumio volumio[1645]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Jan 27 14:15:02 volumio volumio[1645]: errno: -111, Jan 27 14:15:02 volumio volumio[1645]: code: 'ECONNREFUSED', Jan 27 14:15:02 volumio volumio[1645]: syscall: 'connect', Jan 27 14:15:02 volumio volumio[1645]: address: '127.0.0.1', Jan 27 14:15:02 volumio volumio[1645]: port: 9879, Jan 27 14:15:02 volumio volumio[1645]: response: undefined Jan 27 14:15:02 volumio volumio[1645]: } Jan 27 14:15:02 volumio volumio[1645]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 27 14:15:02 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Jan 27 14:15:02 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 14:15:02 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 14:15:02 volumio go-librespot[2010]: go-librespot daemon starting... Jan 27 14:15:02 volumio go-librespot[2011]: time="2026-01-27T14:15:02+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 14:15:02 volumio go-librespot[2011]: time="2026-01-27T14:15:02+07:00" level=debug msg="app state loaded" Jan 27 14:15:02 volumio go-librespot[2011]: time="2026-01-27T14:15:02+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 14:15:03 volumio go-librespot[2011]: time="2026-01-27T14:15:03+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 27 14:15:03 volumio go-librespot[2011]: time="2026-01-27T14:15:03+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 27 14:15:03 volumio go-librespot[2011]: time="2026-01-27T14:15:03+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 27 14:15:03 volumio go-librespot[2011]: time="2026-01-27T14:15:03+07:00" level=info msg="zeroconf server listening on port 38091" Jan 27 14:15:03 volumio go-librespot[2011]: time="2026-01-27T14:15:03+07:00" level=debug msg="obtained new client token: AADAaNTEyoivrTO+e5bcNzUz/S8/Rr4X2mpLe2ROB8sOKXLic6Zj/EHE+NEOhgGpbC4I4R1YNEFSmAkMmT7vnnv/ZiImw7IXx5EIw8HDq09c+aIMjyO3QEDwOzTF//+VLuuPpM2wKC1tshyDJPm4TiHi47DZIWjqsCfcBLm6xtuyslYxvh5Z7S+NQ2Lvs1Z+QK0FajPkctxkOsRVR7NfWPRJ0xGKKkWrUyEx1wtGQT+v+j0Y3+CqZT/zVBI=" Jan 27 14:15:03 volumio go-librespot[2011]: time="2026-01-27T14:15:03+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 14:15:03 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 14:15:03 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 14:15:03 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 14:15:03 volumio go-librespot[2011]: time="2026-01-27T14:15:03+07:00" level=debug msg="completed keyexchange" Jan 27 14:15:03 volumio go-librespot[2011]: time="2026-01-27T14:15:03+07:00" level=debug msg="completed challenge" Jan 27 14:15:03 volumio go-librespot[2011]: time="2026-01-27T14:15:03+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 27 14:15:03 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 14:15:03 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 14:15:03 volumio sudo[2036]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-01-27 14:14' Jan 27 14:15:03 volumio sudo[2036]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 14:15:04 volumio sudo[2036]: pam_unix(sudo:session): session closed for user root Jan 27 14:15:04 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Jan 27 14:15:04 volumio volumio-remote-updater[628]: [2026-01-27 14:15:04] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Jan 27 14:15:04 volumio volumio-remote-updater[628]: [2026-01-27 14:15:04] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Jan 27 14:15:04 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Jan 27 14:15:04 volumio systemd[1]: volumio.service: Consumed 1min 2.250s CPU time. Jan 27 14:15:04 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 27 14:15:04 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Jan 27 14:15:04 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 8662. Jan 27 14:15:04 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 27 14:15:04 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Jan 27 14:15:04 volumio systemd[1]: volumio.service: Consumed 1min 2.250s CPU time. Jan 27 14:15:04 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Jan 27 14:15:04 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Jan 27 14:15:05 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 14:15:05 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 14:15:05 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 14:15:06 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Jan 27 14:15:06 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 14:15:07 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 14:15:07 volumio go-librespot[2067]: go-librespot daemon starting... Jan 27 14:15:07 volumio go-librespot[2068]: time="2026-01-27T14:15:07+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 14:15:07 volumio go-librespot[2068]: time="2026-01-27T14:15:07+07:00" level=debug msg="app state loaded" Jan 27 14:15:07 volumio go-librespot[2068]: time="2026-01-27T14:15:07+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 14:15:07 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 14:15:07 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 14:15:07 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 14:15:07 volumio go-librespot[2068]: time="2026-01-27T14:15:07+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 27 14:15:07 volumio go-librespot[2068]: time="2026-01-27T14:15:07+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 27 14:15:07 volumio go-librespot[2068]: time="2026-01-27T14:15:07+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 27 14:15:07 volumio go-librespot[2068]: time="2026-01-27T14:15:07+07:00" level=info msg="zeroconf server listening on port 40457" Jan 27 14:15:07 volumio go-librespot[2068]: time="2026-01-27T14:15:07+07:00" level=debug msg="obtained new client token: AACZYqlAa1ja6xXqAXpocy067YOT4Mun7zkippVx/QhWPWp2znz41LaUYVIIeYUBiowwEL9m+Bg1CIiBAu6URnwW9ySrQr3Shqo5AWdrXuTI1TdLie9u53IqDNfVXOeKNDAIS27QMYUJA3jeuClliHY1hl0aqEcwbu0X3MmZ+ZAq29LqbcybMiIrbs6TaYG88d570iAfrAbqorb7hBIhtSJofXYw6Dhi/U5z1mhKoaRQSHhtOmsPphxXNms=" Jan 27 14:15:07 volumio go-librespot[2068]: time="2026-01-27T14:15:07+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 14:15:08 volumio go-librespot[2068]: time="2026-01-27T14:15:08+07:00" level=debug msg="completed keyexchange" Jan 27 14:15:08 volumio go-librespot[2068]: time="2026-01-27T14:15:08+07:00" level=debug msg="completed challenge" Jan 27 14:15:08 volumio go-librespot[2068]: time="2026-01-27T14:15:08+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 27 14:15:08 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 14:15:08 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 14:15:08 volumio volumio[2049]: info: ------------------------------------------- Jan 27 14:15:08 volumio volumio[2049]: info: ----- Volumio3 ---- Jan 27 14:15:08 volumio volumio[2049]: info: ------------------------------------------- Jan 27 14:15:08 volumio volumio[2049]: info: ----- System startup ---- Jan 27 14:15:08 volumio volumio[2049]: info: ------------------------------------------- Jan 27 14:15:09 volumio volumio-remote-updater[628]: [2026-01-27 14:15:09] [connect] Successful connection Jan 27 14:15:09 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 14:15:09 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 14:15:09 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 14:15:09 volumio volumio[2049]: info: MYVOLUMIO Environment detected Jan 27 14:15:09 volumio volumio[2049]: info: Plugin folders cleanup Jan 27 14:15:09 volumio volumio[2049]: info: Scanning into folder /volumio/app/plugins/ Jan 27 14:15:09 volumio volumio[2049]: info: Scanning category audio_interface Jan 27 14:15:09 volumio volumio[2049]: info: Scanning category miscellanea Jan 27 14:15:09 volumio volumio[2049]: info: Scanning category music_service Jan 27 14:15:09 volumio volumio[2049]: info: Scanning category plugins.json Jan 27 14:15:09 volumio volumio[2049]: info: Scanning category system_controller Jan 27 14:15:09 volumio volumio[2049]: info: Scanning category user_interface Jan 27 14:15:09 volumio volumio[2049]: info: Scanning into folder /data/plugins/ Jan 27 14:15:09 volumio volumio[2049]: info: Scanning category music_service Jan 27 14:15:09 volumio volumio[2049]: info: Plugin folders cleanup completed Jan 27 14:15:09 volumio volumio[2049]: info: ------------------------------------------- Jan 27 14:15:09 volumio volumio[2049]: info: ----- Core plugins startup ---- Jan 27 14:15:09 volumio volumio[2049]: info: ------------------------------------------- Jan 27 14:15:09 volumio volumio[2049]: info: Loading plugins from folder /volumio/app/plugins/ Jan 27 14:15:09 volumio volumio[2049]: info: Adding plugin upnp to MyMusic Plugins Jan 27 14:15:09 volumio volumio[2049]: info: Adding plugin airplay_emulation to MyMusic Plugins Jan 27 14:15:09 volumio volumio[2049]: info: Adding plugin upnp_browser to MyMusic Plugins Jan 27 14:15:09 volumio volumio[2049]: info: Loading plugins from folder /data/plugins/ Jan 27 14:15:09 volumio volumio[2049]: info: Loading plugin "system"... Jan 27 14:15:09 volumio volumio[2049]: info: Loading plugin "appearance"... Jan 27 14:15:11 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Jan 27 14:15:11 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 14:15:11 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 14:15:11 volumio go-librespot[2087]: go-librespot daemon starting... Jan 27 14:15:11 volumio go-librespot[2088]: time="2026-01-27T14:15:11+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 14:15:11 volumio go-librespot[2088]: time="2026-01-27T14:15:11+07:00" level=debug msg="app state loaded" Jan 27 14:15:11 volumio go-librespot[2088]: time="2026-01-27T14:15:11+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 14:15:11 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 14:15:11 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 14:15:11 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 14:15:11 volumio volumio[2049]: info: Loading plugin "network"... Jan 27 14:15:11 volumio volumio[2049]: info: Refreshing Cached IP Addresses Jan 27 14:15:11 volumio sudo[2096]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 27 14:15:11 volumio sudo[2096]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 14:15:11 volumio sudo[2098]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 27 14:15:11 volumio sudo[2098]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 14:15:11 volumio sudo[2096]: pam_unix(sudo:session): session closed for user root Jan 27 14:15:11 volumio volumio[2049]: info: Loading plugin "services"... Jan 27 14:15:11 volumio go-librespot[2088]: time="2026-01-27T14:15:11+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 27 14:15:11 volumio go-librespot[2088]: time="2026-01-27T14:15:11+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 27 14:15:11 volumio go-librespot[2088]: time="2026-01-27T14:15:11+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 27 14:15:11 volumio volumio[2049]: info: Loading plugin "alsa_controller"... Jan 27 14:15:11 volumio sudo[2098]: pam_unix(sudo:session): session closed for user root Jan 27 14:15:11 volumio go-librespot[2088]: time="2026-01-27T14:15:11+07:00" level=info msg="zeroconf server listening on port 35487" Jan 27 14:15:11 volumio sudo[2108]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Jan 27 14:15:11 volumio sudo[2108]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 14:15:12 volumio volumio[2049]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 27 14:15:12 volumio volumio[2049]: info: Loading plugin "wizard"... Jan 27 14:15:12 volumio volumio[2049]: info: Loading plugin "networkfs"... Jan 27 14:15:12 volumio volumio[2049]: info: Starting Udev Watcher for removable devices Jan 27 14:15:12 volumio go-librespot[2088]: time="2026-01-27T14:15:12+07:00" level=debug msg="obtained new client token: AAAE/MH3LEqeq/39GXHJdPI7YRzwGwPflXsHCB5ELFLTbpFWxWdDkBrKTD1pjlz0SZFY0is05Tw7HFGmZynE9RwQ6qpaMC7+nJUxYmxsxX24OQN7zaPJ3I4ZmPuOThKuuK7UwsEMUrsvCMEZjwf5CeopabtPfeqA/96jVEZOpvC633mmfp9M1FBt17AGd4NMVe5+blMkJoi/Sl80bvRiD5J0iPwcT5oGw5XSmotSdey61IrvOLtn3cB5" Jan 27 14:15:12 volumio volumio[2049]: info: Ignoring mount for partition: boot Jan 27 14:15:12 volumio volumio[2049]: info: Ignoring mount for partition: volumio Jan 27 14:15:12 volumio volumio[2049]: info: Ignoring mount for partition: volumio_data Jan 27 14:15:12 volumio volumio[2049]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 27 14:15:12 volumio volumio[2049]: info: Loading plugin "volumio_command_line_client"... Jan 27 14:15:12 volumio volumio[2049]: info: Loading plugin "upnp"... Jan 27 14:15:12 volumio volumio[2049]: info: [1769498112236] Starting Upmpd Daemon Jan 27 14:15:12 volumio volumio[2049]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 27 14:15:12 volumio volumio[2049]: info: Loading plugin "my_music"... Jan 27 14:15:12 volumio volumio[2049]: info: Loading plugin "mpd"... Jan 27 14:15:12 volumio go-librespot[2088]: time="2026-01-27T14:15:12+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 14:15:12 volumio go-librespot[2088]: time="2026-01-27T14:15:12+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Jan 27 14:15:12 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 14:15:12 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 14:15:12 volumio volumio[2049]: info: Loading plugin "upnp_browser"... Jan 27 14:15:13 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 14:15:13 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 14:15:13 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 14:15:14 volumio sudo[2108]: pam_unix(sudo:session): session closed for user root Jan 27 14:15:15 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Jan 27 14:15:15 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 14:15:15 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 14:15:15 volumio go-librespot[2129]: go-librespot daemon starting... Jan 27 14:15:15 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 14:15:15 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 14:15:15 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 14:15:15 volumio go-librespot[2130]: time="2026-01-27T14:15:15+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 14:15:15 volumio go-librespot[2130]: time="2026-01-27T14:15:15+07:00" level=debug msg="app state loaded" Jan 27 14:15:15 volumio go-librespot[2130]: time="2026-01-27T14:15:15+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 14:15:15 volumio volumio[2049]: info: Starting UPNP Browser Jan 27 14:15:15 volumio volumio[2049]: info: Loading plugin "alarm-clock"... Jan 27 14:15:16 volumio volumio[2049]: info: Loading plugin "airplay_emulation"... Jan 27 14:15:16 volumio volumio[2049]: info: Starting Shairport Sync Jan 27 14:15:16 volumio volumio[2049]: info: Loading plugin "last_100"... Jan 27 14:15:16 volumio volumio[2049]: info: Loading plugin "webradio"... Jan 27 14:15:16 volumio go-librespot[2130]: time="2026-01-27T14:15:16+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 27 14:15:16 volumio go-librespot[2130]: time="2026-01-27T14:15:16+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 27 14:15:16 volumio go-librespot[2130]: time="2026-01-27T14:15:16+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 27 14:15:16 volumio go-librespot[2130]: time="2026-01-27T14:15:16+07:00" level=info msg="zeroconf server listening on port 34537" Jan 27 14:15:16 volumio volumio[2049]: info: Loading plugin "i2s_dacs"... Jan 27 14:15:16 volumio volumio[2049]: info: Loading plugin "volumiodiscovery"... Jan 27 14:15:16 volumio volumio[2049]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 27 14:15:16 volumio volumio[2049]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 27 14:15:16 volumio volumio[2049]: *** WARNING *** For more information see Jan 27 14:15:16 volumio volumio[2049]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 27 14:15:16 volumio volumio[2049]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 27 14:15:16 volumio volumio[2049]: *** WARNING *** For more information see Jan 27 14:15:16 volumio node[2049]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 27 14:15:16 volumio node[2049]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 27 14:15:16 volumio node[2049]: *** WARNING *** For more information see Jan 27 14:15:16 volumio node[2049]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 27 14:15:16 volumio node[2049]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 27 14:15:16 volumio node[2049]: *** WARNING *** For more information see Jan 27 14:15:16 volumio volumio[2049]: info: Applying required configuration parameters for plugin volumiodiscovery Jan 27 14:15:16 volumio volumio[2049]: info: Discovery: Started advertising with name: Volumio Jan 27 14:15:16 volumio go-librespot[2130]: time="2026-01-27T14:15:16+07:00" level=debug msg="obtained new client token: AACxCf42IpSjFO6DqMZ7gD2i4l3949S6iiX0rpmiTk3e4tXtnOATThDu5RD2tr+3/d/h6XUQcPuBBKrSsx/uai+96cc6BRw2+gm564oDJ19tvFd5h1Y4QzxfXfLUUWl16HQtz4/zyqjdr8lnVgpNnItGmECwjdY9bWqjzw4Qz1zdj0/5qV6XY5z0tCsX4oi8xQE57kTtMitohAcCTzGufEKmnuQL7lTmETgLT8ubsu3ao/pOgmFzchZsEcw=" Jan 27 14:15:16 volumio volumio[2049]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 27 14:15:16 volumio volumio[2049]: info: Loading plugin "spop"... Jan 27 14:15:16 volumio go-librespot[2130]: time="2026-01-27T14:15:16+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 14:15:16 volumio go-librespot[2130]: time="2026-01-27T14:15:16+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Jan 27 14:15:16 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 14:15:16 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 14:15:17 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 14:15:17 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 14:15:17 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 14:15:18 volumio volumio[2049]: info: Loading plugin "ytcr"... Jan 27 14:15:19 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 14:15:19 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 14:15:19 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 14:15:19 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Jan 27 14:15:19 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 14:15:19 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 14:15:19 volumio go-librespot[2140]: go-librespot daemon starting... Jan 27 14:15:19 volumio go-librespot[2141]: time="2026-01-27T14:15:19+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 14:15:19 volumio go-librespot[2141]: time="2026-01-27T14:15:19+07:00" level=debug msg="app state loaded" Jan 27 14:15:19 volumio go-librespot[2141]: time="2026-01-27T14:15:19+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 14:15:20 volumio go-librespot[2141]: time="2026-01-27T14:15:20+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 27 14:15:20 volumio go-librespot[2141]: time="2026-01-27T14:15:20+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 27 14:15:20 volumio go-librespot[2141]: time="2026-01-27T14:15:20+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 27 14:15:20 volumio go-librespot[2141]: time="2026-01-27T14:15:20+07:00" level=info msg="zeroconf server listening on port 39099" Jan 27 14:15:20 volumio go-librespot[2141]: time="2026-01-27T14:15:20+07:00" level=debug msg="obtained new client token: AABKF0kEPJi8bN5xvVvpDTHUaiy5iqh1p7P9HgeEB4v1o4fpR/11E2uOk2NdBOzQmy4PLMrYrcjOsbHDTd1BRyB5efZY01s6sIB+55QIW+FndIOkrNuw8mzjh5HbArfIItRmEUpHRr26RZSXXwJJU0U7boFVZszQHZMlvYlpfe5nBuUiaEJbKfHAdkRscTHVW+JCYAHlKK5szwUeKjEl9e1YhMmBP9fSRYcsI3TFSyJ5xRE+7u8l+IZjkxc=" Jan 27 14:15:20 volumio go-librespot[2141]: time="2026-01-27T14:15:20+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 14:15:20 volumio go-librespot[2141]: time="2026-01-27T14:15:20+07:00" level=debug msg="completed keyexchange" Jan 27 14:15:20 volumio go-librespot[2141]: time="2026-01-27T14:15:20+07:00" level=debug msg="completed challenge" Jan 27 14:15:20 volumio go-librespot[2141]: time="2026-01-27T14:15:20+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 27 14:15:20 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 14:15:20 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 14:15:21 volumio volumio[2049]: info: Loading plugin "ytmusic"... Jan 27 14:15:21 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 14:15:21 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 14:15:21 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 14:15:21 volumio volumio-remote-updater[628]: [2026-01-27 14:15:21] [connect] Successful connection Jan 27 14:15:22 volumio volumio[2049]: info: Loading plugin "outputs"... Jan 27 14:15:22 volumio volumio[2049]: info: Loading plugin "albumart"... Jan 27 14:15:22 volumio volumio[2049]: info: Plugin example_plugin is not enabled Jan 27 14:15:22 volumio volumio[2049]: info: Loading plugin "inputs"... Jan 27 14:15:22 volumio volumio[2049]: info: Loading plugin "updater_comm"... Jan 27 14:15:22 volumio volumio[2049]: info: Plugin mpdemulation is not enabled Jan 27 14:15:22 volumio volumio[2049]: info: Loading plugin "rest_api"... Jan 27 14:15:22 volumio volumio[2049]: info: Loading plugin "websocket"... Jan 27 14:15:22 volumio volumio[2049]: info: Starting Socket.io Server version 1.7.4 Jan 27 14:15:22 volumio volumio[2049]: info: Loading plugin "RoonBridge"... Jan 27 14:15:22 volumio volumio[2049]: info: Applying required configuration parameters for plugin RoonBridge Jan 27 14:15:22 volumio volumio[2049]: info: Loading i18n strings for locale en Jan 27 14:15:23 volumio volumio[2049]: Updating browse sources language Jan 27 14:15:23 volumio volumio[2049]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 27 14:15:23 volumio volumio[2049]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 27 14:15:23 volumio volumio[2049]: info: CoreCommandRouter::initPlayerControls Jan 27 14:15:23 volumio volumio[2049]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 14:15:23 volumio volumio[2049]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 14:15:23 volumio volumio[2049]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 14:15:23 volumio volumio[2049]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 14:15:23 volumio volumio[2049]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 14:15:23 volumio volumio[2049]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 14:15:23 volumio volumio[2049]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 14:15:23 volumio volumio[2049]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 14:15:23 volumio volumio[2049]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 27 14:15:23 volumio volumio[2049]: Express server listening on port 3000 Jan 27 14:15:23 volumio volumio[2049]: [Metrics] WebUI: 16s 48.73ms Jan 27 14:15:23 volumio volumio[2162]: Forking 3 albumart workers Jan 27 14:15:23 volumio volumio[2049]: info: CoreStateMachine::resetVolumioState Jan 27 14:15:23 volumio volumio[2049]: info: CoreStateMachine::getcurrentVolume Jan 27 14:15:23 volumio volumio[2049]: info: CoreCommandRouter::volumioRetrievevolume Jan 27 14:15:23 volumio sudo[2190]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 27 14:15:23 volumio sudo[2190]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 14:15:23 volumio sudo[2190]: pam_unix(sudo:session): session closed for user root Jan 27 14:15:23 volumio sudo[2187]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 27 14:15:23 volumio sudo[2187]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 14:15:23 volumio sudo[2187]: pam_unix(sudo:session): session closed for user root Jan 27 14:15:23 volumio volumio[2049]: info: Volumio Network Manager: Network status updated: 1 Jan 27 14:15:23 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 14:15:23 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 14:15:23 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 14:15:23 volumio volumio[2049]: info: VolumeController:: Volume=100 Mute =false Jan 27 14:15:23 volumio volumio[2049]: info: CoreStateMachine::pushState Jan 27 14:15:23 volumio volumio[2049]: info: CorePlayQueue::getTrack 0 Jan 27 14:15:23 volumio volumio[2049]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 27 14:15:23 volumio volumio[2049]: info: CoreCommandRouter::volumioPushState Jan 27 14:15:23 volumio volumio[2049]: info: CoreStateMachine::updateTrackBlock Jan 27 14:15:23 volumio volumio[2049]: info: CorePlayQueue::getTrackBlock Jan 27 14:15:23 volumio volumio[2049]: info: CoreCommandRouter::volumioRetrievevolume Jan 27 14:15:23 volumio volumio-remote-updater[628]: [2026-01-27 14:15:23] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1769498121 101 Jan 27 14:15:23 volumio volumio[2049]: 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 27 14:15:23 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Jan 27 14:15:24 volumio volumio[2049]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 14:15:23 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 14:15:24 volumio volumio[2049]: info: Reloading queue from file Jan 27 14:15:24 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 14:15:24 volumio go-librespot[2215]: go-librespot daemon starting... Jan 27 14:15:24 volumio volumio[2049]: info: CoreStateMachine::setRepeat null single undefined Jan 27 14:15:24 volumio volumio[2049]: info: CoreStateMachine::pushState Jan 27 14:15:24 volumio volumio[2049]: info: CorePlayQueue::getTrack 0 Jan 27 14:15:24 volumio volumio[2049]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 27 14:15:24 volumio volumio[2049]: info: CoreCommandRouter::volumioPushState Jan 27 14:15:24 volumio volumio[2049]: info: CoreStateMachine::setRandom null Jan 27 14:15:24 volumio volumio[2049]: info: CoreStateMachine::pushState Jan 27 14:15:24 volumio volumio[2049]: info: CorePlayQueue::getTrack 0 Jan 27 14:15:24 volumio volumio[2049]: info: CoreCommandRouter::volumioPushState Jan 27 14:15:24 volumio go-librespot[2221]: time="2026-01-27T14:15:24+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 14:15:24 volumio go-librespot[2221]: time="2026-01-27T14:15:24+07:00" level=debug msg="app state loaded" Jan 27 14:15:24 volumio go-librespot[2221]: time="2026-01-27T14:15:24+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 14:15:24 volumio volumio[2049]: info: Setting Device type: Raspberry PI Jan 27 14:15:24 volumio volumio[2049]: info: Completed loading Core Plugins Jan 27 14:15:24 volumio volumio[2049]: info: Preparing to generate the ALSA configuration file Jan 27 14:15:24 volumio volumio[2049]: info: VolumeController:: Volume=100 Mute =false Jan 27 14:15:24 volumio volumio[2049]: info: CoreStateMachine::pushState Jan 27 14:15:24 volumio volumio[2049]: info: CorePlayQueue::getTrack 0 Jan 27 14:15:24 volumio volumio[2049]: info: CoreCommandRouter::volumioPushState Jan 27 14:15:24 volumio volumio[2049]: info: Asound.conf file unchanged, so no further update is needed Jan 27 14:15:24 volumio volumio[2049]: info: Output device has changed, restarting MPD Jan 27 14:15:24 volumio sudo[2230]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Jan 27 14:15:24 volumio sudo[2230]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 14:15:24 volumio volumio[2049]: info: Output device has changed, restarting Shairport Sync Jan 27 14:15:24 volumio volumio[2049]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 14:15:24 volumio volumio[2049]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 14:15:24 volumio sudo[2234]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 27 14:15:24 volumio sudo[2234]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 14:15:24 volumio sudo[2234]: pam_unix(sudo:session): session closed for user root Jan 27 14:15:24 volumio volumio[2049]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 27 14:15:24 volumio volumio[2049]: info: ___________ START PLUGINS ___________ Jan 27 14:15:24 volumio sudo[2230]: pam_unix(sudo:session): session closed for user root Jan 27 14:15:24 volumio sudo[2238]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 27 14:15:24 volumio sudo[2238]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 14:15:24 volumio volumio[2049]: info: ControllerMpd::onStart: Initializing MPD Jan 27 14:15:24 volumio volumio[2049]: info: Creating MPD Configuration file Jan 27 14:15:24 volumio sudo[2245]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 27 14:15:24 volumio sudo[2245]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 14:15:24 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Jan 27 14:15:24 volumio sudo[2245]: pam_unix(sudo:session): session closed for user root Jan 27 14:15:24 volumio go-librespot[2221]: time="2026-01-27T14:15:24+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 27 14:15:24 volumio go-librespot[2221]: time="2026-01-27T14:15:24+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 27 14:15:24 volumio go-librespot[2221]: time="2026-01-27T14:15:24+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 27 14:15:24 volumio go-librespot[2221]: time="2026-01-27T14:15:24+07:00" level=info msg="zeroconf server listening on port 42353" Jan 27 14:15:24 volumio sudo[2248]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 27 14:15:24 volumio volumio[2049]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 27 14:15:24 volumio volumio[2049]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 27 14:15:24 volumio sudo[2248]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 14:15:25 volumio volumio[2049]: info: [1769498125006] CoreMusicLibrary::Adding element Media Servers Jan 27 14:15:25 volumio volumio[2049]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 27 14:15:25 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 27 14:15:25 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 27 14:15:25 volumio systemd[1]: mpd.service: Consumed 7.303s CPU time. Jan 27 14:15:25 volumio volumio[2049]: info: UPNP Browser: Client initialized successfully Jan 27 14:15:25 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 27 14:15:25 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 27 14:15:25 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 27 14:15:25 volumio volumio[2049]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 14:15:25 volumio volumio[2049]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 14:15:25 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 27 14:15:25 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 27 14:15:25 volumio volumio[2049]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 27 14:15:25 volumio volumio[2049]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 14:15:25 volumio volumio[2049]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 14:15:25 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 27 14:15:25 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 27 14:15:25 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 27 14:15:25 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 27 14:15:25 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 27 14:15:25 volumio go-librespot[2221]: time="2026-01-27T14:15:25+07:00" level=debug msg="obtained new client token: AADbI7QX9GZ3/K3DxZO0lBr9g1jV7zyEAEFFS6YogHXviSKSdCE6u/5NR0LjJnQ5jzJyoto8Q3+sRH6wu6DJWWTAm1xut0Ul//g8GicGQQGI+1vsnz331gtikLj5wW25FJ/6YS/5mLNdcATQgvapMcC8ZIH8RDFaSpgFr1JQ6pAG8mll+H9Z37Z5YEbkD9betIqF6eaCFyL5FLVKW+ogEsb6CIUlbqtrwHNuE4vLNmW/h/EHdqsdMPys" Jan 27 14:15:25 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 27 14:15:25 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 27 14:15:25 volumio volumio[2049]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 27 14:15:25 volumio volumio[2049]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 27 14:15:25 volumio volumio[2049]: info: [1769498125297] CoreMusicLibrary::Adding element Last_100 Jan 27 14:15:25 volumio volumio[2049]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 27 14:15:25 volumio volumio[2049]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 27 14:15:25 volumio volumio[2049]: info: [1769498125311] CoreMusicLibrary::Adding element Webradio Jan 27 14:15:25 volumio volumio[2049]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 27 14:15:25 volumio volumio[2049]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 27 14:15:25 volumio volumio[2049]: info: Initializing BBC Radios Jan 27 14:15:25 volumio go-librespot[2221]: time="2026-01-27T14:15:25+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 14:15:25 volumio go-librespot[2221]: time="2026-01-27T14:15:25+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Jan 27 14:15:25 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 14:15:25 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 14:15:25 volumio volumio[2049]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 27 14:15:25 volumio volumio[2049]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 14:15:25 volumio volumio[2049]: info: Creating Spotify config file Jan 27 14:15:25 volumio volumio[2049]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 14:15:25 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 14:15:25 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 14:15:25 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 14:15:25 volumio sudo[2261]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 27 14:15:25 volumio sudo[2261]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jan 27 14:15:25 volumio sudo[2261]: pam_unix(sudo:session): session closed for user root Jan 27 14:15:26 volumio volumio[2178]: Starting albumart workers Jan 27 14:15:26 volumio volumio[2049]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 27 14:15:26 volumio volumio[2049]: info: [1769498126698] CoreMusicLibrary::Adding element YouTube Music Jan 27 14:15:26 volumio volumio[2049]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 27 14:15:26 volumio volumio[2049]: Cannot find translation for source YouTube Music Jan 27 14:15:26 volumio volumio[2049]: info: Volumio Calling Home Jan 27 14:15:26 volumio volumio[2176]: Starting albumart workers Jan 27 14:15:26 volumio sudo[2278]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Jan 27 14:15:26 volumio sudo[2278]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 14:15:27 volumio sudo[2278]: pam_unix(sudo:session): session closed for user root Jan 27 14:15:27 volumio volumio[2175]: Starting albumart workers Jan 27 14:15:27 volumio volumio[2049]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Jan 27 14:15:27 volumio volumio[2049]: info: Discovery: Found device Volumio Jan 27 14:15:27 volumio volumio[2049]: info: CoreCommandRouter::volumioGetState Jan 27 14:15:27 volumio volumio[2049]: info: CorePlayQueue::getTrack 0 Jan 27 14:15:27 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 14:15:27 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 14:15:27 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 14:15:27 volumio volumio[2049]: info: MPD Permissions set Jan 27 14:15:27 volumio volumio[2049]: info: MPD Permissions set Jan 27 14:15:27 volumio volumio[2049]: info: Upmpdcli Daemon Started Jan 27 14:15:27 volumio volumio[2049]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Jan 27 14:15:27 volumio volumio[2049]: info: Discovery: Found device Volumio Jan 27 14:15:27 volumio volumio[2049]: info: CoreCommandRouter::volumioGetState Jan 27 14:15:27 volumio volumio[2049]: info: CorePlayQueue::getTrack 0 Jan 27 14:15:27 volumio volumio[2049]: info: Volumio called home Jan 27 14:15:27 volumio volumio[2049]: info: Spotify config file written Jan 27 14:15:27 volumio sudo[2284]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jan 27 14:15:27 volumio sudo[2284]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 14:15:27 volumio volumio[2049]: 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 27 14:15:27 volumio volumio[2049]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 14:15:27 volumio volumio[2049]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 14:15:27 volumio volumio[2049]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 14:15:27 volumio volumio[2049]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 14:15:27 volumio volumio[2049]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 14:15:27 volumio volumio[2049]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 14:15:27 volumio volumio[2049]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 14:15:27 volumio volumio[2049]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 14:15:27 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 14:15:27 volumio volumio[2049]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 14:15:27 volumio volumio[2049]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 14:15:28 volumio volumio[2049]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 14:15:28 volumio volumio[2049]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 14:15:28 volumio volumio[2049]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 14:15:28 volumio volumio[2049]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 14:15:28 volumio volumio[2049]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 14:15:28 volumio volumio[2049]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 14:15:28 volumio volumio[2049]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 14:15:28 volumio volumio[2049]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 14:15:28 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 14:15:28 volumio go-librespot[2291]: go-librespot daemon starting... Jan 27 14:15:28 volumio volumio[2049]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 14:15:28 volumio volumio[2049]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 14:15:28 volumio sudo[2284]: pam_unix(sudo:session): session closed for user root Jan 27 14:15:28 volumio volumio[2049]: info: No need to fix Spotify hosts Jan 27 14:15:28 volumio go-librespot[2297]: time="2026-01-27T14:15:28+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 14:15:28 volumio go-librespot[2297]: time="2026-01-27T14:15:28+07:00" level=debug msg="app state loaded" Jan 27 14:15:28 volumio go-librespot[2297]: time="2026-01-27T14:15:28+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 14:15:28 volumio go-librespot[2297]: time="2026-01-27T14:15:28+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 27 14:15:28 volumio go-librespot[2297]: time="2026-01-27T14:15:28+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 27 14:15:28 volumio go-librespot[2297]: time="2026-01-27T14:15:28+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 27 14:15:28 volumio go-librespot[2297]: time="2026-01-27T14:15:28+07:00" level=info msg="zeroconf server listening on port 41311" Jan 27 14:15:29 volumio go-librespot[2297]: time="2026-01-27T14:15:29+07:00" level=debug msg="obtained new client token: AACj/ih/GlkscN+PhcWYrRkk4Q+U01+a6QKe0v3lrv1ho49U1fRebl0YV6mXTcEmEZLsP9lXkUwQ6c8MwXe8t9RgsRApk5xPZEpMuAbeT/R4ttV5RxLgulaJj7ycrjsP/d/7mnXDcWuW+XhAFfdJhiq3DbR7uAHzKBm+jYVVJDvQes5b7ojMI99cxmhw8KOvPlBR6h5PgmN2Dp1lxgfvnmba3ZQsXYVSVEnVEaCQRwbK1PZjE8CxmgFC" Jan 27 14:15:29 volumio go-librespot[2297]: time="2026-01-27T14:15:29+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 14:15:29 volumio go-librespot[2297]: time="2026-01-27T14:15:29+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Jan 27 14:15:29 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 14:15:29 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 14:15:29 volumio volumio[2049]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 27 14:15:29 volumio volumio[2049]: SPOTIFY: BQDKqcM42aezB9uOkIQjErRh2i3zsVgcNIQetybcEKL21eqA0SfeUYFgp__ylNuPFcI2hMNo5BBXFBwZYO7rGqNUYuIVikbgYk2v_5qld_SRd8Rh_2U8skMs1wXgQErrf15ZUjbL3v3uV5rA_PHLAtFd34Xm_jgnf9kM2KzeVSSfuvmru1NUcoFnl7nYb-OrWhR8rmzvJE49cF-4norBMvW8wRjgdqHZ7mLqcQAPELe45WwDZfTUd3LDNAMBLFK1tflElw3PYHKxRgr_Ikkeo4evFoFp13utmTuwr_UYdTjwPdJ329sR3Xjl Jan 27 14:15:29 volumio volumio[2049]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 27 14:15:29 volumio volumio[2049]: info: New Spotify access token = BQDKqcM42aezB9uOkIQjErRh2i3zsVgcNIQetybcEKL21eqA0SfeUYFgp__ylNuPFcI2hMNo5BBXFBwZYO7rGqNUYuIVikbgYk2v_5qld_SRd8Rh_2U8skMs1wXgQErrf15ZUjbL3v3uV5rA_PHLAtFd34Xm_jgnf9kM2KzeVSSfuvmru1NUcoFnl7nYb-OrWhR8rmzvJE49cF-4norBMvW8wRjgdqHZ7mLqcQAPELe45WwDZfTUd3LDNAMBLFK1tflElw3PYHKxRgr_Ikkeo4evFoFp13utmTuwr_UYdTjwPdJ329sR3Xjl Jan 27 14:15:29 volumio volumio[2049]: info: Spotify credentials grant success - running version from March 24, 2019 Jan 27 14:15:29 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 14:15:29 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 14:15:29 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 14:15:29 volumio volumio[2049]: info: Starting Shairport Sync Jan 27 14:15:29 volumio volumio[2049]: info: Starting Shairport Sync Jan 27 14:15:29 volumio volumio[2049]: info: Starting Shairport Sync Jan 27 14:15:29 volumio sudo[2325]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 27 14:15:29 volumio sudo[2325]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 14:15:29 volumio sudo[2329]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 27 14:15:29 volumio sudo[2329]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 14:15:29 volumio sudo[2327]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 27 14:15:29 volumio sudo[2327]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 14:15:29 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 27 14:15:29 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Jan 27 14:15:29 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 27 14:15:29 volumio systemd[1]: shairport-sync.service: Consumed 2.336s CPU time. Jan 27 14:15:30 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 27 14:15:30 volumio volumio[2049]: info: CoreCommandRouter::volumioGetState Jan 27 14:15:30 volumio sudo[2325]: pam_unix(sudo:session): session closed for user root Jan 27 14:15:30 volumio volumio[2049]: info: CorePlayQueue::getTrack 0 Jan 27 14:15:30 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 27 14:15:30 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Jan 27 14:15:30 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 27 14:15:30 volumio volumio[2049]: info: Shairport-Sync Started Jan 27 14:15:30 volumio volumio[2049]: Error adding Membership: Error: addMembership EINVAL Jan 27 14:15:30 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 27 14:15:30 volumio sudo[2329]: pam_unix(sudo:session): session closed for user root Jan 27 14:15:30 volumio sudo[2327]: pam_unix(sudo:session): session closed for user root Jan 27 14:15:30 volumio volumio[2049]: info: Shairport-Sync Started Jan 27 14:15:30 volumio volumio[2049]: info: Shairport-Sync Started Jan 27 14:15:30 volumio volumio[2049]: 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 27 14:15:30 volumio volumio[2049]: info: Spotify Successfully logged in Jan 27 14:15:30 volumio volumio[2049]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 27 14:15:30 volumio volumio[2049]: info: [1769498130376] CoreMusicLibrary::Adding element Spotify Jan 27 14:15:30 volumio volumio[2049]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 27 14:15:30 volumio volumio[2049]: Cannot find translation for source YouTube Music Jan 27 14:15:30 volumio volumio[2049]: Cannot find translation for source Spotify Jan 27 14:15:30 volumio volumio[2049]: info: [yt-cast-receiver] DIAL server listening on port 8098 Jan 27 14:15:30 volumio volumio[2049]: info: CoreCommandRouter::volumioRetrievevolume Jan 27 14:15:31 volumio volumio[2049]: info: VolumeController:: Volume=100 Mute =false Jan 27 14:15:31 volumio volumio[2049]: info: CoreCommandRouter::volumioGetState Jan 27 14:15:31 volumio volumio[2049]: info: CorePlayQueue::getTrack 0 Jan 27 14:15:31 volumio volumio[2049]: info: CoreStateMachine::pushState Jan 27 14:15:31 volumio volumio[2049]: info: CorePlayQueue::getTrack 0 Jan 27 14:15:31 volumio volumio[2049]: info: CoreCommandRouter::volumioPushState Jan 27 14:15:31 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 14:15:31 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 14:15:31 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 14:15:32 volumio volumio[2049]: info: go-librespot daemon successfully initialized Jan 27 14:15:32 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Jan 27 14:15:32 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 14:15:32 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 14:15:32 volumio go-librespot[2365]: go-librespot daemon starting... Jan 27 14:15:32 volumio go-librespot[2366]: time="2026-01-27T14:15:32+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 14:15:32 volumio go-librespot[2366]: time="2026-01-27T14:15:32+07:00" level=debug msg="app state loaded" Jan 27 14:15:32 volumio go-librespot[2366]: time="2026-01-27T14:15:32+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 14:15:33 volumio mpd[2276]: 2026-01-27T14:15:33 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 27 14:15:33 volumio systemd[1]: Started mpd.service - Music Player Daemon. Jan 27 14:15:33 volumio sudo[2248]: pam_unix(sudo:session): session closed for user root Jan 27 14:15:33 volumio go-librespot[2366]: time="2026-01-27T14:15:33+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 27 14:15:33 volumio go-librespot[2366]: time="2026-01-27T14:15:33+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 27 14:15:33 volumio go-librespot[2366]: time="2026-01-27T14:15:33+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 27 14:15:33 volumio sudo[2238]: pam_unix(sudo:session): session closed for user root Jan 27 14:15:33 volumio go-librespot[2366]: time="2026-01-27T14:15:33+07:00" level=info msg="zeroconf server listening on port 37265" Jan 27 14:15:33 volumio go-librespot[2366]: time="2026-01-27T14:15:33+07:00" level=debug msg="obtained new client token: AACVXHWSgSh6sXwRo3ksy+ZrD2EYsfjvzVeJyGDvutlGo4aBaYnu74br5T50vhRjb2WcaLqBDaPvTmcc1cxRZqR4EMPOVAG+T355AP0+ZRkG+bNworxOAvonKtpVkXqEU1ceDgHpAdAnUlM4qJSm01Gv2tEfQ2yg1u/G9tpEvBPX1Y4VyJvbzji5pImF+GrhoC2cHUqHHNtcj82P+5iiqIQN3b2+xWWtlBRpGTIiUeHu0bhIXrtw7wZF498=" Jan 27 14:15:33 volumio volumio[2049]: error: MPD error: The expression evaluated to a falsy value: Jan 27 14:15:33 volumio volumio[2049]: assert.ok(self.idling) Jan 27 14:15:33 volumio volumio[2049]: error: The expression evaluated to a falsy value: Jan 27 14:15:33 volumio volumio[2049]: assert.ok(self.idling) Jan 27 14:15:33 volumio volumio[2049]: info: MPD running with PID2276 Jan 27 14:15:33 volumio volumio[2049]: ,establishing connection Jan 27 14:15:33 volumio volumio[2049]: error: updateQueue error: null Jan 27 14:15:33 volumio go-librespot[2366]: time="2026-01-27T14:15:33+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 14:15:33 volumio volumio[2049]: info: Completed starting Core Plugins Jan 27 14:15:33 volumio volumio[2049]: info: ------------------------------------------- Jan 27 14:15:33 volumio volumio[2049]: info: ----- MyVolumio plugins startup ---- Jan 27 14:15:33 volumio volumio[2049]: info: ------------------------------------------- Jan 27 14:15:33 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 14:15:33 volumio volumio[2049]: info: [MyVolumio PluginManager] Fetching plans data.... Jan 27 14:15:33 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 14:15:33 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 14:15:33 volumio volumio[2049]: error: updateQueue error: null Jan 27 14:15:33 volumio go-librespot[2366]: time="2026-01-27T14:15:33+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Jan 27 14:15:33 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 14:15:33 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 14:15:35 volumio volumio[2049]: info: Initializing connection to go-librespot Websocket Jan 27 14:15:35 volumio volumio[2049]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 27 14:15:35 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 14:15:35 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 14:15:35 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 14:15:36 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Jan 27 14:15:36 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 14:15:36 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 14:15:36 volumio go-librespot[2378]: go-librespot daemon starting... Jan 27 14:15:36 volumio go-librespot[2379]: time="2026-01-27T14:15:36+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 14:15:36 volumio go-librespot[2379]: time="2026-01-27T14:15:36+07:00" level=debug msg="app state loaded" Jan 27 14:15:36 volumio go-librespot[2379]: time="2026-01-27T14:15:36+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 14:15:37 volumio go-librespot[2379]: time="2026-01-27T14:15:37+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 27 14:15:37 volumio go-librespot[2379]: time="2026-01-27T14:15:37+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 27 14:15:37 volumio go-librespot[2379]: time="2026-01-27T14:15:37+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 27 14:15:37 volumio go-librespot[2379]: time="2026-01-27T14:15:37+07:00" level=info msg="zeroconf server listening on port 35333" Jan 27 14:15:37 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 14:15:37 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 14:15:37 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 14:15:37 volumio go-librespot[2379]: time="2026-01-27T14:15:37+07:00" level=debug msg="obtained new client token: AADg++CZ60opjaKrP6J5j0Qg1Gff/k5gdOD5AVOlD/PKYuW3fEEshJASNVsBhP1waTNkZ269cDnzvWihjMCdpuxkjpx3ZRpQtZKaxm86iwZi8sjUiM55iLV0UeKuz6LhTfvQtz8e+DLIgvY1WPDYN/13iPPicGQ5VvDE5ZhAG69rdBAbx5nVooE/iNm7aBtMPSjGBsT7E4xpHUa81nFydAtJKtix4ZE37XV/yQq6LgOv8ymHs5dA9aldyv4=" Jan 27 14:15:37 volumio go-librespot[2379]: time="2026-01-27T14:15:37+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 14:15:37 volumio go-librespot[2379]: time="2026-01-27T14:15:37+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Jan 27 14:15:37 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 14:15:37 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 14:15:38 volumio volumio[2049]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Jan 27 14:15:38 volumio volumio[2049]: info: Initializing connection to go-librespot Websocket Jan 27 14:15:38 volumio volumio[2049]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 27 14:15:39 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 14:15:39 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 14:15:39 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 14:15:40 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 11. Jan 27 14:15:40 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 14:15:41 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 14:15:41 volumio go-librespot[2387]: go-librespot daemon starting... Jan 27 14:15:41 volumio go-librespot[2388]: time="2026-01-27T14:15:41+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 14:15:41 volumio go-librespot[2388]: time="2026-01-27T14:15:41+07:00" level=debug msg="app state loaded" Jan 27 14:15:41 volumio go-librespot[2388]: time="2026-01-27T14:15:41+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 14:15:41 volumio volumio[2049]: info: Initializing connection to go-librespot Websocket Jan 27 14:15:41 volumio go-librespot[2388]: time="2026-01-27T14:15:41+07:00" level=debug msg="new websocket client" Jan 27 14:15:41 volumio volumio[2049]: info: Connection to go-librespot Websocket established Jan 27 14:15:41 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 14:15:41 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 14:15:41 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 14:15:41 volumio go-librespot[2388]: time="2026-01-27T14:15:41+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 27 14:15:41 volumio go-librespot[2388]: time="2026-01-27T14:15:41+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 27 14:15:41 volumio go-librespot[2388]: time="2026-01-27T14:15:41+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 27 14:15:41 volumio go-librespot[2388]: time="2026-01-27T14:15:41+07:00" level=info msg="zeroconf server listening on port 46679" Jan 27 14:15:41 volumio go-librespot[2388]: time="2026-01-27T14:15:41+07:00" level=debug msg="obtained new client token: AABtQtCFhgHIrsJ1zUrwKoKWFLhfE8C4cCG7mhAo96XI/cfCHy3VjaRmAREuQTdbdzzfreBBdnbNa3c3mVKRqh7ZeF6fEn9lXZj4m8qNHUItlclwDNxxBi+E0ywmuqabCwPSp1yuc7ur5sfwb/nWfehDw+wK/GYaSWm1KsMIXGM1TMc9kr81Db7MME8bY8vNoKBjmrrM0BchpPrLXz4/ORwNf917nwOdknZB6seFjHbpUO0n9FrghP19w2o=" Jan 27 14:15:42 volumio go-librespot[2388]: time="2026-01-27T14:15:42+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 14:15:42 volumio go-librespot[2388]: time="2026-01-27T14:15:42+07:00" level=debug msg="completed keyexchange" Jan 27 14:15:42 volumio go-librespot[2388]: time="2026-01-27T14:15:42+07:00" level=debug msg="completed challenge" Jan 27 14:15:42 volumio go-librespot[2388]: time="2026-01-27T14:15:42+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 27 14:15:42 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 14:15:42 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 14:15:42 volumio volumio[2049]: info: Connection to go-librespot Websocket closed Jan 27 14:15:42 volumio volumio[2049]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Jan 27 14:15:42 volumio volumio[2049]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Jan 27 14:15:42 volumio volumio[2049]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Jan 27 14:15:42 volumio volumio[2049]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Jan 27 14:15:42 volumio volumio[2049]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Jan 27 14:15:42 volumio volumio[2049]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Jan 27 14:15:42 volumio volumio[2049]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Jan 27 14:15:42 volumio volumio[2049]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Jan 27 14:15:42 volumio volumio[2049]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Jan 27 14:15:42 volumio volumio[2049]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Jan 27 14:15:42 volumio volumio[2049]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Jan 27 14:15:42 volumio volumio[2049]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Jan 27 14:15:42 volumio volumio[2049]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Jan 27 14:15:42 volumio volumio[2049]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Jan 27 14:15:42 volumio volumio[2049]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Jan 27 14:15:42 volumio volumio[2049]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Jan 27 14:15:42 volumio volumio[2049]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Jan 27 14:15:42 volumio volumio[2049]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Jan 27 14:15:42 volumio volumio[2049]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Jan 27 14:15:42 volumio volumio[2049]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Jan 27 14:15:42 volumio volumio[2049]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Jan 27 14:15:42 volumio volumio[2049]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Jan 27 14:15:42 volumio volumio[2049]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Jan 27 14:15:42 volumio volumio[2049]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Jan 27 14:15:42 volumio volumio[2049]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Jan 27 14:15:42 volumio volumio[2049]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Jan 27 14:15:42 volumio volumio[2049]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Jan 27 14:15:42 volumio volumio[2049]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Jan 27 14:15:42 volumio volumio[2049]: info: Adding plugin bluetooth to MyMusic Plugins Jan 27 14:15:42 volumio volumio[2049]: info: Adding plugin multiroom to MyMusic Plugins Jan 27 14:15:42 volumio volumio[2049]: info: Adding plugin metavolumio to MyMusic Plugins Jan 27 14:15:42 volumio volumio[2049]: info: Adding plugin cd_controller to MyMusic Plugins Jan 27 14:15:42 volumio volumio[2049]: info: Adding plugin qobuzconnect to MyMusic Plugins Jan 27 14:15:42 volumio volumio[2049]: info: Adding plugin smart_inputs to MyMusic Plugins Jan 27 14:15:42 volumio volumio[2049]: info: Adding plugin tidalconnect to MyMusic Plugins Jan 27 14:15:42 volumio volumio[2049]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Jan 27 14:15:43 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 14:15:43 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 14:15:43 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 14:15:44 volumio volumio[2049]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Jan 27 14:15:44 volumio volumio[2049]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Jan 27 14:15:44 volumio volumio[2049]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 14:15:44 volumio volumio[2049]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 14:15:44 volumio volumio[2049]: info: Starting MyVolumio Remote Streaming Endpoints Jan 27 14:15:44 volumio volumio[2049]: info: MyVolumio login type: Token Jan 27 14:15:44 volumio volumio[2049]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Jan 27 14:15:44 volumio volumio[2049]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Jan 27 14:15:45 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 12. Jan 27 14:15:45 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 14:15:45 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 14:15:45 volumio go-librespot[2409]: go-librespot daemon starting... Jan 27 14:15:45 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 14:15:45 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 14:15:45 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 14:15:45 volumio go-librespot[2410]: time="2026-01-27T14:15:45+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 14:15:45 volumio go-librespot[2410]: time="2026-01-27T14:15:45+07:00" level=debug msg="app state loaded" Jan 27 14:15:45 volumio go-librespot[2410]: time="2026-01-27T14:15:45+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 14:15:46 volumio go-librespot[2410]: time="2026-01-27T14:15:46+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 27 14:15:46 volumio go-librespot[2410]: time="2026-01-27T14:15:46+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 27 14:15:46 volumio go-librespot[2410]: time="2026-01-27T14:15:46+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 27 14:15:46 volumio go-librespot[2410]: time="2026-01-27T14:15:46+07:00" level=info msg="zeroconf server listening on port 45495" Jan 27 14:15:46 volumio volumio[2049]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Jan 27 14:15:46 volumio volumio[2049]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Jan 27 14:15:46 volumio volumio[2049]: info: Streaming services startup Jan 27 14:15:46 volumio volumio[2049]: info: Starting Streaming Daemon Jan 27 14:15:46 volumio go-librespot[2410]: time="2026-01-27T14:15:46+07:00" level=debug msg="obtained new client token: AADK38Gzxp9CljZi6F42+qEI1ThAqrcA9ItqQjbYuXGcNelzbRH6waZySSJG2hkWdGyEcPwEvhw9BN4svMc2iILbyNS6wf5ePmClVZoVKGmOBiHawxAOe3gQSZxXkgTVWZrIPdhOVvr1ePWeJTXcChk+OukFkupu/io6gKWmQPBHUPJ8P6SMik3I0Z969OHgD4fy8fqiklOoAVcb2sxhcpz9XlCX48aNc3rPaJuSoUUssxRPZ18yVk5KphA=" Jan 27 14:15:46 volumio volumio[2049]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Jan 27 14:15:46 volumio sudo[2418]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jan 27 14:15:46 volumio sudo[2418]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 14:15:46 volumio sudo[2418]: pam_unix(sudo:session): session closed for user root Jan 27 14:15:46 volumio go-librespot[2410]: time="2026-01-27T14:15:46+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 27 14:15:46 volumio volumio[2049]: info: Getting Spotify volume Jan 27 14:15:46 volumio volumio[2049]: info: Initializing connection to go-librespot Websocket Jan 27 14:15:46 volumio go-librespot[2410]: time="2026-01-27T14:15:46+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Jan 27 14:15:46 volumio volumio[2049]: error: Cannot start Volumio Streaming Daemon Jan 27 14:15:46 volumio volumio[2049]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Jan 27 14:15:46 volumio volumio[2049]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Jan 27 14:15:46 volumio go-librespot[2410]: time="2026-01-27T14:15:46+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Jan 27 14:15:46 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 14:15:46 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 14:15:46 volumio volumio[2049]: info: Error connecting to go-librespot Websocket: Error: socket hang up Jan 27 14:15:46 volumio volumio[2049]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 27 14:15:46 volumio volumio[2049]: Error: socket hang up Jan 27 14:15:46 volumio volumio[2049]: at connResetException (node:internal/errors:720:14) Jan 27 14:15:46 volumio volumio[2049]: at Socket.socketOnEnd (node:_http_client:519:23) Jan 27 14:15:46 volumio volumio[2049]: at Socket.emit (node:events:526:35) Jan 27 14:15:46 volumio volumio[2049]: at endReadableNT (node:internal/streams/readable:1376:12) Jan 27 14:15:46 volumio volumio[2049]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Jan 27 14:15:46 volumio volumio[2049]: code: 'ECONNRESET', Jan 27 14:15:46 volumio volumio[2049]: response: undefined Jan 27 14:15:46 volumio volumio[2049]: } Jan 27 14:15:46 volumio volumio[2049]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 27 14:15:47 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 14:15:47 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 14:15:47 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 14:15:48 volumio sudo[2438]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-01-27 14:14' Jan 27 14:15:48 volumio sudo[2438]: 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"