Jan 28 11:07:00 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 11:07:00 volumio volumio[30093]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 11:07:00 volumio volumio[30093]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:07:00 volumio volumio[30093]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:07:00 volumio volumio[30093]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:07:00 volumio volumio[30093]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:07:00 volumio volumio[30093]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:07:00 volumio volumio[30093]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:07:00 volumio volumio[30093]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:07:00 volumio volumio[30093]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:07:00 volumio volumio[30093]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:07:00 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 11:07:00 volumio go-librespot[30333]: go-librespot daemon starting... Jan 28 11:07:00 volumio volumio[30093]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 11:07:00 volumio volumio[30093]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:07:00 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Jan 28 11:07:00 volumio volumio[30093]: info: No need to fix Spotify hosts Jan 28 11:07:00 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Jan 28 11:07:00 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 11:07:00 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 11:07:00 volumio go-librespot[30345]: go-librespot daemon starting... Jan 28 11:07:00 volumio sudo[30326]: pam_unix(sudo:session): session closed for user root Jan 28 11:07:00 volumio go-librespot[30346]: time="2026-01-28T11:07:00+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 11:07:00 volumio go-librespot[30346]: time="2026-01-28T11:07:00+07:00" level=debug msg="app state loaded" Jan 28 11:07:00 volumio go-librespot[30346]: time="2026-01-28T11:07:00+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 11:07:01 volumio go-librespot[30346]: time="2026-01-28T11:07:01+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 11:07:01 volumio go-librespot[30346]: time="2026-01-28T11:07:01+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 28 11:07:01 volumio go-librespot[30346]: time="2026-01-28T11:07:01+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 28 11:07:01 volumio go-librespot[30346]: time="2026-01-28T11:07:01+07:00" level=info msg="zeroconf server listening on port 39717" Jan 28 11:07:01 volumio go-librespot[30346]: time="2026-01-28T11:07:01+07:00" level=debug msg="obtained new client token: AACkdsATNirsT2HNIJcXpLx31zdytxP1SgxWwe8eN1e51vXo4vFjLJtwoG7k1cxokybPeNmLnZiK0x++NsjxXn+DRyMFKkLjIUx22mP3oKcd78xU9tVjh4+Nh++Yu1GIylQ4WHFo3aqlXvNxjjgRJK/YunUF3SK8Q1MPdKimyRUcoRC9u1ZTuG0afv9g1XiFlyboheJ2eCgpDDrDAowf0IbbO/9T017QMUy7HdcFXULTuXpUXitPWN+lMH8=" Jan 28 11:07:01 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 11:07:01 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 11:07:01 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 11:07:01 volumio go-librespot[30346]: time="2026-01-28T11:07:01+07:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:4070, retrying with a different AP" error="dial tcp 104.199.241.202:4070: connect: connection refused" Jan 28 11:07:01 volumio go-librespot[30346]: time="2026-01-28T11:07:01+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Jan 28 11:07:01 volumio go-librespot[30346]: time="2026-01-28T11:07:01+07:00" level=debug msg="completed keyexchange" Jan 28 11:07:01 volumio go-librespot[30346]: time="2026-01-28T11:07:01+07:00" level=debug msg="completed challenge" Jan 28 11:07:01 volumio volumio[30093]: info: Volumio called home Jan 28 11:07:01 volumio go-librespot[30346]: time="2026-01-28T11:07:01+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 11:07:01 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 11:07:01 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 11:07:01 volumio volumio[30093]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 28 11:07:01 volumio volumio[30093]: SPOTIFY: BQAj8GNvGgJl-YnKmC7tPzZhQfuk934mK8xBhP0f4A6FdZLc0YwhVidXFvZKMhnvP5Z1KwqeFtwgagQ081yV5YNa7kzz0yZo4ZM4Fy1GviMqkTk2dzQdcCHj4n8w-zwgJ7h2GiVtpVgJvTPMqpCgzGp0Vl0DAmIDU_8FFLcEFtX7bCtSkt8Srlmr2qCdd6P3B2oqUZJoRBiVGcKFJKfCu8ruCYYmvZ1PBqZyi8kp0bGtOozdfLuEFgUiKfTOzKCGIZsIn1VLqDJCbA4YV8GtuiuN0ecsJyLrMr5_L4BSki6_NOuQ5EMG6NwK Jan 28 11:07:01 volumio volumio[30093]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 28 11:07:01 volumio volumio[30093]: info: New Spotify access token = BQAj8GNvGgJl-YnKmC7tPzZhQfuk934mK8xBhP0f4A6FdZLc0YwhVidXFvZKMhnvP5Z1KwqeFtwgagQ081yV5YNa7kzz0yZo4ZM4Fy1GviMqkTk2dzQdcCHj4n8w-zwgJ7h2GiVtpVgJvTPMqpCgzGp0Vl0DAmIDU_8FFLcEFtX7bCtSkt8Srlmr2qCdd6P3B2oqUZJoRBiVGcKFJKfCu8ruCYYmvZ1PBqZyi8kp0bGtOozdfLuEFgUiKfTOzKCGIZsIn1VLqDJCbA4YV8GtuiuN0ecsJyLrMr5_L4BSki6_NOuQ5EMG6NwK Jan 28 11:07:01 volumio volumio[30093]: info: Spotify credentials grant success - running version from March 24, 2019 Jan 28 11:07:02 volumio volumio[30093]: info: Starting Shairport Sync Jan 28 11:07:02 volumio volumio[30093]: info: Starting Shairport Sync Jan 28 11:07:02 volumio volumio[30093]: info: Starting Shairport Sync Jan 28 11:07:02 volumio sudo[30373]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 28 11:07:02 volumio sudo[30373]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:07:02 volumio sudo[30377]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 28 11:07:02 volumio sudo[30377]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:07:02 volumio sudo[30375]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 28 11:07:02 volumio sudo[30375]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:07:02 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 28 11:07:02 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Jan 28 11:07:02 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 28 11:07:02 volumio systemd[1]: shairport-sync.service: Consumed 2.278s CPU time. Jan 28 11:07:02 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 28 11:07:02 volumio sudo[30373]: pam_unix(sudo:session): session closed for user root Jan 28 11:07:02 volumio sudo[30375]: pam_unix(sudo:session): session closed for user root Jan 28 11:07:02 volumio sudo[30377]: pam_unix(sudo:session): session closed for user root Jan 28 11:07:02 volumio volumio[30093]: info: CoreCommandRouter::volumioGetState Jan 28 11:07:02 volumio volumio[30093]: info: CorePlayQueue::getTrack 0 Jan 28 11:07:02 volumio volumio[30093]: info: Shairport-Sync Started Jan 28 11:07:02 volumio volumio[30093]: Error adding Membership: Error: addMembership EINVAL Jan 28 11:07:02 volumio volumio[30093]: info: Shairport-Sync Started Jan 28 11:07:02 volumio volumio[30093]: info: Shairport-Sync Started Jan 28 11:07:02 volumio volumio[30093]: SPOTIFY: User informations: {"country":"PK","display_name":"215mmgea6kss3jxeqsqdquvji","email":"linh.ngotran@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/215mmgea6kss3jxeqsqdquvji"},"followers":{"href":null,"total":1},"href":"https://api.spotify.com/v1/users/215mmgea6kss3jxeqsqdquvji","id":"215mmgea6kss3jxeqsqdquvji","images":[],"product":"premium","type":"user","uri":"spotify:user:215mmgea6kss3jxeqsqdquvji"} Jan 28 11:07:02 volumio volumio[30093]: info: Spotify Successfully logged in Jan 28 11:07:02 volumio volumio[30093]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 11:07:02 volumio volumio[30093]: info: [1769573222873] CoreMusicLibrary::Adding element Spotify Jan 28 11:07:02 volumio volumio[30093]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 11:07:02 volumio volumio[30093]: Cannot find translation for source YouTube Music Jan 28 11:07:02 volumio volumio[30093]: Cannot find translation for source Spotify Jan 28 11:07:03 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 11:07:03 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 11:07:03 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 11:07:03 volumio volumio[30093]: info: [yt-cast-receiver] DIAL server listening on port 8098 Jan 28 11:07:03 volumio volumio[30093]: info: CoreCommandRouter::volumioRetrievevolume Jan 28 11:07:03 volumio volumio[30093]: info: VolumeController:: Volume=100 Mute =false Jan 28 11:07:03 volumio volumio[30093]: info: CoreCommandRouter::volumioGetState Jan 28 11:07:03 volumio volumio[30093]: info: CorePlayQueue::getTrack 0 Jan 28 11:07:03 volumio volumio[30093]: info: CoreStateMachine::pushState Jan 28 11:07:03 volumio volumio[30093]: info: CorePlayQueue::getTrack 0 Jan 28 11:07:04 volumio volumio[30093]: info: CoreCommandRouter::volumioPushState Jan 28 11:07:04 volumio volumio[30093]: info: go-librespot daemon successfully initialized Jan 28 11:07:04 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Jan 28 11:07:05 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 11:07:05 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 11:07:05 volumio go-librespot[30413]: go-librespot daemon starting... Jan 28 11:07:05 volumio go-librespot[30414]: time="2026-01-28T11:07:05+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 11:07:05 volumio go-librespot[30414]: time="2026-01-28T11:07:05+07:00" level=debug msg="app state loaded" Jan 28 11:07:05 volumio go-librespot[30414]: time="2026-01-28T11:07:05+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 11:07:05 volumio mpd[30316]: 2026-01-28T11:07:05 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 28 11:07:05 volumio systemd[1]: Started mpd.service - Music Player Daemon. Jan 28 11:07:05 volumio sudo[30276]: pam_unix(sudo:session): session closed for user root Jan 28 11:07:05 volumio sudo[30288]: pam_unix(sudo:session): session closed for user root Jan 28 11:07:05 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 11:07:05 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 11:07:05 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 11:07:05 volumio volumio[30093]: error: MPD error: The expression evaluated to a falsy value: Jan 28 11:07:05 volumio volumio[30093]: assert.ok(self.idling) Jan 28 11:07:05 volumio volumio[30093]: error: The expression evaluated to a falsy value: Jan 28 11:07:05 volumio volumio[30093]: assert.ok(self.idling) Jan 28 11:07:05 volumio go-librespot[30414]: time="2026-01-28T11:07:05+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 11:07:05 volumio go-librespot[30414]: time="2026-01-28T11:07:05+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 28 11:07:05 volumio go-librespot[30414]: time="2026-01-28T11:07:05+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 28 11:07:05 volumio volumio[30093]: info: MPD running with PID30316 Jan 28 11:07:05 volumio volumio[30093]: ,establishing connection Jan 28 11:07:05 volumio volumio[30093]: error: updateQueue error: null Jan 28 11:07:05 volumio go-librespot[30414]: time="2026-01-28T11:07:05+07:00" level=info msg="zeroconf server listening on port 45321" Jan 28 11:07:05 volumio volumio[30093]: info: Completed starting Core Plugins Jan 28 11:07:05 volumio volumio[30093]: info: ------------------------------------------- Jan 28 11:07:05 volumio volumio[30093]: info: ----- MyVolumio plugins startup ---- Jan 28 11:07:05 volumio volumio[30093]: info: ------------------------------------------- Jan 28 11:07:05 volumio volumio[30093]: info: [MyVolumio PluginManager] Fetching plans data.... Jan 28 11:07:05 volumio volumio[30093]: error: updateQueue error: null Jan 28 11:07:05 volumio go-librespot[30414]: time="2026-01-28T11:07:05+07:00" level=debug msg="obtained new client token: AACySgIDjvUfmQQ+i/hLT0dQOXUELS3h0wsaGvLLuaX4nWGh2tpBD6OJVhQOuYLHc6bDa96wYEuoB+6bnLTq1L45wLBkhEJGFgSqYAwK4jTwO8mKqF3nQpgER6dDmP6Ryr/u4zsvOzgF1IJDkJ/tyIxTwFHJ6X56Lwr/hcN3j+iVVlh75I2tLJWu40As5QXx9h9oaOlYbg6EIhaCpuDuB46zFvc1RDiW1eY+VB8ErvZH05Ct8pfpdnjGcPg=" Jan 28 11:07:06 volumio go-librespot[30414]: time="2026-01-28T11:07:06+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 11:07:06 volumio go-librespot[30414]: time="2026-01-28T11:07:06+07:00" level=debug msg="completed keyexchange" Jan 28 11:07:06 volumio go-librespot[30414]: time="2026-01-28T11:07:06+07:00" level=debug msg="completed challenge" Jan 28 11:07:06 volumio go-librespot[30414]: time="2026-01-28T11:07:06+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 11:07:06 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 11:07:06 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 11:07:07 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 11:07:07 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 11:07:07 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 11:07:07 volumio volumio[30093]: info: Initializing connection to go-librespot Websocket Jan 28 11:07:07 volumio volumio[30093]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 28 11:07:09 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Jan 28 11:07:09 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 11:07:09 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 11:07:09 volumio go-librespot[30426]: go-librespot daemon starting... Jan 28 11:07:09 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 11:07:09 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 11:07:09 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 11:07:09 volumio go-librespot[30427]: time="2026-01-28T11:07:09+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 11:07:09 volumio go-librespot[30427]: time="2026-01-28T11:07:09+07:00" level=debug msg="app state loaded" Jan 28 11:07:09 volumio go-librespot[30427]: time="2026-01-28T11:07:09+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 11:07:10 volumio go-librespot[30427]: time="2026-01-28T11:07:10+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 11:07:10 volumio go-librespot[30427]: time="2026-01-28T11:07:10+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 28 11:07:10 volumio go-librespot[30427]: time="2026-01-28T11:07:10+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 28 11:07:10 volumio go-librespot[30427]: time="2026-01-28T11:07:10+07:00" level=info msg="zeroconf server listening on port 39215" Jan 28 11:07:10 volumio go-librespot[30427]: time="2026-01-28T11:07:10+07:00" level=debug msg="obtained new client token: AACV5kzQgSmkYL4CQFe+RnbDiF2g9etnKIdMawo8PISCP8rRFvcFXYErpiDapDhWPdQ/AkZX+HFSSszSZMjdVHlVUPikRyLZf8ZEGkNgNcOJrvtXbPQxRvbJJUJLgXTocEnMQpFEwVk7lXe+gPL8eFHcYSg4i4Dp30Jbk8h5ooXJfX7Zezd/VbYdLizZETMm29i+IQG4Dyqj5jfUx5StnKRisT94dedaJv/gYWQwRH62q9lSVuE1f6wQ" Jan 28 11:07:10 volumio go-librespot[30427]: time="2026-01-28T11:07:10+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 11:07:10 volumio go-librespot[30427]: time="2026-01-28T11:07:10+07:00" level=debug msg="completed keyexchange" Jan 28 11:07:10 volumio go-librespot[30427]: time="2026-01-28T11:07:10+07:00" level=debug msg="completed challenge" Jan 28 11:07:10 volumio volumio[30093]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Jan 28 11:07:10 volumio go-librespot[30427]: time="2026-01-28T11:07:10+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 11:07:10 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 11:07:10 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 11:07:10 volumio volumio[30093]: info: Initializing connection to go-librespot Websocket Jan 28 11:07:10 volumio volumio[30093]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 28 11:07:11 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 11:07:11 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 11:07:11 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 11:07:13 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 11:07:13 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 11:07:13 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 11:07:13 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Jan 28 11:07:13 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 11:07:13 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 11:07:13 volumio go-librespot[30436]: go-librespot daemon starting... Jan 28 11:07:13 volumio go-librespot[30437]: time="2026-01-28T11:07:13+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 11:07:13 volumio go-librespot[30437]: time="2026-01-28T11:07:13+07:00" level=debug msg="app state loaded" Jan 28 11:07:13 volumio go-librespot[30437]: time="2026-01-28T11:07:13+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 11:07:13 volumio volumio[30093]: info: Initializing connection to go-librespot Websocket Jan 28 11:07:13 volumio go-librespot[30437]: time="2026-01-28T11:07:13+07:00" level=debug msg="new websocket client" Jan 28 11:07:13 volumio volumio[30093]: info: Connection to go-librespot Websocket established Jan 28 11:07:14 volumio go-librespot[30437]: time="2026-01-28T11:07: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 28 11:07:14 volumio go-librespot[30437]: time="2026-01-28T11:07: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 28 11:07:14 volumio go-librespot[30437]: time="2026-01-28T11:07: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 28 11:07:14 volumio go-librespot[30437]: time="2026-01-28T11:07:14+07:00" level=info msg="zeroconf server listening on port 40879" Jan 28 11:07:14 volumio volumio[30093]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Jan 28 11:07:14 volumio volumio[30093]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Jan 28 11:07:14 volumio volumio[30093]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Jan 28 11:07:14 volumio volumio[30093]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Jan 28 11:07:14 volumio volumio[30093]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Jan 28 11:07:14 volumio volumio[30093]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Jan 28 11:07:14 volumio volumio[30093]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Jan 28 11:07:14 volumio volumio[30093]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Jan 28 11:07:14 volumio volumio[30093]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Jan 28 11:07:14 volumio volumio[30093]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Jan 28 11:07:14 volumio volumio[30093]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Jan 28 11:07:14 volumio volumio[30093]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Jan 28 11:07:14 volumio volumio[30093]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Jan 28 11:07:14 volumio volumio[30093]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Jan 28 11:07:14 volumio volumio[30093]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Jan 28 11:07:14 volumio volumio[30093]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Jan 28 11:07:14 volumio volumio[30093]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Jan 28 11:07:14 volumio volumio[30093]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Jan 28 11:07:14 volumio volumio[30093]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Jan 28 11:07:14 volumio volumio[30093]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Jan 28 11:07:14 volumio volumio[30093]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Jan 28 11:07:14 volumio volumio[30093]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Jan 28 11:07:14 volumio volumio[30093]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Jan 28 11:07:14 volumio volumio[30093]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Jan 28 11:07:14 volumio volumio[30093]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Jan 28 11:07:14 volumio volumio[30093]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Jan 28 11:07:14 volumio volumio[30093]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Jan 28 11:07:14 volumio volumio[30093]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Jan 28 11:07:14 volumio volumio[30093]: info: Adding plugin bluetooth to MyMusic Plugins Jan 28 11:07:14 volumio volumio[30093]: info: Adding plugin multiroom to MyMusic Plugins Jan 28 11:07:14 volumio volumio[30093]: info: Adding plugin metavolumio to MyMusic Plugins Jan 28 11:07:14 volumio volumio[30093]: info: Adding plugin cd_controller to MyMusic Plugins Jan 28 11:07:14 volumio volumio[30093]: info: Adding plugin qobuzconnect to MyMusic Plugins Jan 28 11:07:14 volumio volumio[30093]: info: Adding plugin smart_inputs to MyMusic Plugins Jan 28 11:07:14 volumio volumio[30093]: info: Adding plugin tidalconnect to MyMusic Plugins Jan 28 11:07:14 volumio volumio[30093]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Jan 28 11:07:14 volumio go-librespot[30437]: time="2026-01-28T11:07:14+07:00" level=debug msg="obtained new client token: AAD1E6EuzlsCCpnpYbnyLRRgxRpQV1ukCqaJx0mE967RWQ4NpqJ1d364UP77Dw9vircHwifj5GtANxUufmzpumhJkj0lvToMeG7+ar8olwc+T4Jz4/7LSrrUWu0IlrzOnDJkh7NXwJ/oAZ9UXUL3sly3fUj76+VcVlknAljmpBL3vjLYN2CvoXsJX7s1rbYxDLTH+OOZb8Qajsv46XB2Vn31JfPn5u3N/V52CgZgJRKc+v3YwgeHInCGdt8=" Jan 28 11:07:14 volumio go-librespot[30437]: time="2026-01-28T11:07:14+07:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:4070, retrying with a different AP" error="dial tcp 104.199.241.202:4070: connect: connection refused" Jan 28 11:07:14 volumio go-librespot[30437]: time="2026-01-28T11:07:14+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Jan 28 11:07:14 volumio go-librespot[30437]: time="2026-01-28T11:07:14+07:00" level=debug msg="completed keyexchange" Jan 28 11:07:14 volumio go-librespot[30437]: time="2026-01-28T11:07:14+07:00" level=debug msg="completed challenge" Jan 28 11:07:14 volumio go-librespot[30437]: time="2026-01-28T11:07:14+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 11:07:14 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 11:07:14 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 11:07:15 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 11:07:15 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 11:07:15 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 11:07:16 volumio volumio[30093]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Jan 28 11:07:16 volumio volumio[30093]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Jan 28 11:07:16 volumio volumio[30093]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 11:07:16 volumio volumio[30093]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 11:07:16 volumio volumio[30093]: info: Starting MyVolumio Remote Streaming Endpoints Jan 28 11:07:16 volumio volumio[30093]: info: MyVolumio login type: Token Jan 28 11:07:16 volumio volumio[30093]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Jan 28 11:07:16 volumio volumio[30093]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Jan 28 11:07:17 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 11:07:17 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 11:07:17 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 11:07:17 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Jan 28 11:07:17 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 11:07:18 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 11:07:18 volumio go-librespot[30459]: go-librespot daemon starting... Jan 28 11:07:18 volumio go-librespot[30460]: time="2026-01-28T11:07:18+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 11:07:18 volumio go-librespot[30460]: time="2026-01-28T11:07:18+07:00" level=debug msg="app state loaded" Jan 28 11:07:18 volumio go-librespot[30460]: time="2026-01-28T11:07:18+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 11:07:18 volumio volumio[30093]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Jan 28 11:07:18 volumio volumio[30093]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Jan 28 11:07:18 volumio volumio[30093]: info: Streaming services startup Jan 28 11:07:18 volumio volumio[30093]: info: Starting Streaming Daemon Jan 28 11:07:18 volumio sudo[30468]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jan 28 11:07:18 volumio sudo[30468]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:07:18 volumio volumio[30093]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Jan 28 11:07:18 volumio sudo[30468]: pam_unix(sudo:session): session closed for user root Jan 28 11:07:18 volumio volumio[30093]: info: Getting Spotify volume Jan 28 11:07:18 volumio volumio[30093]: info: Connection to go-librespot Websocket closed Jan 28 11:07:18 volumio volumio[30093]: error: Cannot start Volumio Streaming Daemon Jan 28 11:07:18 volumio volumio[30093]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Jan 28 11:07:18 volumio volumio[30093]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Jan 28 11:07:18 volumio volumio[30093]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Jan 28 11:07:18 volumio go-librespot[30460]: time="2026-01-28T11:07: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 28 11:07:18 volumio go-librespot[30460]: time="2026-01-28T11:07: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 28 11:07:18 volumio go-librespot[30460]: time="2026-01-28T11:07: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 28 11:07:18 volumio volumio[30093]: info: CoreCommandRouter::volumioGetState Jan 28 11:07:18 volumio volumio[30093]: info: CorePlayQueue::getTrack 0 Jan 28 11:07:18 volumio go-librespot[30460]: time="2026-01-28T11:07:18+07:00" level=info msg="zeroconf server listening on port 45417" Jan 28 11:07:18 volumio volumio[30093]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jan 28 11:07:18 volumio volumio[30093]: SPOTIFY: SPOTIFY VOLUME undefined Jan 28 11:07:18 volumio volumio[30093]: SPOTIFY: VOLUMIO VOLUME 100 Jan 28 11:07:18 volumio volumio[30093]: info: Aligning Spotify Volume to Volumio Volume Jan 28 11:07:18 volumio volumio[30093]: info: CoreCommandRouter::volumioGetState Jan 28 11:07:18 volumio volumio[30093]: info: CorePlayQueue::getTrack 0 Jan 28 11:07:18 volumio volumio[30093]: info: Setting Spotify Volume from Volumio: 100 Jan 28 11:07:18 volumio go-librespot[30460]: time="2026-01-28T11:07:18+07:00" level=debug msg="obtained new client token: AACG4ZQuND59R8OtrHuyk+aOv4ZfdwXjIpQfwnmvNkj+MqeW4jw+dvI9KNuXzHrzr/HLeylLzH4PITCjdGcBhPyylnt8f7NDpuE7gH9tt4Xvo+CKXKjsnzIaXypk96prCkAReo4O/CYwpMBg87++rhOFQvz3L1srxfDEcz/doiJdMNpiO04UxNAIshLxDYsZH7cm0HcXx/LGrzPSs1TAhAYtygHLqEuq7YOl+rOHWkCxd/ieBSHyAgeZcF0=" Jan 28 11:07:19 volumio go-librespot[30460]: time="2026-01-28T11:07:19+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 11:07:19 volumio go-librespot[30460]: time="2026-01-28T11:07:19+07:00" level=debug msg="completed keyexchange" Jan 28 11:07:19 volumio go-librespot[30460]: time="2026-01-28T11:07:19+07:00" level=debug msg="completed challenge" Jan 28 11:07:19 volumio go-librespot[30460]: time="2026-01-28T11:07:19+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 11:07:19 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 11:07:19 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 11:07:19 volumio volumio[30093]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 28 11:07:19 volumio volumio[30093]: Error: socket hang up Jan 28 11:07:19 volumio volumio[30093]: at connResetException (node:internal/errors:720:14) Jan 28 11:07:19 volumio volumio[30093]: at Socket.socketOnEnd (node:_http_client:519:23) Jan 28 11:07:19 volumio volumio[30093]: at Socket.emit (node:events:526:35) Jan 28 11:07:19 volumio volumio[30093]: at endReadableNT (node:internal/streams/readable:1376:12) Jan 28 11:07:19 volumio volumio[30093]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Jan 28 11:07:19 volumio volumio[30093]: code: 'ECONNRESET', Jan 28 11:07:19 volumio volumio[30093]: response: undefined Jan 28 11:07:19 volumio volumio[30093]: } Jan 28 11:07:19 volumio volumio[30093]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 28 11:07:19 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 11:07:19 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 11:07:19 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 11:07:20 volumio sudo[30490]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-01-28 11:06' Jan 28 11:07:20 volumio sudo[30490]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:07:21 volumio sudo[30490]: pam_unix(sudo:session): session closed for user root Jan 28 11:07:21 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 11:07:21 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 11:07:21 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 11:07:22 volumio volumio-remote-updater[628]: [2026-01-28 11:07:22] [error] handle_read_frame error: asio.system:104 (Connection reset by peer) Jan 28 11:07:22 volumio volumio-remote-updater[628]: [2026-01-28 11:07:22] [disconnect] Disconnect close local:[1006,Connection reset by peer] remote:[1006] Jan 28 11:07:22 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Jan 28 11:07:22 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Jan 28 11:07:22 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 11:07:22 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 11:07:22 volumio go-librespot[30498]: go-librespot daemon starting... Jan 28 11:07:22 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Jan 28 11:07:22 volumio systemd[1]: volumio.service: Consumed 59.186s CPU time. Jan 28 11:07:22 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 28 11:07:22 volumio go-librespot[30504]: time="2026-01-28T11:07:22+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 11:07:22 volumio go-librespot[30504]: time="2026-01-28T11:07:22+07:00" level=debug msg="app state loaded" Jan 28 11:07:22 volumio go-librespot[30504]: time="2026-01-28T11:07:22+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 11:07:22 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Jan 28 11:07:22 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 10026. Jan 28 11:07:22 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 28 11:07:22 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Jan 28 11:07:22 volumio systemd[1]: volumio.service: Consumed 59.186s CPU time. Jan 28 11:07:22 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Jan 28 11:07:22 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Jan 28 11:07:23 volumio go-librespot[30504]: time="2026-01-28T11:07: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 28 11:07:23 volumio go-librespot[30504]: time="2026-01-28T11:07: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 28 11:07:23 volumio go-librespot[30504]: time="2026-01-28T11:07: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 28 11:07:23 volumio go-librespot[30504]: time="2026-01-28T11:07:23+07:00" level=info msg="zeroconf server listening on port 38899" Jan 28 11:07:23 volumio go-librespot[30504]: time="2026-01-28T11:07:23+07:00" level=debug msg="obtained new client token: AAAWi8dhtl2jeGDOILn4NQD3RNH1Yc/eC2MTU4q5NOpWMmGL/EHSychS4uPVK6mwFMcpDgUlz85pHADoCH3meXXxobOjDgtLMvJ/fbZyMuBWQFt9whMmKBSDuZi9pZPYnf2A4CdF6RAc2ikfqBJWOAanhJU1o6wFByoRM9PvxIaDZQjYKcQr8vfu0sn+SFcUU73T+9I87CLZelNsTRdD5pZQ0yM8TNPByLW5u3SDqtE/xVFfvC3kTcTePlo=" Jan 28 11:07:23 volumio go-librespot[30504]: time="2026-01-28T11:07:23+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 11:07:23 volumio go-librespot[30504]: time="2026-01-28T11:07:23+07:00" level=debug msg="completed keyexchange" Jan 28 11:07:23 volumio go-librespot[30504]: time="2026-01-28T11:07:23+07:00" level=debug msg="completed challenge" Jan 28 11:07:23 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 11:07:23 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 11:07:23 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 11:07:23 volumio go-librespot[30504]: time="2026-01-28T11:07:23+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 11:07:23 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 11:07:23 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 11:07:25 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 11:07:25 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 11:07:25 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 11:07:26 volumio volumio[30517]: info: ------------------------------------------- Jan 28 11:07:26 volumio volumio[30517]: info: ----- Volumio3 ---- Jan 28 11:07:26 volumio volumio[30517]: info: ------------------------------------------- Jan 28 11:07:26 volumio volumio[30517]: info: ----- System startup ---- Jan 28 11:07:26 volumio volumio[30517]: info: ------------------------------------------- Jan 28 11:07:26 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Jan 28 11:07:26 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 11:07:26 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 11:07:26 volumio go-librespot[30540]: go-librespot daemon starting... Jan 28 11:07:26 volumio go-librespot[30541]: time="2026-01-28T11:07:26+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 11:07:26 volumio go-librespot[30541]: time="2026-01-28T11:07:26+07:00" level=debug msg="app state loaded" Jan 28 11:07:26 volumio go-librespot[30541]: time="2026-01-28T11:07:26+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 11:07:27 volumio go-librespot[30541]: time="2026-01-28T11:07:27+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 11:07:27 volumio go-librespot[30541]: time="2026-01-28T11:07:27+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 28 11:07:27 volumio go-librespot[30541]: time="2026-01-28T11:07:27+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 28 11:07:27 volumio go-librespot[30541]: time="2026-01-28T11:07:27+07:00" level=info msg="zeroconf server listening on port 34845" Jan 28 11:07:27 volumio volumio-remote-updater[628]: [2026-01-28 11:07:27] [connect] Successful connection Jan 28 11:07:27 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 11:07:27 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 11:07:27 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 11:07:27 volumio go-librespot[30541]: time="2026-01-28T11:07:27+07:00" level=debug msg="obtained new client token: AAA3qopx/ZsSZEBhqdoYbOa1Cy8N/YBgiMySoQDOierKJxuWpfdHppCTSZ/cSXMzWVmZCLUsOuGeewQEMoOi7yUhEMVMFnJbDn9Gnl8WsuIZ7zV9kTMIHIg5rDaB8YseD4Z7uFPP6QmgcJd4S8yKqn+gQWviuhxOLFVmM7Gu1sFnAdMaHpgkGN5ez4H0ZIyAEWIC7Mz2wZ01yb3FgDMe+VNg0/bcJ3Nl2rOc3U89BkFp6rg4ACxnm9M5rO4=" Jan 28 11:07:27 volumio go-librespot[30541]: time="2026-01-28T11:07:27+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 11:07:27 volumio go-librespot[30541]: time="2026-01-28T11:07:27+07:00" level=debug msg="completed keyexchange" Jan 28 11:07:27 volumio go-librespot[30541]: time="2026-01-28T11:07:27+07:00" level=debug msg="completed challenge" Jan 28 11:07:27 volumio volumio[30517]: info: MYVOLUMIO Environment detected Jan 28 11:07:27 volumio go-librespot[30541]: time="2026-01-28T11:07:27+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 11:07:27 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 11:07:27 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 11:07:27 volumio volumio[30517]: info: Plugin folders cleanup Jan 28 11:07:27 volumio volumio[30517]: info: Scanning into folder /volumio/app/plugins/ Jan 28 11:07:27 volumio volumio[30517]: info: Scanning category audio_interface Jan 28 11:07:27 volumio volumio[30517]: info: Scanning category miscellanea Jan 28 11:07:27 volumio volumio[30517]: info: Scanning category music_service Jan 28 11:07:28 volumio volumio[30517]: info: Scanning category plugins.json Jan 28 11:07:28 volumio volumio[30517]: info: Scanning category system_controller Jan 28 11:07:28 volumio volumio[30517]: info: Scanning category user_interface Jan 28 11:07:28 volumio volumio[30517]: info: Scanning into folder /data/plugins/ Jan 28 11:07:28 volumio volumio[30517]: info: Scanning category music_service Jan 28 11:07:28 volumio volumio[30517]: info: Plugin folders cleanup completed Jan 28 11:07:28 volumio volumio[30517]: info: ------------------------------------------- Jan 28 11:07:28 volumio volumio[30517]: info: ----- Core plugins startup ---- Jan 28 11:07:28 volumio volumio[30517]: info: ------------------------------------------- Jan 28 11:07:28 volumio volumio[30517]: info: Loading plugins from folder /volumio/app/plugins/ Jan 28 11:07:28 volumio volumio[30517]: info: Adding plugin upnp to MyMusic Plugins Jan 28 11:07:28 volumio volumio[30517]: info: Adding plugin airplay_emulation to MyMusic Plugins Jan 28 11:07:28 volumio volumio[30517]: info: Adding plugin upnp_browser to MyMusic Plugins Jan 28 11:07:28 volumio volumio[30517]: info: Loading plugins from folder /data/plugins/ Jan 28 11:07:28 volumio volumio[30517]: info: Loading plugin "system"... Jan 28 11:07:28 volumio volumio[30517]: info: Loading plugin "appearance"... Jan 28 11:07:29 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 11:07:29 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 11:07:29 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 11:07:29 volumio volumio[30517]: info: Loading plugin "network"... Jan 28 11:07:29 volumio volumio[30517]: info: Refreshing Cached IP Addresses Jan 28 11:07:30 volumio sudo[30556]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 28 11:07:30 volumio sudo[30556]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:07:30 volumio volumio[30517]: info: Loading plugin "services"... Jan 28 11:07:30 volumio sudo[30558]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 28 11:07:30 volumio sudo[30558]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:07:30 volumio sudo[30556]: pam_unix(sudo:session): session closed for user root Jan 28 11:07:30 volumio volumio[30517]: info: Loading plugin "alsa_controller"... Jan 28 11:07:30 volumio sudo[30558]: pam_unix(sudo:session): session closed for user root Jan 28 11:07:30 volumio sudo[30565]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Jan 28 11:07:30 volumio sudo[30565]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:07:30 volumio volumio[30517]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 28 11:07:30 volumio volumio[30517]: info: Loading plugin "wizard"... Jan 28 11:07:30 volumio volumio[30517]: info: Loading plugin "networkfs"... Jan 28 11:07:30 volumio volumio[30517]: info: Starting Udev Watcher for removable devices Jan 28 11:07:30 volumio volumio[30517]: info: Ignoring mount for partition: boot Jan 28 11:07:30 volumio volumio[30517]: info: Ignoring mount for partition: volumio Jan 28 11:07:30 volumio volumio[30517]: info: Ignoring mount for partition: volumio_data Jan 28 11:07:30 volumio volumio[30517]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 28 11:07:30 volumio volumio[30517]: info: Loading plugin "volumio_command_line_client"... Jan 28 11:07:30 volumio volumio[30517]: info: Loading plugin "upnp"... Jan 28 11:07:30 volumio volumio[30517]: info: [1769573250380] Starting Upmpd Daemon Jan 28 11:07:30 volumio volumio[30517]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 28 11:07:30 volumio volumio[30517]: info: Loading plugin "my_music"... Jan 28 11:07:30 volumio volumio[30517]: info: Loading plugin "mpd"... Jan 28 11:07:30 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Jan 28 11:07:30 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 11:07:31 volumio volumio[30517]: info: Loading plugin "upnp_browser"... Jan 28 11:07:31 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 11:07:31 volumio go-librespot[30589]: go-librespot daemon starting... Jan 28 11:07:31 volumio go-librespot[30590]: time="2026-01-28T11:07:31+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 11:07:31 volumio go-librespot[30590]: time="2026-01-28T11:07:31+07:00" level=debug msg="app state loaded" Jan 28 11:07:31 volumio go-librespot[30590]: time="2026-01-28T11:07:31+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 11:07:31 volumio go-librespot[30590]: time="2026-01-28T11:07:31+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 11:07:31 volumio go-librespot[30590]: time="2026-01-28T11:07:31+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 28 11:07:31 volumio go-librespot[30590]: time="2026-01-28T11:07:31+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 28 11:07:31 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 11:07:31 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 11:07:31 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 11:07:31 volumio go-librespot[30590]: time="2026-01-28T11:07:31+07:00" level=info msg="zeroconf server listening on port 45633" Jan 28 11:07:31 volumio go-librespot[30590]: time="2026-01-28T11:07:31+07:00" level=debug msg="obtained new client token: AACuL45gn/KvoFKZ/ctnXlaRJhHl1cONRm3u5dHE6RDbvRM3QfrB4c+WXjuPSe8hZA0IWLUDMlv3QSjdpKeKsDQbjATsCmjAd4LY+kHZ/ecmGBMElzzy3PmggklAHidPPOTnsRd0HREJaXxl7xF2pCMKj9K7L0VDoz31UjBwnzGA4lKfCT1DN5Q8SofylQpQ/yU5yLSCKvDwxkHTknrlsi1UfjW8yWMgDyu4Z4URPkKrzTllu/gWJVH8HJA=" Jan 28 11:07:31 volumio go-librespot[30590]: time="2026-01-28T11:07:31+07:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:4070, retrying with a different AP" error="dial tcp 104.199.241.202:4070: connect: connection refused" Jan 28 11:07:32 volumio go-librespot[30590]: time="2026-01-28T11:07:32+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Jan 28 11:07:32 volumio go-librespot[30590]: time="2026-01-28T11:07:32+07:00" level=debug msg="completed keyexchange" Jan 28 11:07:32 volumio go-librespot[30590]: time="2026-01-28T11:07:32+07:00" level=debug msg="completed challenge" Jan 28 11:07:32 volumio go-librespot[30590]: time="2026-01-28T11:07: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 28 11:07:32 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 11:07:32 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 11:07:32 volumio sudo[30565]: pam_unix(sudo:session): session closed for user root Jan 28 11:07:33 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 11:07:33 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 11:07:33 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 11:07:34 volumio volumio[30517]: info: Starting UPNP Browser Jan 28 11:07:34 volumio volumio[30517]: info: Loading plugin "alarm-clock"... Jan 28 11:07:34 volumio volumio[30517]: info: Loading plugin "airplay_emulation"... Jan 28 11:07:34 volumio volumio[30517]: info: Starting Shairport Sync Jan 28 11:07:34 volumio volumio[30517]: info: Loading plugin "last_100"... Jan 28 11:07:34 volumio volumio[30517]: info: Loading plugin "webradio"... Jan 28 11:07:34 volumio volumio[30517]: info: Loading plugin "i2s_dacs"... Jan 28 11:07:34 volumio volumio[30517]: info: Loading plugin "volumiodiscovery"... Jan 28 11:07:34 volumio volumio[30517]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 28 11:07:34 volumio volumio[30517]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 11:07:34 volumio volumio[30517]: *** WARNING *** For more information see Jan 28 11:07:34 volumio volumio[30517]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 28 11:07:34 volumio volumio[30517]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 11:07:34 volumio volumio[30517]: *** WARNING *** For more information see Jan 28 11:07:34 volumio node[30517]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 28 11:07:34 volumio node[30517]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 11:07:34 volumio node[30517]: *** WARNING *** For more information see Jan 28 11:07:34 volumio node[30517]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 28 11:07:34 volumio node[30517]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 11:07:34 volumio node[30517]: *** WARNING *** For more information see Jan 28 11:07:34 volumio volumio[30517]: info: Applying required configuration parameters for plugin volumiodiscovery Jan 28 11:07:34 volumio volumio[30517]: info: Discovery: Started advertising with name: Volumio Jan 28 11:07:34 volumio volumio[30517]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 28 11:07:34 volumio volumio[30517]: info: Loading plugin "spop"... Jan 28 11:07:35 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Jan 28 11:07:35 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 11:07:35 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 11:07:35 volumio go-librespot[30601]: go-librespot daemon starting... Jan 28 11:07:35 volumio go-librespot[30602]: time="2026-01-28T11:07:35+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 11:07:35 volumio go-librespot[30602]: time="2026-01-28T11:07:35+07:00" level=debug msg="app state loaded" Jan 28 11:07:35 volumio go-librespot[30602]: time="2026-01-28T11:07:35+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 11:07:35 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 11:07:35 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 11:07:35 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 11:07:35 volumio go-librespot[30602]: time="2026-01-28T11:07:35+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 11:07:35 volumio go-librespot[30602]: time="2026-01-28T11:07:35+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 28 11:07:35 volumio go-librespot[30602]: time="2026-01-28T11:07:35+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 28 11:07:35 volumio go-librespot[30602]: time="2026-01-28T11:07:35+07:00" level=info msg="zeroconf server listening on port 43957" Jan 28 11:07:36 volumio go-librespot[30602]: time="2026-01-28T11:07:36+07:00" level=debug msg="obtained new client token: AAAuQq9A78hjeBIV7IPF9lXTgBjeuFSJ4+QKQ2c9haFXXLlR5Emmw6O7/ulzt6qa6PqrJLlEHkSdvp4ieYLGlerwC803stFh4amTXA60Xq+qbgf3786dwR+2ItxdC1mFgqHRWSi7pAJwUrOGNzI2uZhLfgge+Qmdt0NPuk67mRoLN9fEJPB/vYm0mo5DBB3szsVZFzJq21j4BJv2Ievz7wp6CUHjPwHoD9LnJ6xsbRh3Eka4BX8fJk01" Jan 28 11:07:36 volumio go-librespot[30602]: time="2026-01-28T11:07:36+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 11:07:36 volumio go-librespot[30602]: time="2026-01-28T11:07:36+07:00" level=debug msg="completed keyexchange" Jan 28 11:07:36 volumio go-librespot[30602]: time="2026-01-28T11:07:36+07:00" level=debug msg="completed challenge" Jan 28 11:07:36 volumio go-librespot[30602]: time="2026-01-28T11:07:36+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 11:07:36 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 11:07:36 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 11:07:36 volumio volumio[30517]: info: Loading plugin "ytcr"... Jan 28 11:07:37 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 11:07:37 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 11:07:37 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 11:07:39 volumio volumio[30517]: info: Loading plugin "ytmusic"... Jan 28 11:07:39 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 11:07:39 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 11:07:39 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 11:07:39 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Jan 28 11:07:39 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 11:07:39 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 11:07:39 volumio go-librespot[30609]: go-librespot daemon starting... Jan 28 11:07:39 volumio go-librespot[30610]: time="2026-01-28T11:07:39+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 11:07:39 volumio go-librespot[30610]: time="2026-01-28T11:07:39+07:00" level=debug msg="app state loaded" Jan 28 11:07:39 volumio go-librespot[30610]: time="2026-01-28T11:07:39+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 11:07:39 volumio volumio-remote-updater[628]: [2026-01-28 11:07:39] [connect] Successful connection Jan 28 11:07:40 volumio go-librespot[30610]: time="2026-01-28T11:07: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 28 11:07:40 volumio go-librespot[30610]: time="2026-01-28T11:07: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 28 11:07:40 volumio go-librespot[30610]: time="2026-01-28T11:07: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 28 11:07:40 volumio volumio[30517]: info: Loading plugin "outputs"... Jan 28 11:07:40 volumio volumio[30517]: info: Loading plugin "albumart"... Jan 28 11:07:40 volumio go-librespot[30610]: time="2026-01-28T11:07:40+07:00" level=info msg="zeroconf server listening on port 38821" Jan 28 11:07:40 volumio volumio[30517]: info: Plugin example_plugin is not enabled Jan 28 11:07:40 volumio volumio[30517]: info: Loading plugin "inputs"... Jan 28 11:07:40 volumio volumio[30517]: info: Loading plugin "updater_comm"... Jan 28 11:07:40 volumio go-librespot[30610]: time="2026-01-28T11:07:40+07:00" level=debug msg="obtained new client token: AABV7xBd2aO4tJupfD+jL8gF+0axj6MQffnhgCWxMTma9yipMXRz+1BLOdZ1VV7TkowUraTK6162wNbIAANBUEmyIbglaUA6I0SJHDxQml92ChtItTtNud6HCycv3Endjtoa0b9JRWRn2MyYg4h7m8L2xsUZTPCeYOffoTw5EUN4re2NifSku1l9ODsA2tfJC3KnBDhFylUNfXKpZhIzOE1V5sqggz5QVY9zkTatf1Zwki5LKHS7qmCtqIM=" Jan 28 11:07:40 volumio volumio[30517]: info: Plugin mpdemulation is not enabled Jan 28 11:07:40 volumio volumio[30517]: info: Loading plugin "rest_api"... Jan 28 11:07:40 volumio volumio[30517]: info: Loading plugin "websocket"... Jan 28 11:07:40 volumio volumio[30517]: info: Starting Socket.io Server version 1.7.4 Jan 28 11:07:40 volumio volumio[30517]: info: Loading plugin "RoonBridge"... Jan 28 11:07:40 volumio go-librespot[30610]: time="2026-01-28T11:07:40+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 11:07:40 volumio go-librespot[30610]: time="2026-01-28T11:07:40+07:00" level=debug msg="completed keyexchange" Jan 28 11:07:40 volumio go-librespot[30610]: time="2026-01-28T11:07:40+07:00" level=debug msg="completed challenge" Jan 28 11:07:40 volumio go-librespot[30610]: time="2026-01-28T11:07:40+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 11:07:40 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 11:07:40 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 11:07:41 volumio volumio[30517]: info: Applying required configuration parameters for plugin RoonBridge Jan 28 11:07:41 volumio volumio[30517]: info: Loading i18n strings for locale en Jan 28 11:07:41 volumio volumio[30517]: Updating browse sources language Jan 28 11:07:41 volumio volumio[30517]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 11:07:41 volumio volumio[30517]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 28 11:07:41 volumio volumio[30517]: info: CoreCommandRouter::initPlayerControls Jan 28 11:07:41 volumio volumio[30517]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:07:41 volumio volumio[30517]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:07:41 volumio volumio[30517]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:07:41 volumio volumio[30517]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:07:41 volumio volumio[30517]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:07:41 volumio volumio[30517]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:07:41 volumio volumio[30517]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:07:41 volumio volumio[30517]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:07:41 volumio volumio[30517]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 28 11:07:41 volumio volumio[30517]: Express server listening on port 3000 Jan 28 11:07:41 volumio volumio[30517]: [Metrics] WebUI: 16s 69.94ms Jan 28 11:07:41 volumio volumio[30631]: Forking 3 albumart workers Jan 28 11:07:41 volumio volumio[30517]: info: CoreStateMachine::resetVolumioState Jan 28 11:07:41 volumio volumio[30517]: info: CoreStateMachine::getcurrentVolume Jan 28 11:07:41 volumio volumio[30517]: info: CoreCommandRouter::volumioRetrievevolume Jan 28 11:07:41 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 11:07:41 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 11:07:41 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 11:07:41 volumio sudo[30657]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 28 11:07:41 volumio sudo[30657]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:07:41 volumio sudo[30657]: pam_unix(sudo:session): session closed for user root Jan 28 11:07:41 volumio sudo[30667]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 28 11:07:41 volumio sudo[30667]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:07:41 volumio volumio[30517]: info: Volumio Network Manager: Network status updated: 1 Jan 28 11:07:41 volumio sudo[30667]: pam_unix(sudo:session): session closed for user root Jan 28 11:07:42 volumio volumio[30517]: info: VolumeController:: Volume=100 Mute =false Jan 28 11:07:42 volumio volumio[30517]: info: CoreStateMachine::pushState Jan 28 11:07:42 volumio volumio[30517]: info: CorePlayQueue::getTrack 0 Jan 28 11:07:42 volumio volumio[30517]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 28 11:07:42 volumio volumio[30517]: info: CoreCommandRouter::volumioPushState Jan 28 11:07:42 volumio volumio[30517]: info: CoreStateMachine::updateTrackBlock Jan 28 11:07:42 volumio volumio[30517]: info: CorePlayQueue::getTrackBlock Jan 28 11:07:42 volumio volumio[30517]: info: CoreCommandRouter::volumioRetrievevolume Jan 28 11:07:42 volumio volumio-remote-updater[628]: [2026-01-28 11:07:42] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1769573259 101 Jan 28 11:07:42 volumio volumio[30517]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 1 Jan 28 11:07:42 volumio volumio[30517]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 11:07:42 volumio volumio[30517]: info: Reloading queue from file Jan 28 11:07:42 volumio volumio[30517]: info: CoreStateMachine::setRepeat null single undefined Jan 28 11:07:42 volumio volumio[30517]: info: CoreStateMachine::pushState Jan 28 11:07:42 volumio volumio[30517]: info: CorePlayQueue::getTrack 0 Jan 28 11:07:42 volumio volumio[30517]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 28 11:07:42 volumio volumio[30517]: info: CoreCommandRouter::volumioPushState Jan 28 11:07:42 volumio volumio[30517]: info: CoreStateMachine::setRandom null Jan 28 11:07:42 volumio volumio[30517]: info: CoreStateMachine::pushState Jan 28 11:07:42 volumio volumio[30517]: info: CorePlayQueue::getTrack 0 Jan 28 11:07:42 volumio volumio[30517]: info: CoreCommandRouter::volumioPushState Jan 28 11:07:42 volumio volumio[30517]: info: Setting Device type: Raspberry PI Jan 28 11:07:42 volumio volumio[30517]: info: Completed loading Core Plugins Jan 28 11:07:42 volumio volumio[30517]: info: Preparing to generate the ALSA configuration file Jan 28 11:07:42 volumio volumio[30517]: info: VolumeController:: Volume=100 Mute =false Jan 28 11:07:42 volumio volumio[30517]: info: CoreStateMachine::pushState Jan 28 11:07:42 volumio volumio[30517]: info: CorePlayQueue::getTrack 0 Jan 28 11:07:42 volumio volumio[30517]: info: CoreCommandRouter::volumioPushState Jan 28 11:07:42 volumio volumio[30517]: info: Asound.conf file unchanged, so no further update is needed Jan 28 11:07:42 volumio volumio[30517]: info: Output device has changed, restarting MPD Jan 28 11:07:42 volumio volumio[30517]: info: Output device has changed, restarting Shairport Sync Jan 28 11:07:42 volumio volumio[30517]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:07:42 volumio volumio[30517]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 11:07:42 volumio sudo[30692]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Jan 28 11:07:42 volumio sudo[30692]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:07:42 volumio sudo[30694]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 28 11:07:42 volumio sudo[30694]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:07:42 volumio sudo[30694]: pam_unix(sudo:session): session closed for user root Jan 28 11:07:42 volumio sudo[30696]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 28 11:07:42 volumio sudo[30696]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:07:42 volumio sudo[30692]: pam_unix(sudo:session): session closed for user root Jan 28 11:07:42 volumio volumio[30517]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 28 11:07:42 volumio volumio[30517]: info: ___________ START PLUGINS ___________ Jan 28 11:07:42 volumio volumio[30517]: info: ControllerMpd::onStart: Initializing MPD Jan 28 11:07:42 volumio volumio[30517]: info: Creating MPD Configuration file Jan 28 11:07:42 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Jan 28 11:07:42 volumio volumio[30517]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 28 11:07:42 volumio volumio[30517]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 11:07:42 volumio volumio[30517]: info: [1769573262900] CoreMusicLibrary::Adding element Media Servers Jan 28 11:07:42 volumio volumio[30517]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 11:07:42 volumio volumio[30517]: info: UPNP Browser: Client initialized successfully Jan 28 11:07:43 volumio sudo[30707]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 28 11:07:43 volumio sudo[30707]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:07:43 volumio sudo[30705]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 28 11:07:43 volumio sudo[30705]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:07:43 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 28 11:07:43 volumio volumio[30517]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:07:43 volumio volumio[30517]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 11:07:43 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 28 11:07:43 volumio systemd[1]: mpd.service: Consumed 7.364s CPU time. Jan 28 11:07:43 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 28 11:07:43 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 28 11:07:43 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 28 11:07:43 volumio sudo[30705]: pam_unix(sudo:session): session closed for user root Jan 28 11:07:43 volumio volumio[30517]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 28 11:07:43 volumio volumio[30517]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:07:43 volumio volumio[30517]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 11:07:43 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 28 11:07:43 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 28 11:07:43 volumio volumio[30517]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 28 11:07:43 volumio volumio[30517]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 11:07:43 volumio volumio[30517]: info: [1769573263203] CoreMusicLibrary::Adding element Last_100 Jan 28 11:07:43 volumio volumio[30517]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 11:07:43 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 28 11:07:43 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 28 11:07:43 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 28 11:07:43 volumio volumio[30517]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 11:07:43 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 28 11:07:43 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 28 11:07:43 volumio volumio[30517]: info: [1769573263234] CoreMusicLibrary::Adding element Webradio Jan 28 11:07:43 volumio volumio[30517]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 11:07:43 volumio volumio[30517]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 28 11:07:43 volumio volumio[30517]: info: Initializing BBC Radios Jan 28 11:07:43 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 28 11:07:43 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 28 11:07:43 volumio volumio[30517]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 28 11:07:43 volumio volumio[30517]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 11:07:43 volumio volumio[30517]: info: Creating Spotify config file Jan 28 11:07:43 volumio volumio[30517]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:07:43 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 11:07:43 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 11:07:43 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 11:07:43 volumio sudo[30726]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 28 11:07:43 volumio sudo[30726]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jan 28 11:07:43 volumio sudo[30726]: pam_unix(sudo:session): session closed for user root Jan 28 11:07:43 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Jan 28 11:07:43 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 11:07:44 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 11:07:44 volumio go-librespot[30737]: go-librespot daemon starting... Jan 28 11:07:44 volumio go-librespot[30738]: time="2026-01-28T11:07:44+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 11:07:44 volumio go-librespot[30738]: time="2026-01-28T11:07:44+07:00" level=info msg="zeroconf server listening on port 40611" Jan 28 11:07:44 volumio volumio[30517]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 11:07:44 volumio volumio[30517]: info: [1769573264864] CoreMusicLibrary::Adding element YouTube Music Jan 28 11:07:44 volumio volumio[30517]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 11:07:44 volumio volumio[30517]: Cannot find translation for source YouTube Music Jan 28 11:07:44 volumio volumio[30517]: info: Volumio Calling Home Jan 28 11:07:45 volumio sudo[30746]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Jan 28 11:07:45 volumio sudo[30746]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:07:45 volumio volumio[30644]: Starting albumart workers Jan 28 11:07:45 volumio sudo[30746]: pam_unix(sudo:session): session closed for user root Jan 28 11:07:45 volumio volumio[30646]: Starting albumart workers Jan 28 11:07:45 volumio volumio[30647]: Starting albumart workers Jan 28 11:07:45 volumio volumio[30517]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Jan 28 11:07:45 volumio volumio[30517]: info: Discovery: Found device Volumio Jan 28 11:07:45 volumio volumio[30517]: info: CoreCommandRouter::volumioGetState Jan 28 11:07:45 volumio volumio[30517]: info: CorePlayQueue::getTrack 0 Jan 28 11:07:45 volumio volumio[30517]: info: MPD Permissions set Jan 28 11:07:45 volumio volumio[30517]: info: MPD Permissions set Jan 28 11:07:45 volumio volumio[30517]: info: Upmpdcli Daemon Started Jan 28 11:07:45 volumio volumio[30517]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Jan 28 11:07:45 volumio volumio[30517]: info: Discovery: Found device Volumio Jan 28 11:07:45 volumio volumio[30517]: info: CoreCommandRouter::volumioGetState Jan 28 11:07:45 volumio volumio[30517]: info: CorePlayQueue::getTrack 0 Jan 28 11:07:45 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 11:07:45 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 11:07:45 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 11:07:45 volumio volumio[30517]: info: Spotify config file written Jan 28 11:07:45 volumio sudo[30752]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jan 28 11:07:45 volumio sudo[30752]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:07:45 volumio volumio[30517]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Jan 28 11:07:45 volumio volumio[30517]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:07:45 volumio volumio[30517]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:07:45 volumio volumio[30517]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:07:45 volumio volumio[30517]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:07:45 volumio volumio[30517]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:07:45 volumio volumio[30517]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:07:45 volumio volumio[30517]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:07:45 volumio volumio[30517]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:07:45 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Jan 28 11:07:45 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Jan 28 11:07:45 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 11:07:45 volumio volumio[30517]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 11:07:45 volumio volumio[30517]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:07:45 volumio volumio[30517]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:07:45 volumio volumio[30517]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:07:45 volumio volumio[30517]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:07:45 volumio volumio[30517]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:07:45 volumio volumio[30517]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:07:45 volumio volumio[30517]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:07:45 volumio volumio[30517]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:07:45 volumio volumio[30517]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:07:45 volumio go-librespot[30759]: go-librespot daemon starting... Jan 28 11:07:46 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 11:07:46 volumio sudo[30752]: pam_unix(sudo:session): session closed for user root Jan 28 11:07:46 volumio go-librespot[30762]: time="2026-01-28T11:07:46+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 11:07:46 volumio go-librespot[30762]: time="2026-01-28T11:07:46+07:00" level=debug msg="app state loaded" Jan 28 11:07:46 volumio go-librespot[30762]: time="2026-01-28T11:07:46+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 11:07:46 volumio volumio[30517]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 11:07:46 volumio volumio[30517]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:07:46 volumio volumio[30517]: info: No need to fix Spotify hosts Jan 28 11:07:46 volumio go-librespot[30762]: time="2026-01-28T11:07:46+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 28 11:07:46 volumio go-librespot[30762]: time="2026-01-28T11:07:46+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Jan 28 11:07:46 volumio go-librespot[30762]: time="2026-01-28T11:07:46+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Jan 28 11:07:46 volumio go-librespot[30762]: time="2026-01-28T11:07:46+07:00" level=info msg="zeroconf server listening on port 45215" Jan 28 11:07:47 volumio go-librespot[30762]: time="2026-01-28T11:07:47+07:00" level=debug msg="obtained new client token: AACi3CYe7j4F+/VPYxxUowyNfLaVlDAYXGeKqlWC6sh9Ly8cQXBDOjZCC9mhAd/P75rtuyOBwX8mOdTrm8lMLtPOea1f1NG86eV9Pxsu3JQp5vSyg2b4F565UXXAxjlsjyWi1/VhWgGwFeP9vlcaD+GiMSVYH6ezvArkh2jqzneATXVMJceaqtJSvC0eaZJn0oy5hwEqcYJ3my9ERmJEmoBLYV6BqjB450jI2nc4lqc7mTKLrAZ4sCcf" Jan 28 11:07:47 volumio go-librespot[30762]: time="2026-01-28T11:07:47+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 11:07:47 volumio go-librespot[30762]: time="2026-01-28T11:07:47+07:00" level=debug msg="completed keyexchange" Jan 28 11:07:47 volumio go-librespot[30762]: time="2026-01-28T11:07:47+07:00" level=debug msg="completed challenge" Jan 28 11:07:47 volumio volumio[30517]: info: Volumio called home Jan 28 11:07:47 volumio go-librespot[30762]: time="2026-01-28T11:07:47+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 11:07:47 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 11:07:47 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 11:07:47 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 11:07:47 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 11:07:47 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 11:07:47 volumio volumio[30517]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 28 11:07:47 volumio volumio[30517]: SPOTIFY: BQBV_qrDlWtaIW_ST83LccVXiz7orgz9LB_WkY6zfsW4F8R6vocD2JGYzjLBisKmKSuaTZRno8yJenxzJh6zfZoHqJa8J6gEHd-77mdDDOikgDOaJW5T1eAHXdoSFMGbMu3eh_OvH2Cx_-6KKee-dq5hDOlyV4HfGHTm-IEf97euWld90rJhvPyUrnOsE8yt3EzWtLo2f_IGrjlFustgfNETnrOku94ug4onH9Ts8ePTLe8D2Wjag-rz-j6rvCc-ugSEX9dG7gzKINoMTzveaIrTnD49vcJIgD2sQzdowG-SKeonsN_Cb0pH Jan 28 11:07:47 volumio volumio[30517]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 28 11:07:47 volumio volumio[30517]: info: New Spotify access token = BQBV_qrDlWtaIW_ST83LccVXiz7orgz9LB_WkY6zfsW4F8R6vocD2JGYzjLBisKmKSuaTZRno8yJenxzJh6zfZoHqJa8J6gEHd-77mdDDOikgDOaJW5T1eAHXdoSFMGbMu3eh_OvH2Cx_-6KKee-dq5hDOlyV4HfGHTm-IEf97euWld90rJhvPyUrnOsE8yt3EzWtLo2f_IGrjlFustgfNETnrOku94ug4onH9Ts8ePTLe8D2Wjag-rz-j6rvCc-ugSEX9dG7gzKINoMTzveaIrTnD49vcJIgD2sQzdowG-SKeonsN_Cb0pH Jan 28 11:07:47 volumio volumio[30517]: info: Spotify credentials grant success - running version from March 24, 2019 Jan 28 11:07:47 volumio volumio[30517]: info: Starting Shairport Sync Jan 28 11:07:47 volumio volumio[30517]: info: Starting Shairport Sync Jan 28 11:07:47 volumio volumio[30517]: info: Starting Shairport Sync Jan 28 11:07:47 volumio sudo[30794]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 28 11:07:47 volumio sudo[30794]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:07:47 volumio sudo[30796]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 28 11:07:47 volumio sudo[30796]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:07:47 volumio sudo[30798]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 28 11:07:47 volumio sudo[30798]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:07:48 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 28 11:07:48 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Jan 28 11:07:48 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 28 11:07:48 volumio systemd[1]: shairport-sync.service: Consumed 2.369s CPU time. Jan 28 11:07:48 volumio volumio[30517]: info: CoreCommandRouter::volumioGetState Jan 28 11:07:48 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 28 11:07:48 volumio volumio[30517]: info: CorePlayQueue::getTrack 0 Jan 28 11:07:48 volumio sudo[30796]: pam_unix(sudo:session): session closed for user root Jan 28 11:07:48 volumio sudo[30798]: pam_unix(sudo:session): session closed for user root Jan 28 11:07:48 volumio sudo[30794]: pam_unix(sudo:session): session closed for user root Jan 28 11:07:48 volumio volumio[30517]: info: Shairport-Sync Started Jan 28 11:07:48 volumio volumio[30517]: Error adding Membership: Error: addMembership EINVAL Jan 28 11:07:48 volumio volumio[30517]: info: Shairport-Sync Started Jan 28 11:07:48 volumio volumio[30517]: info: Shairport-Sync Started Jan 28 11:07:48 volumio volumio[30517]: SPOTIFY: User informations: {"country":"PK","display_name":"215mmgea6kss3jxeqsqdquvji","email":"linh.ngotran@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/215mmgea6kss3jxeqsqdquvji"},"followers":{"href":null,"total":1},"href":"https://api.spotify.com/v1/users/215mmgea6kss3jxeqsqdquvji","id":"215mmgea6kss3jxeqsqdquvji","images":[],"product":"premium","type":"user","uri":"spotify:user:215mmgea6kss3jxeqsqdquvji"} Jan 28 11:07:48 volumio volumio[30517]: info: Spotify Successfully logged in Jan 28 11:07:48 volumio volumio[30517]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 11:07:48 volumio volumio[30517]: info: [1769573268588] CoreMusicLibrary::Adding element Spotify Jan 28 11:07:48 volumio volumio[30517]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 11:07:48 volumio volumio[30517]: Cannot find translation for source YouTube Music Jan 28 11:07:48 volumio volumio[30517]: Cannot find translation for source Spotify Jan 28 11:07:49 volumio volumio[30517]: info: [yt-cast-receiver] DIAL server listening on port 8098 Jan 28 11:07:49 volumio volumio[30517]: info: CoreCommandRouter::volumioRetrievevolume Jan 28 11:07:49 volumio volumio[30517]: info: VolumeController:: Volume=100 Mute =false Jan 28 11:07:49 volumio volumio[30517]: info: CoreCommandRouter::volumioGetState Jan 28 11:07:49 volumio volumio[30517]: info: CorePlayQueue::getTrack 0 Jan 28 11:07:49 volumio volumio[30517]: info: CoreStateMachine::pushState Jan 28 11:07:49 volumio volumio[30517]: info: CorePlayQueue::getTrack 0 Jan 28 11:07:49 volumio volumio[30517]: info: CoreCommandRouter::volumioPushState Jan 28 11:07:49 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 11:07:49 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 11:07:49 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 11:07:50 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Jan 28 11:07:50 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 11:07:50 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 11:07:50 volumio go-librespot[30833]: go-librespot daemon starting... Jan 28 11:07:50 volumio go-librespot[30834]: time="2026-01-28T11:07:50+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 11:07:50 volumio go-librespot[30834]: time="2026-01-28T11:07:50+07:00" level=debug msg="app state loaded" Jan 28 11:07:50 volumio go-librespot[30834]: time="2026-01-28T11:07:50+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 11:07:50 volumio volumio[30517]: info: go-librespot daemon successfully initialized Jan 28 11:07:51 volumio go-librespot[30834]: time="2026-01-28T11:07:51+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 11:07:51 volumio go-librespot[30834]: time="2026-01-28T11:07:51+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 28 11:07:51 volumio go-librespot[30834]: time="2026-01-28T11:07:51+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 28 11:07:51 volumio go-librespot[30834]: time="2026-01-28T11:07:51+07:00" level=info msg="zeroconf server listening on port 41217" Jan 28 11:07:51 volumio mpd[30736]: 2026-01-28T11:07:51 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 28 11:07:51 volumio systemd[1]: Started mpd.service - Music Player Daemon. Jan 28 11:07:51 volumio sudo[30707]: pam_unix(sudo:session): session closed for user root Jan 28 11:07:51 volumio sudo[30696]: pam_unix(sudo:session): session closed for user root Jan 28 11:07:51 volumio go-librespot[30834]: time="2026-01-28T11:07:51+07:00" level=debug msg="obtained new client token: AAD1LIFpWxD9OOasarcyaNeTng0cUIhy53qvp/gSZMw5b1KQ0YAnYZQ7EacXo1bpJvq5I5t1j2R8V5TEHzVpnqFUPw/I+MU/4UHXkwLQ0Fi5oAyAE1Hvb+HbU6Q/VK4zpsfP3vipvCeo0OYBudQpVsBYc1vFsC79XHicLjKV40FIgL61R2qZjEn0u7dOseC1nC5IIdGII9XA6MJQYsvuwAUl8EVre7BMP5Nt/0L4H5OQw9xMR3F7hrHSS/Y=" Jan 28 11:07:51 volumio volumio[30517]: error: MPD error: The expression evaluated to a falsy value: Jan 28 11:07:51 volumio volumio[30517]: assert.ok(self.idling) Jan 28 11:07:51 volumio volumio[30517]: error: The expression evaluated to a falsy value: Jan 28 11:07:51 volumio volumio[30517]: assert.ok(self.idling) Jan 28 11:07:51 volumio volumio[30517]: error: updateQueue error: null Jan 28 11:07:51 volumio volumio[30517]: info: MPD running with PID30736 Jan 28 11:07:51 volumio volumio[30517]: ,establishing connection Jan 28 11:07:51 volumio go-librespot[30834]: time="2026-01-28T11:07:51+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 11:07:51 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 11:07:51 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 11:07:51 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 11:07:51 volumio volumio[30517]: info: Completed starting Core Plugins Jan 28 11:07:51 volumio volumio[30517]: info: ------------------------------------------- Jan 28 11:07:51 volumio volumio[30517]: info: ----- MyVolumio plugins startup ---- Jan 28 11:07:51 volumio volumio[30517]: info: ------------------------------------------- Jan 28 11:07:51 volumio volumio[30517]: info: [MyVolumio PluginManager] Fetching plans data.... Jan 28 11:07:51 volumio go-librespot[30834]: time="2026-01-28T11:07:51+07:00" level=debug msg="completed keyexchange" Jan 28 11:07:51 volumio go-librespot[30834]: time="2026-01-28T11:07:51+07:00" level=debug msg="completed challenge" Jan 28 11:07:51 volumio volumio[30517]: error: updateQueue error: null Jan 28 11:07:51 volumio go-librespot[30834]: time="2026-01-28T11:07:51+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 11:07:51 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 11:07:51 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 11:07:53 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 11:07:53 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 11:07:53 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 11:07:53 volumio volumio[30517]: info: Initializing connection to go-librespot Websocket Jan 28 11:07:53 volumio volumio[30517]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 28 11:07:54 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Jan 28 11:07:54 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 11:07:55 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 11:07:55 volumio go-librespot[30846]: go-librespot daemon starting... Jan 28 11:07:55 volumio go-librespot[30847]: time="2026-01-28T11:07:55+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 11:07:55 volumio go-librespot[30847]: time="2026-01-28T11:07:55+07:00" level=debug msg="app state loaded" Jan 28 11:07:55 volumio go-librespot[30847]: time="2026-01-28T11:07:55+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 11:07:55 volumio go-librespot[30847]: time="2026-01-28T11:07:55+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 11:07:55 volumio go-librespot[30847]: time="2026-01-28T11:07:55+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 28 11:07:55 volumio go-librespot[30847]: time="2026-01-28T11:07:55+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 28 11:07:55 volumio go-librespot[30847]: time="2026-01-28T11:07:55+07:00" level=info msg="zeroconf server listening on port 40919" Jan 28 11:07:55 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 11:07:55 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 11:07:55 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 11:07:55 volumio go-librespot[30847]: time="2026-01-28T11:07:55+07:00" level=debug msg="obtained new client token: AAB49kY5yuCThQUGC3kMnk9/DuJLIwNgCgLcVslKOfy3Ko8Un5zyOrxvweUyG11pQCm7GWvDb1PwPGPcEaygiifblIrNSLAx11+f1VAea8eS/doKA2ukYxj7QmitePOxZchCVX7eKoYSAsUvQrL4HvMCB/4RPH6p+Z+09MS0l8L/poVXmJpSEdY5Q8ticyM7Lw0UA7q/wWhR/dJV7uK6LCeOnlkyi9Dvi6Mn90RbU1lKAjjHf3uBSbpZvuM=" Jan 28 11:07:55 volumio go-librespot[30847]: time="2026-01-28T11:07:55+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 11:07:55 volumio go-librespot[30847]: time="2026-01-28T11:07:55+07:00" level=debug msg="completed keyexchange" Jan 28 11:07:55 volumio go-librespot[30847]: time="2026-01-28T11:07:55+07:00" level=debug msg="completed challenge" Jan 28 11:07:56 volumio go-librespot[30847]: time="2026-01-28T11:07:56+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 11:07:56 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 11:07:56 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 11:07:56 volumio volumio[30517]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Jan 28 11:07:56 volumio volumio[30517]: info: Initializing connection to go-librespot Websocket Jan 28 11:07:56 volumio volumio[30517]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 28 11:07:57 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 11:07:57 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 11:07:57 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 11:07:59 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Jan 28 11:07:59 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 11:07:59 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 11:07:59 volumio go-librespot[30855]: go-librespot daemon starting... Jan 28 11:07:59 volumio go-librespot[30856]: time="2026-01-28T11:07:59+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 11:07:59 volumio go-librespot[30856]: time="2026-01-28T11:07:59+07:00" level=debug msg="app state loaded" Jan 28 11:07:59 volumio go-librespot[30856]: time="2026-01-28T11:07:59+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 11:07:59 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 11:07:59 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 11:07:59 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 11:07:59 volumio volumio[30517]: info: Initializing connection to go-librespot Websocket Jan 28 11:07:59 volumio go-librespot[30856]: time="2026-01-28T11:07:59+07:00" level=debug msg="new websocket client" Jan 28 11:07:59 volumio volumio[30517]: info: Connection to go-librespot Websocket established Jan 28 11:07:59 volumio go-librespot[30856]: time="2026-01-28T11:07:59+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 11:07:59 volumio go-librespot[30856]: time="2026-01-28T11:07:59+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 28 11:07:59 volumio go-librespot[30856]: time="2026-01-28T11:07:59+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 28 11:07:59 volumio go-librespot[30856]: time="2026-01-28T11:07:59+07:00" level=info msg="zeroconf server listening on port 40235" Jan 28 11:08:00 volumio go-librespot[30856]: time="2026-01-28T11:08:00+07:00" level=debug msg="obtained new client token: AABbMDOYEFKUVfMYvoYVHfrN+Z2QjocE+v9181/oIsp5xk2JvTqZrFjNyyPG46pzzvGgth6gTu7qgXnNkUZBl9AiZ/TREixDzG8UV36eXdYoSW7uk/i1FzpOIkcMcFb3DJ9CdxxMkSAsu8wTeIXDhVlAcH2X0Q0ztJeDZF/S+V6rEqcwtLfR0dBURKP8540Afry3KI3+xjp5eMUELlUVzW1gqJAq49Db75n6TlHYJdZKnFkqKTJy4qCR" Jan 28 11:08:00 volumio go-librespot[30856]: time="2026-01-28T11:08:00+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 11:08:00 volumio volumio[30517]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Jan 28 11:08:00 volumio volumio[30517]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Jan 28 11:08:00 volumio volumio[30517]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Jan 28 11:08:00 volumio volumio[30517]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Jan 28 11:08:00 volumio volumio[30517]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Jan 28 11:08:00 volumio volumio[30517]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Jan 28 11:08:00 volumio volumio[30517]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Jan 28 11:08:00 volumio volumio[30517]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Jan 28 11:08:00 volumio volumio[30517]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Jan 28 11:08:00 volumio volumio[30517]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Jan 28 11:08:00 volumio volumio[30517]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Jan 28 11:08:00 volumio volumio[30517]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Jan 28 11:08:00 volumio volumio[30517]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Jan 28 11:08:00 volumio volumio[30517]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Jan 28 11:08:00 volumio volumio[30517]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Jan 28 11:08:00 volumio volumio[30517]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Jan 28 11:08:00 volumio volumio[30517]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Jan 28 11:08:00 volumio volumio[30517]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Jan 28 11:08:00 volumio volumio[30517]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Jan 28 11:08:00 volumio volumio[30517]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Jan 28 11:08:00 volumio volumio[30517]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Jan 28 11:08:00 volumio volumio[30517]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Jan 28 11:08:00 volumio volumio[30517]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Jan 28 11:08:00 volumio volumio[30517]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Jan 28 11:08:00 volumio volumio[30517]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Jan 28 11:08:00 volumio volumio[30517]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Jan 28 11:08:00 volumio volumio[30517]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Jan 28 11:08:00 volumio volumio[30517]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Jan 28 11:08:00 volumio volumio[30517]: info: Adding plugin bluetooth to MyMusic Plugins Jan 28 11:08:00 volumio volumio[30517]: info: Adding plugin multiroom to MyMusic Plugins Jan 28 11:08:00 volumio volumio[30517]: info: Adding plugin metavolumio to MyMusic Plugins Jan 28 11:08:00 volumio volumio[30517]: info: Adding plugin cd_controller to MyMusic Plugins Jan 28 11:08:00 volumio volumio[30517]: info: Adding plugin qobuzconnect to MyMusic Plugins Jan 28 11:08:00 volumio volumio[30517]: info: Adding plugin smart_inputs to MyMusic Plugins Jan 28 11:08:00 volumio volumio[30517]: info: Adding plugin tidalconnect to MyMusic Plugins Jan 28 11:08:00 volumio volumio[30517]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Jan 28 11:08:00 volumio go-librespot[30856]: time="2026-01-28T11:08:00+07:00" level=debug msg="completed keyexchange" Jan 28 11:08:00 volumio go-librespot[30856]: time="2026-01-28T11:08:00+07:00" level=debug msg="completed challenge" Jan 28 11:08:00 volumio go-librespot[30856]: time="2026-01-28T11:08:00+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 11:08:00 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 11:08:00 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 11:08:01 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 11:08:01 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 11:08:01 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 11:08:02 volumio volumio[30517]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Jan 28 11:08:02 volumio volumio[30517]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Jan 28 11:08:02 volumio volumio[30517]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 11:08:02 volumio volumio[30517]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 11:08:02 volumio volumio[30517]: info: Starting MyVolumio Remote Streaming Endpoints Jan 28 11:08:02 volumio volumio[30517]: info: MyVolumio login type: Token Jan 28 11:08:02 volumio volumio[30517]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Jan 28 11:08:02 volumio volumio[30517]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Jan 28 11:08:03 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Jan 28 11:08:03 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 11:08:03 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 11:08:03 volumio go-librespot[30878]: go-librespot daemon starting... Jan 28 11:08:03 volumio go-librespot[30879]: time="2026-01-28T11:08:03+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 11:08:03 volumio go-librespot[30879]: time="2026-01-28T11:08:03+07:00" level=debug msg="app state loaded" Jan 28 11:08:03 volumio go-librespot[30879]: time="2026-01-28T11:08:03+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 11:08:03 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 11:08:03 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 11:08:03 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 11:08:03 volumio volumio[30517]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Jan 28 11:08:03 volumio volumio[30517]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Jan 28 11:08:03 volumio volumio[30517]: info: Streaming services startup Jan 28 11:08:03 volumio volumio[30517]: info: Starting Streaming Daemon Jan 28 11:08:03 volumio sudo[30887]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jan 28 11:08:03 volumio sudo[30887]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:08:03 volumio volumio[30517]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Jan 28 11:08:04 volumio sudo[30887]: pam_unix(sudo:session): session closed for user root Jan 28 11:08:04 volumio volumio[30517]: info: Getting Spotify volume Jan 28 11:08:04 volumio go-librespot[30879]: time="2026-01-28T11:08:04+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 11:08:04 volumio go-librespot[30879]: time="2026-01-28T11:08:04+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 28 11:08:04 volumio go-librespot[30879]: time="2026-01-28T11:08:04+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 28 11:08:04 volumio volumio[30517]: info: Connection to go-librespot Websocket closed Jan 28 11:08:04 volumio volumio[30517]: error: Cannot start Volumio Streaming Daemon Jan 28 11:08:04 volumio volumio[30517]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Jan 28 11:08:04 volumio volumio[30517]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Jan 28 11:08:04 volumio go-librespot[30879]: time="2026-01-28T11:08:04+07:00" level=info msg="zeroconf server listening on port 38281" Jan 28 11:08:04 volumio volumio[30517]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Jan 28 11:08:04 volumio go-librespot[30879]: time="2026-01-28T11:08:04+07:00" level=debug msg="obtained new client token: AACogaHPWY85torxStUe/qF/AOArE0PX2ABGo62zTc0Xr0ROmHA9flXguaBE1WKDQm6rwObVjn5Z9L1hG2XCdZA74MssycVNCq2xoZNizVHpolFhkRESAnycSX7DFschg5lmx+QA1BRzUF/++A0afPJeYQDCazEokBhSvqUJh8e6cTyue0X5wakIgk7q5qu9wBRLp80fUUtR0zG2pM6fXC27pMYiNCNCpwmUDoFBME/gT+cyguVQnrZwDOc=" Jan 28 11:08:04 volumio volumio[30517]: info: CoreCommandRouter::volumioGetState Jan 28 11:08:04 volumio volumio[30517]: info: CorePlayQueue::getTrack 0 Jan 28 11:08:04 volumio volumio[30517]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jan 28 11:08:04 volumio volumio[30517]: SPOTIFY: SPOTIFY VOLUME undefined Jan 28 11:08:04 volumio volumio[30517]: SPOTIFY: VOLUMIO VOLUME 100 Jan 28 11:08:04 volumio volumio[30517]: info: Aligning Spotify Volume to Volumio Volume Jan 28 11:08:04 volumio volumio[30517]: info: CoreCommandRouter::volumioGetState Jan 28 11:08:04 volumio volumio[30517]: info: CorePlayQueue::getTrack 0 Jan 28 11:08:04 volumio volumio[30517]: info: Setting Spotify Volume from Volumio: 100 Jan 28 11:08:04 volumio go-librespot[30879]: time="2026-01-28T11:08:04+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 11:08:04 volumio go-librespot[30879]: time="2026-01-28T11:08:04+07:00" level=debug msg="completed keyexchange" Jan 28 11:08:04 volumio go-librespot[30879]: time="2026-01-28T11:08:04+07:00" level=debug msg="completed challenge" Jan 28 11:08:04 volumio go-librespot[30879]: time="2026-01-28T11:08:04+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 11:08:04 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 11:08:04 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 11:08:04 volumio volumio[30517]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 28 11:08:04 volumio volumio[30517]: Error: socket hang up Jan 28 11:08:04 volumio volumio[30517]: at connResetException (node:internal/errors:720:14) Jan 28 11:08:04 volumio volumio[30517]: at Socket.socketOnEnd (node:_http_client:519:23) Jan 28 11:08:04 volumio volumio[30517]: at Socket.emit (node:events:526:35) Jan 28 11:08:04 volumio volumio[30517]: at endReadableNT (node:internal/streams/readable:1376:12) Jan 28 11:08:04 volumio volumio[30517]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Jan 28 11:08:04 volumio volumio[30517]: code: 'ECONNRESET', Jan 28 11:08:04 volumio volumio[30517]: response: undefined Jan 28 11:08:04 volumio volumio[30517]: } Jan 28 11:08:04 volumio volumio[30517]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 28 11:08:05 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 11:08:05 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 11:08:05 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 11:08:06 volumio sudo[30907]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-01-28 11:07' Jan 28 11:08:06 volumio sudo[30907]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:08:06 volumio sudo[30907]: pam_unix(sudo:session): session closed for user root Jan 28 11:08:06 volumio volumio-remote-updater[628]: [2026-01-28 11:08:06] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Jan 28 11:08:06 volumio volumio-remote-updater[628]: [2026-01-28 11:08:06] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Jan 28 11:08:06 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Jan 28 11:08:06 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Jan 28 11:08:06 volumio systemd[1]: volumio.service: Consumed 58.898s CPU time. Jan 28 11:08:06 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 28 11:08:06 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Jan 28 11:08:06 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 10027. Jan 28 11:08:06 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 28 11:08:06 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Jan 28 11:08:06 volumio systemd[1]: volumio.service: Consumed 58.898s CPU time. Jan 28 11:08:06 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Jan 28 11:08:06 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Jan 28 11:08:07 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 11:08:07 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 11:08:07 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 11:08:07 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Jan 28 11:08:07 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 11:08:07 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 11:08:07 volumio go-librespot[30935]: go-librespot daemon starting... Jan 28 11:08:07 volumio go-librespot[30936]: time="2026-01-28T11:08:07+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 11:08:07 volumio go-librespot[30936]: time="2026-01-28T11:08:07+07:00" level=debug msg="app state loaded" Jan 28 11:08:07 volumio go-librespot[30936]: time="2026-01-28T11:08:07+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 11:08:08 volumio go-librespot[30936]: time="2026-01-28T11:08:08+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 28 11:08:08 volumio go-librespot[30936]: time="2026-01-28T11:08:08+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Jan 28 11:08:08 volumio go-librespot[30936]: time="2026-01-28T11:08:08+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Jan 28 11:08:08 volumio go-librespot[30936]: time="2026-01-28T11:08:08+07:00" level=info msg="zeroconf server listening on port 44489" Jan 28 11:08:08 volumio go-librespot[30936]: time="2026-01-28T11:08:08+07:00" level=debug msg="obtained new client token: AACYwotJ/u5k9wDJwTya0Iaun3yaftWWWISAi0orKjTJaPFH6n2uan8xKw2ciHpTYYpIqzcB0+DKWFMXQDXUWZe9yFXIk5b6T3UGFIN2UXpZE6nId3YLwLy+U5Kry0wvZ715ppHVqU6VaGz+4S6wRlqnD2FW/5EqSCT0a41esIKI+bK6TtDt1BcLdu9bTORIKcvY/UhoW+P7lBlRsPBoIssQjRRVAjVqip9U0RbrscHYlddlFyl3yeOgokY=" Jan 28 11:08:08 volumio go-librespot[30936]: time="2026-01-28T11:08:08+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 11:08:08 volumio go-librespot[30936]: time="2026-01-28T11:08:08+07:00" level=debug msg="completed keyexchange" Jan 28 11:08:08 volumio go-librespot[30936]: time="2026-01-28T11:08:08+07:00" level=debug msg="completed challenge" Jan 28 11:08:08 volumio go-librespot[30936]: time="2026-01-28T11:08: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 28 11:08:08 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 11:08:08 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 11:08:09 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 11:08:09 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 11:08:09 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 11:08:10 volumio volumio[30920]: info: ------------------------------------------- Jan 28 11:08:10 volumio volumio[30920]: info: ----- Volumio3 ---- Jan 28 11:08:10 volumio volumio[30920]: info: ------------------------------------------- Jan 28 11:08:10 volumio volumio[30920]: info: ----- System startup ---- Jan 28 11:08:10 volumio volumio[30920]: info: ------------------------------------------- Jan 28 11:08:11 volumio volumio-remote-updater[628]: [2026-01-28 11:08:11] [connect] Successful connection Jan 28 11:08:11 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 11:08:11 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 11:08:11 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 11:08:11 volumio volumio[30920]: info: MYVOLUMIO Environment detected Jan 28 11:08:11 volumio volumio[30920]: info: Plugin folders cleanup Jan 28 11:08:11 volumio volumio[30920]: info: Scanning into folder /volumio/app/plugins/ Jan 28 11:08:11 volumio volumio[30920]: info: Scanning category audio_interface Jan 28 11:08:11 volumio volumio[30920]: info: Scanning category miscellanea Jan 28 11:08:11 volumio volumio[30920]: info: Scanning category music_service Jan 28 11:08:11 volumio volumio[30920]: info: Scanning category plugins.json Jan 28 11:08:11 volumio volumio[30920]: info: Scanning category system_controller Jan 28 11:08:11 volumio volumio[30920]: info: Scanning category user_interface Jan 28 11:08:11 volumio volumio[30920]: info: Scanning into folder /data/plugins/ Jan 28 11:08:11 volumio volumio[30920]: info: Scanning category music_service Jan 28 11:08:11 volumio volumio[30920]: info: Plugin folders cleanup completed Jan 28 11:08:11 volumio volumio[30920]: info: ------------------------------------------- Jan 28 11:08:11 volumio volumio[30920]: info: ----- Core plugins startup ---- Jan 28 11:08:11 volumio volumio[30920]: info: ------------------------------------------- Jan 28 11:08:11 volumio volumio[30920]: info: Loading plugins from folder /volumio/app/plugins/ Jan 28 11:08:11 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Jan 28 11:08:11 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 11:08:11 volumio volumio[30920]: info: Adding plugin upnp to MyMusic Plugins Jan 28 11:08:12 volumio volumio[30920]: info: Adding plugin airplay_emulation to MyMusic Plugins Jan 28 11:08:12 volumio volumio[30920]: info: Adding plugin upnp_browser to MyMusic Plugins Jan 28 11:08:12 volumio volumio[30920]: info: Loading plugins from folder /data/plugins/ Jan 28 11:08:12 volumio volumio[30920]: info: Loading plugin "system"... Jan 28 11:08:12 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 11:08:12 volumio go-librespot[30952]: go-librespot daemon starting... Jan 28 11:08:12 volumio volumio[30920]: info: Loading plugin "appearance"... Jan 28 11:08:12 volumio go-librespot[30953]: time="2026-01-28T11:08:12+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 11:08:12 volumio go-librespot[30953]: time="2026-01-28T11:08:12+07:00" level=debug msg="app state loaded" Jan 28 11:08:12 volumio go-librespot[30953]: time="2026-01-28T11:08:12+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 11:08:12 volumio go-librespot[30953]: time="2026-01-28T11:08:12+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 11:08:12 volumio go-librespot[30953]: time="2026-01-28T11:08:12+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 28 11:08:12 volumio go-librespot[30953]: time="2026-01-28T11:08:12+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 28 11:08:12 volumio go-librespot[30953]: time="2026-01-28T11:08:12+07:00" level=info msg="zeroconf server listening on port 35433" Jan 28 11:08:12 volumio go-librespot[30953]: time="2026-01-28T11:08:12+07:00" level=debug msg="obtained new client token: AADDC13fAvRMGPIuy8IZwZrWpQzK6b4LLXig8EzgWxCo/poMcVDIJHZMjJnj1RwHk+/2d31EPTae6cKyWlVsb9r+J2Is9aLazMulxMf9bBZFRM7H7uINP4msK67/pYL5U6ihBBIN+WXbSat172InjkmQfWnzq2kbrlTk2koSYXxxgDwYsdKz4C8Oew1YCkbZROBz6Bp5/6K3fD+TA6m+m3TCZ9am0Qjo7vpb5Y4NbzcxHAU0MwE464Iu2v4=" Jan 28 11:08:12 volumio go-librespot[30953]: time="2026-01-28T11:08:12+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 11:08:13 volumio go-librespot[30953]: time="2026-01-28T11:08:13+07:00" level=debug msg="completed keyexchange" Jan 28 11:08:13 volumio go-librespot[30953]: time="2026-01-28T11:08:13+07:00" level=debug msg="completed challenge" Jan 28 11:08:13 volumio go-librespot[30953]: time="2026-01-28T11:08:13+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 11:08:13 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 11:08:13 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 11:08:13 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 11:08:13 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 11:08:13 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 11:08:14 volumio volumio[30920]: info: Loading plugin "network"... Jan 28 11:08:14 volumio volumio[30920]: info: Refreshing Cached IP Addresses Jan 28 11:08:14 volumio sudo[30965]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 28 11:08:14 volumio sudo[30965]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:08:14 volumio volumio[30920]: info: Loading plugin "services"... Jan 28 11:08:14 volumio sudo[30967]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 28 11:08:14 volumio sudo[30967]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:08:14 volumio volumio[30920]: info: Loading plugin "alsa_controller"... Jan 28 11:08:14 volumio sudo[30965]: pam_unix(sudo:session): session closed for user root Jan 28 11:08:14 volumio sudo[30967]: pam_unix(sudo:session): session closed for user root Jan 28 11:08:14 volumio sudo[30978]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Jan 28 11:08:14 volumio sudo[30978]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:08:14 volumio volumio[30920]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 28 11:08:14 volumio volumio[30920]: info: Loading plugin "wizard"... Jan 28 11:08:14 volumio volumio[30920]: info: Loading plugin "networkfs"... Jan 28 11:08:14 volumio volumio[30920]: info: Starting Udev Watcher for removable devices Jan 28 11:08:14 volumio volumio[30920]: info: Ignoring mount for partition: boot Jan 28 11:08:14 volumio volumio[30920]: info: Ignoring mount for partition: volumio Jan 28 11:08:14 volumio volumio[30920]: info: Ignoring mount for partition: volumio_data Jan 28 11:08:14 volumio volumio[30920]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 28 11:08:14 volumio volumio[30920]: info: Loading plugin "volumio_command_line_client"... Jan 28 11:08:14 volumio volumio[30920]: info: Loading plugin "upnp"... Jan 28 11:08:14 volumio volumio[30920]: info: [1769573294486] Starting Upmpd Daemon Jan 28 11:08:14 volumio volumio[30920]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 28 11:08:14 volumio volumio[30920]: info: Loading plugin "my_music"... Jan 28 11:08:14 volumio volumio[30920]: info: Loading plugin "mpd"... Jan 28 11:08:15 volumio volumio[30920]: info: Loading plugin "upnp_browser"... Jan 28 11:08:15 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 11:08:15 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 11:08:15 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 11:08:16 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Jan 28 11:08:16 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 11:08:16 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 11:08:16 volumio go-librespot[30998]: go-librespot daemon starting... Jan 28 11:08:16 volumio go-librespot[30999]: time="2026-01-28T11:08:16+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 11:08:16 volumio go-librespot[30999]: time="2026-01-28T11:08:16+07:00" level=debug msg="app state loaded" Jan 28 11:08:16 volumio go-librespot[30999]: time="2026-01-28T11:08:16+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 11:08:16 volumio go-librespot[30999]: time="2026-01-28T11:08: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 28 11:08:16 volumio go-librespot[30999]: time="2026-01-28T11:08: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 28 11:08:16 volumio go-librespot[30999]: time="2026-01-28T11:08: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 28 11:08:16 volumio go-librespot[30999]: time="2026-01-28T11:08:16+07:00" level=info msg="zeroconf server listening on port 36021" Jan 28 11:08:17 volumio sudo[30978]: pam_unix(sudo:session): session closed for user root Jan 28 11:08:17 volumio go-librespot[30999]: time="2026-01-28T11:08:17+07:00" level=debug msg="obtained new client token: AABNiQ+B0zf7flObILI48OaXjpg43I/aKGfCFZ7BbCu6teFHVKBqAkymdu0lpvDdf7k+cN7mWbLpa3Bqma9yiI4UD/PvzpE/LDh0X5HZLub9nRvUv5QEMjcdsMjtbssgk2FzQDpuJQkicquklviocaAFsavCexRwQKe10YzoneYHY5fhMWiF4kwiquIg+AgrbaqkW6jagXBa5LrCQV8dn06cISUCI4GGPl23rINZ+KUM6P5gFA4zX1vG" Jan 28 11:08:17 volumio go-librespot[30999]: time="2026-01-28T11:08:17+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 11:08:17 volumio go-librespot[30999]: time="2026-01-28T11:08:17+07:00" level=debug msg="completed keyexchange" Jan 28 11:08:17 volumio go-librespot[30999]: time="2026-01-28T11:08:17+07:00" level=debug msg="completed challenge" Jan 28 11:08:17 volumio go-librespot[30999]: time="2026-01-28T11:08:17+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 11:08:17 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 11:08:17 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 11:08:17 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 11:08:17 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 11:08:17 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 11:08:18 volumio volumio[30920]: info: Starting UPNP Browser Jan 28 11:08:18 volumio volumio[30920]: info: Loading plugin "alarm-clock"... Jan 28 11:08:18 volumio volumio[30920]: info: Loading plugin "airplay_emulation"... Jan 28 11:08:18 volumio volumio[30920]: info: Starting Shairport Sync Jan 28 11:08:18 volumio volumio[30920]: info: Loading plugin "last_100"... Jan 28 11:08:18 volumio volumio[30920]: info: Loading plugin "webradio"... Jan 28 11:08:18 volumio volumio[30920]: info: Loading plugin "i2s_dacs"... Jan 28 11:08:18 volumio volumio[30920]: info: Loading plugin "volumiodiscovery"... Jan 28 11:08:18 volumio volumio[30920]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 28 11:08:18 volumio volumio[30920]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 11:08:18 volumio volumio[30920]: *** WARNING *** For more information see Jan 28 11:08:18 volumio volumio[30920]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 28 11:08:18 volumio volumio[30920]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 11:08:18 volumio volumio[30920]: *** WARNING *** For more information see Jan 28 11:08:18 volumio node[30920]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 28 11:08:18 volumio node[30920]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 11:08:18 volumio node[30920]: *** WARNING *** For more information see Jan 28 11:08:18 volumio node[30920]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 28 11:08:18 volumio node[30920]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 11:08:18 volumio node[30920]: *** WARNING *** For more information see Jan 28 11:08:18 volumio volumio[30920]: info: Applying required configuration parameters for plugin volumiodiscovery Jan 28 11:08:18 volumio volumio[30920]: info: Discovery: Started advertising with name: Volumio Jan 28 11:08:18 volumio volumio[30920]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 28 11:08:18 volumio volumio[30920]: info: Loading plugin "spop"... Jan 28 11:08:19 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 11:08:19 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 11:08:19 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 11:08:20 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Jan 28 11:08:20 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 11:08:20 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 11:08:20 volumio go-librespot[31009]: go-librespot daemon starting... Jan 28 11:08:20 volumio go-librespot[31010]: time="2026-01-28T11:08:20+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 11:08:20 volumio go-librespot[31010]: time="2026-01-28T11:08:20+07:00" level=debug msg="app state loaded" Jan 28 11:08:20 volumio go-librespot[31010]: time="2026-01-28T11:08:20+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 11:08:20 volumio volumio[30920]: info: Loading plugin "ytcr"... Jan 28 11:08:21 volumio go-librespot[31010]: time="2026-01-28T11:08:21+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 11:08:21 volumio go-librespot[31010]: time="2026-01-28T11:08:21+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 28 11:08:21 volumio go-librespot[31010]: time="2026-01-28T11:08:21+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 28 11:08:21 volumio go-librespot[31010]: time="2026-01-28T11:08:21+07:00" level=info msg="zeroconf server listening on port 42217" Jan 28 11:08:21 volumio go-librespot[31010]: time="2026-01-28T11:08:21+07:00" level=debug msg="obtained new client token: AAATb0PShyeWSIfZQnHnzExbxO7T9TicdfU+tXwX6bnoKGwcoJ+HW0pIV7awXJMiWB4RM5TuHbJfkfKzj55NZbfkigdPp7x8uiogmFD/M16kGMbbHjaICiXcRPYi7uHF3ZB+LBZvHndpHeb33A43ujgn6pscT+79F4YIg15t0ummOqKwBA0UD8KpMBLYnb7vL9cVTsNhLqLBb91V7FLT/FTqf7cRGnYe+AObnOmQ5IcWikZCF14xTNNol5M=" Jan 28 11:08:21 volumio go-librespot[31010]: time="2026-01-28T11:08:21+07:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:4070, retrying with a different AP" error="dial tcp 104.199.241.202:4070: connect: connection refused" Jan 28 11:08:21 volumio go-librespot[31010]: time="2026-01-28T11:08:21+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Jan 28 11:08:21 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 11:08:21 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 11:08:21 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 11:08:21 volumio go-librespot[31010]: time="2026-01-28T11:08:21+07:00" level=debug msg="completed keyexchange" Jan 28 11:08:21 volumio go-librespot[31010]: time="2026-01-28T11:08:21+07:00" level=debug msg="completed challenge" Jan 28 11:08:21 volumio go-librespot[31010]: time="2026-01-28T11:08:21+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 11:08:21 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 11:08:21 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 11:08:23 volumio volumio[30920]: info: Loading plugin "ytmusic"... Jan 28 11:08:23 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 11:08:23 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 11:08:23 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 11:08:24 volumio volumio-remote-updater[628]: [2026-01-28 11:08:24] [connect] Successful connection Jan 28 11:08:24 volumio volumio[30920]: info: Loading plugin "outputs"... Jan 28 11:08:24 volumio volumio[30920]: info: Loading plugin "albumart"... Jan 28 11:08:24 volumio volumio[30920]: info: Plugin example_plugin is not enabled Jan 28 11:08:24 volumio volumio[30920]: info: Loading plugin "inputs"... Jan 28 11:08:24 volumio volumio[30920]: info: Loading plugin "updater_comm"... Jan 28 11:08:24 volumio volumio[30920]: info: Plugin mpdemulation is not enabled Jan 28 11:08:24 volumio volumio[30920]: info: Loading plugin "rest_api"... Jan 28 11:08:24 volumio volumio[30920]: info: Loading plugin "websocket"... Jan 28 11:08:24 volumio volumio[30920]: info: Starting Socket.io Server version 1.7.4 Jan 28 11:08:24 volumio volumio[30920]: info: Loading plugin "RoonBridge"... Jan 28 11:08:24 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Jan 28 11:08:24 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 11:08:25 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 11:08:25 volumio go-librespot[31041]: go-librespot daemon starting... Jan 28 11:08:25 volumio go-librespot[31042]: time="2026-01-28T11:08:25+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 11:08:25 volumio go-librespot[31042]: time="2026-01-28T11:08:25+07:00" level=debug msg="app state loaded" Jan 28 11:08:25 volumio go-librespot[31042]: time="2026-01-28T11:08:25+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 11:08:25 volumio volumio[30920]: info: Applying required configuration parameters for plugin RoonBridge Jan 28 11:08:25 volumio volumio[30920]: info: Loading i18n strings for locale en Jan 28 11:08:25 volumio volumio[30920]: Updating browse sources language Jan 28 11:08:25 volumio volumio[30920]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 11:08:25 volumio go-librespot[31042]: time="2026-01-28T11:08:25+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 11:08:25 volumio go-librespot[31042]: time="2026-01-28T11:08:25+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 28 11:08:25 volumio go-librespot[31042]: time="2026-01-28T11:08:25+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 28 11:08:25 volumio go-librespot[31042]: time="2026-01-28T11:08:25+07:00" level=info msg="zeroconf server listening on port 41651" Jan 28 11:08:25 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 11:08:25 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 11:08:25 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 11:08:25 volumio volumio[31031]: Forking 3 albumart workers Jan 28 11:08:25 volumio volumio[30920]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 28 11:08:25 volumio volumio[30920]: info: CoreCommandRouter::initPlayerControls Jan 28 11:08:25 volumio volumio[30920]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:08:25 volumio volumio[30920]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:08:25 volumio volumio[30920]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:08:25 volumio volumio[30920]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:08:25 volumio volumio[30920]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:08:25 volumio volumio[30920]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:08:25 volumio volumio[30920]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:08:25 volumio volumio[30920]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:08:25 volumio volumio[30920]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 28 11:08:25 volumio volumio[30920]: Express server listening on port 3000 Jan 28 11:08:25 volumio volumio[30920]: [Metrics] WebUI: 16s 279.85ms Jan 28 11:08:25 volumio volumio[30920]: info: CoreStateMachine::resetVolumioState Jan 28 11:08:25 volumio volumio[30920]: info: CoreStateMachine::getcurrentVolume Jan 28 11:08:25 volumio volumio[30920]: info: CoreCommandRouter::volumioRetrievevolume Jan 28 11:08:25 volumio go-librespot[31042]: time="2026-01-28T11:08:25+07:00" level=debug msg="obtained new client token: AACKk5jooMjdbJ5Lzx6ixsuJm5PETHWWlGmq2HF1gf/Plvd3ycrAhqpCt0YpJ/kauibJsvZDuDYnJHEYq3I6dRKHGC+nlQ5s8wp9/WZp07QQTuNe0bijkODrKeAx3bJPuISyKwCBtqPID0wDpurMZADI32pv305B86n8EcXLDwkmysT/Rry+FYu4zZ0Qm/AoOKUPbaStRtIsgReY1Jgevw2INk30psYSs5JS/cgGd8jwUCQ7P5cwnZc9Pfo=" Jan 28 11:08:26 volumio go-librespot[31042]: time="2026-01-28T11:08:26+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 11:08:26 volumio sudo[31083]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 28 11:08:26 volumio sudo[31083]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:08:26 volumio sudo[31085]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 28 11:08:26 volumio sudo[31085]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:08:26 volumio sudo[31083]: pam_unix(sudo:session): session closed for user root Jan 28 11:08:26 volumio sudo[31085]: pam_unix(sudo:session): session closed for user root Jan 28 11:08:26 volumio volumio[30920]: info: Volumio Network Manager: Network status updated: 1 Jan 28 11:08:26 volumio go-librespot[31042]: time="2026-01-28T11:08:26+07:00" level=debug msg="completed keyexchange" Jan 28 11:08:26 volumio go-librespot[31042]: time="2026-01-28T11:08:26+07:00" level=debug msg="completed challenge" Jan 28 11:08:26 volumio go-librespot[31042]: time="2026-01-28T11:08:26+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 11:08:26 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 11:08:26 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 11:08:26 volumio volumio[30920]: info: VolumeController:: Volume=100 Mute =false Jan 28 11:08:26 volumio volumio[30920]: info: CoreStateMachine::pushState Jan 28 11:08:26 volumio volumio[30920]: info: CorePlayQueue::getTrack 0 Jan 28 11:08:26 volumio volumio[30920]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 28 11:08:26 volumio volumio[30920]: info: CoreCommandRouter::volumioPushState Jan 28 11:08:26 volumio volumio[30920]: info: CoreStateMachine::updateTrackBlock Jan 28 11:08:26 volumio volumio[30920]: info: CorePlayQueue::getTrackBlock Jan 28 11:08:26 volumio volumio[30920]: info: CoreCommandRouter::volumioRetrievevolume Jan 28 11:08:26 volumio volumio-remote-updater[628]: [2026-01-28 11:08:26] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1769573304 101 Jan 28 11:08:26 volumio volumio[30920]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 1 Jan 28 11:08:26 volumio volumio[30920]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 11:08:26 volumio volumio[30920]: info: Reloading queue from file Jan 28 11:08:26 volumio volumio[30920]: info: CoreStateMachine::setRepeat null single undefined Jan 28 11:08:26 volumio volumio[30920]: info: CoreStateMachine::pushState Jan 28 11:08:26 volumio volumio[30920]: info: CorePlayQueue::getTrack 0 Jan 28 11:08:26 volumio volumio[30920]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 28 11:08:26 volumio volumio[30920]: info: CoreCommandRouter::volumioPushState Jan 28 11:08:26 volumio volumio[30920]: info: CoreStateMachine::setRandom null Jan 28 11:08:26 volumio volumio[30920]: info: CoreStateMachine::pushState Jan 28 11:08:26 volumio volumio[30920]: info: CorePlayQueue::getTrack 0 Jan 28 11:08:26 volumio volumio[30920]: info: CoreCommandRouter::volumioPushState Jan 28 11:08:26 volumio volumio[30920]: info: Setting Device type: Raspberry PI Jan 28 11:08:26 volumio volumio[30920]: info: Completed loading Core Plugins Jan 28 11:08:26 volumio volumio[30920]: info: Preparing to generate the ALSA configuration file Jan 28 11:08:26 volumio volumio[30920]: info: VolumeController:: Volume=100 Mute =false Jan 28 11:08:26 volumio volumio[30920]: info: CoreStateMachine::pushState Jan 28 11:08:26 volumio volumio[30920]: info: CorePlayQueue::getTrack 0 Jan 28 11:08:26 volumio volumio[30920]: info: CoreCommandRouter::volumioPushState Jan 28 11:08:26 volumio volumio[30920]: info: Asound.conf file unchanged, so no further update is needed Jan 28 11:08:26 volumio volumio[30920]: info: Output device has changed, restarting MPD Jan 28 11:08:27 volumio volumio[30920]: info: Output device has changed, restarting Shairport Sync Jan 28 11:08:27 volumio volumio[30920]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:08:27 volumio volumio[30920]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 11:08:27 volumio sudo[31105]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 28 11:08:27 volumio sudo[31101]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Jan 28 11:08:27 volumio sudo[31105]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:08:27 volumio sudo[31101]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:08:27 volumio sudo[31103]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 28 11:08:27 volumio sudo[31103]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:08:27 volumio sudo[31103]: pam_unix(sudo:session): session closed for user root Jan 28 11:08:27 volumio volumio[30920]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 28 11:08:27 volumio volumio[30920]: info: ___________ START PLUGINS ___________ Jan 28 11:08:27 volumio volumio[30920]: info: ControllerMpd::onStart: Initializing MPD Jan 28 11:08:27 volumio volumio[30920]: info: Creating MPD Configuration file Jan 28 11:08:27 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Jan 28 11:08:27 volumio sudo[31101]: pam_unix(sudo:session): session closed for user root Jan 28 11:08:27 volumio volumio[30920]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 28 11:08:27 volumio volumio[30920]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 11:08:27 volumio volumio[30920]: info: [1769573307355] CoreMusicLibrary::Adding element Media Servers Jan 28 11:08:27 volumio volumio[30920]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 11:08:27 volumio sudo[31116]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 28 11:08:27 volumio sudo[31116]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:08:27 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 28 11:08:27 volumio sudo[31114]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 28 11:08:27 volumio sudo[31114]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:08:27 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 28 11:08:27 volumio systemd[1]: mpd.service: Consumed 7.504s CPU time. Jan 28 11:08:27 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 28 11:08:27 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 28 11:08:27 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 28 11:08:27 volumio sudo[31114]: pam_unix(sudo:session): session closed for user root Jan 28 11:08:27 volumio volumio[30920]: info: UPNP Browser: Client initialized successfully Jan 28 11:08:27 volumio volumio[30920]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:08:27 volumio volumio[30920]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 11:08:27 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 28 11:08:27 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 28 11:08:27 volumio volumio[30920]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 28 11:08:27 volumio volumio[30920]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:08:27 volumio volumio[30920]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 11:08:27 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 28 11:08:27 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 28 11:08:27 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 28 11:08:27 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 28 11:08:27 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 28 11:08:27 volumio volumio[30920]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 28 11:08:27 volumio volumio[30920]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 11:08:27 volumio volumio[30920]: info: [1769573307664] CoreMusicLibrary::Adding element Last_100 Jan 28 11:08:27 volumio volumio[30920]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 11:08:27 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 11:08:27 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 11:08:27 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 11:08:27 volumio volumio[30920]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 11:08:27 volumio volumio[30920]: info: [1769573307683] CoreMusicLibrary::Adding element Webradio Jan 28 11:08:27 volumio volumio[30920]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 11:08:27 volumio volumio[30920]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 28 11:08:27 volumio volumio[30920]: info: Initializing BBC Radios Jan 28 11:08:27 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 28 11:08:27 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 28 11:08:27 volumio volumio[30920]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 28 11:08:27 volumio volumio[30920]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 11:08:27 volumio volumio[30920]: info: Creating Spotify config file Jan 28 11:08:27 volumio volumio[30920]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:08:28 volumio sudo[31133]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 28 11:08:28 volumio sudo[31133]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jan 28 11:08:28 volumio sudo[31133]: pam_unix(sudo:session): session closed for user root Jan 28 11:08:28 volumio volumio[31050]: Starting albumart workers Jan 28 11:08:28 volumio volumio[31051]: Starting albumart workers Jan 28 11:08:29 volumio volumio[31052]: Starting albumart workers Jan 28 11:08:29 volumio volumio[30920]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 11:08:29 volumio volumio[30920]: info: [1769573309159] CoreMusicLibrary::Adding element YouTube Music Jan 28 11:08:29 volumio volumio[30920]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 11:08:29 volumio volumio[30920]: Cannot find translation for source YouTube Music Jan 28 11:08:29 volumio volumio[30920]: info: Volumio Calling Home Jan 28 11:08:29 volumio sudo[31147]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Jan 28 11:08:29 volumio sudo[31147]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:08:29 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Jan 28 11:08:29 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 11:08:29 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 11:08:29 volumio go-librespot[31152]: go-librespot daemon starting... Jan 28 11:08:29 volumio sudo[31147]: pam_unix(sudo:session): session closed for user root Jan 28 11:08:29 volumio go-librespot[31153]: time="2026-01-28T11:08:29+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 11:08:29 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 11:08:29 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 11:08:29 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 11:08:30 volumio go-librespot[31153]: time="2026-01-28T11:08:30+07:00" level=info msg="zeroconf server listening on port 43333" Jan 28 11:08:30 volumio volumio[30920]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Jan 28 11:08:30 volumio volumio[30920]: info: Discovery: Found device Volumio Jan 28 11:08:30 volumio volumio[30920]: info: CoreCommandRouter::volumioGetState Jan 28 11:08:30 volumio volumio[30920]: info: CorePlayQueue::getTrack 0 Jan 28 11:08:30 volumio volumio[30920]: info: MPD Permissions set Jan 28 11:08:30 volumio volumio[30920]: info: MPD Permissions set Jan 28 11:08:30 volumio volumio[30920]: info: Upmpdcli Daemon Started Jan 28 11:08:30 volumio volumio[30920]: info: Spotify config file written Jan 28 11:08:30 volumio volumio[30920]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Jan 28 11:08:30 volumio volumio[30920]: info: Discovery: Found device Volumio Jan 28 11:08:30 volumio volumio[30920]: info: CoreCommandRouter::volumioGetState Jan 28 11:08:30 volumio volumio[30920]: info: CorePlayQueue::getTrack 0 Jan 28 11:08:30 volumio sudo[31161]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jan 28 11:08:30 volumio sudo[31161]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:08:30 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Jan 28 11:08:31 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Jan 28 11:08:31 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 11:08:31 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 11:08:31 volumio go-librespot[31172]: go-librespot daemon starting... Jan 28 11:08:31 volumio sudo[31161]: pam_unix(sudo:session): session closed for user root Jan 28 11:08:31 volumio volumio[30920]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Jan 28 11:08:31 volumio go-librespot[31176]: time="2026-01-28T11:08:31+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 11:08:31 volumio go-librespot[31176]: time="2026-01-28T11:08:31+07:00" level=debug msg="app state loaded" Jan 28 11:08:31 volumio go-librespot[31176]: time="2026-01-28T11:08:31+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 11:08:31 volumio volumio[30920]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:08:31 volumio volumio[30920]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:08:31 volumio volumio[30920]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:08:31 volumio volumio[30920]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:08:31 volumio volumio[30920]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:08:31 volumio volumio[30920]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:08:31 volumio volumio[30920]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:08:31 volumio volumio[30920]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:08:31 volumio volumio[30920]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 11:08:31 volumio volumio[30920]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:08:31 volumio volumio[30920]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:08:31 volumio volumio[30920]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:08:31 volumio volumio[30920]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:08:31 volumio volumio[30920]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:08:31 volumio volumio[30920]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:08:31 volumio volumio[30920]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:08:31 volumio volumio[30920]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:08:31 volumio volumio[30920]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:08:31 volumio volumio[30920]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 11:08:31 volumio volumio[30920]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 11:08:31 volumio volumio[30920]: info: No need to fix Spotify hosts Jan 28 11:08:31 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 11:08:31 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 11:08:31 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 11:08:31 volumio go-librespot[31176]: time="2026-01-28T11:08:31+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 28 11:08:31 volumio go-librespot[31176]: time="2026-01-28T11:08:31+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Jan 28 11:08:31 volumio go-librespot[31176]: time="2026-01-28T11:08:31+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Jan 28 11:08:31 volumio go-librespot[31176]: time="2026-01-28T11:08:31+07:00" level=info msg="zeroconf server listening on port 42751" Jan 28 11:08:31 volumio volumio[30920]: info: Volumio called home Jan 28 11:08:32 volumio go-librespot[31176]: time="2026-01-28T11:08:32+07:00" level=debug msg="obtained new client token: AABLJYdwJeYR5lJveMHVX98p5Y8kr4QH4cp9F4vJhVkOH6M5kedccDoIGX0tbhCQ4l3jt9j7MCfZQ6LVnIwp9+bk5ubkViDZu1pV/4FKPXcUJWdm8hrbNsx2gFKid1kODRRrddT1GQl71+X88L9w7AyROMWAzir/vAQcG7jPm8b7MJlHy935orwDoKcpzjLcpoWi1Bp3koOuzQf9QoKDaElvMMyuX2Ot5OHxUmLnEryGHoV+kpWmadzG5Zk=" Jan 28 11:08:32 volumio go-librespot[31176]: time="2026-01-28T11:08:32+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 11:08:32 volumio volumio[30920]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 28 11:08:32 volumio volumio[30920]: SPOTIFY: BQCZcCWBzmdWKm72qHtco8xD-npEPmUcHbnL_uu20DyW0wQ4wp_h7Sjd5RS76TJvTNLSTlNDKym8b5hzMyUqlgvSCx8GNLnSVQqdgFEajGpbH0tZK4iVYh35TxkcEfQcHjq0AqHRs3UljlY4i5mmFfBB-ZKDoS_72S8bc_FiT7YiHvn4j3Quj_SEplho4r-eJYEYC-LJVFaHGi8tY9vpnAOP7Y7hYn25RFmudnzt2D00PwZt-4F5-z0oqjWO0xQxeAi2BCgnqi7egNs6EUTtVKoX9bvLknKLkw83nIp5HIYyweeMVLqSyQsb Jan 28 11:08:32 volumio volumio[30920]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 28 11:08:32 volumio volumio[30920]: info: New Spotify access token = BQCZcCWBzmdWKm72qHtco8xD-npEPmUcHbnL_uu20DyW0wQ4wp_h7Sjd5RS76TJvTNLSTlNDKym8b5hzMyUqlgvSCx8GNLnSVQqdgFEajGpbH0tZK4iVYh35TxkcEfQcHjq0AqHRs3UljlY4i5mmFfBB-ZKDoS_72S8bc_FiT7YiHvn4j3Quj_SEplho4r-eJYEYC-LJVFaHGi8tY9vpnAOP7Y7hYn25RFmudnzt2D00PwZt-4F5-z0oqjWO0xQxeAi2BCgnqi7egNs6EUTtVKoX9bvLknKLkw83nIp5HIYyweeMVLqSyQsb Jan 28 11:08:32 volumio volumio[30920]: info: Spotify credentials grant success - running version from March 24, 2019 Jan 28 11:08:32 volumio go-librespot[31176]: time="2026-01-28T11:08:32+07:00" level=debug msg="completed keyexchange" Jan 28 11:08:32 volumio go-librespot[31176]: time="2026-01-28T11:08:32+07:00" level=debug msg="completed challenge" Jan 28 11:08:32 volumio go-librespot[31176]: time="2026-01-28T11:08: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 28 11:08:32 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 11:08:32 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 11:08:32 volumio volumio[30920]: info: Starting Shairport Sync Jan 28 11:08:32 volumio volumio[30920]: info: Starting Shairport Sync Jan 28 11:08:32 volumio volumio[30920]: info: Starting Shairport Sync Jan 28 11:08:32 volumio sudo[31201]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 28 11:08:32 volumio sudo[31201]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:08:32 volumio sudo[31203]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 28 11:08:32 volumio sudo[31203]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:08:32 volumio sudo[31206]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 28 11:08:32 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 28 11:08:32 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Jan 28 11:08:32 volumio sudo[31206]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:08:32 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 28 11:08:32 volumio systemd[1]: shairport-sync.service: Consumed 2.366s CPU time. Jan 28 11:08:32 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 28 11:08:32 volumio sudo[31201]: pam_unix(sudo:session): session closed for user root Jan 28 11:08:32 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 28 11:08:32 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Jan 28 11:08:32 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 28 11:08:32 volumio volumio[30920]: info: Shairport-Sync Started Jan 28 11:08:32 volumio volumio[30920]: Error adding Membership: Error: addMembership EINVAL Jan 28 11:08:32 volumio volumio[30920]: info: CoreCommandRouter::volumioGetState Jan 28 11:08:32 volumio volumio[30920]: info: CorePlayQueue::getTrack 0 Jan 28 11:08:32 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 28 11:08:32 volumio sudo[31203]: pam_unix(sudo:session): session closed for user root Jan 28 11:08:32 volumio sudo[31206]: pam_unix(sudo:session): session closed for user root Jan 28 11:08:33 volumio volumio[30920]: info: Shairport-Sync Started Jan 28 11:08:33 volumio volumio[30920]: info: Shairport-Sync Started Jan 28 11:08:33 volumio volumio[30920]: SPOTIFY: User informations: {"country":"PK","display_name":"215mmgea6kss3jxeqsqdquvji","email":"linh.ngotran@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/215mmgea6kss3jxeqsqdquvji"},"followers":{"href":null,"total":1},"href":"https://api.spotify.com/v1/users/215mmgea6kss3jxeqsqdquvji","id":"215mmgea6kss3jxeqsqdquvji","images":[],"product":"premium","type":"user","uri":"spotify:user:215mmgea6kss3jxeqsqdquvji"} Jan 28 11:08:33 volumio volumio[30920]: info: Spotify Successfully logged in Jan 28 11:08:33 volumio volumio[30920]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 11:08:33 volumio volumio[30920]: info: [1769573313228] CoreMusicLibrary::Adding element Spotify Jan 28 11:08:33 volumio volumio[30920]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 11:08:33 volumio volumio[30920]: Cannot find translation for source YouTube Music Jan 28 11:08:33 volumio volumio[30920]: Cannot find translation for source Spotify Jan 28 11:08:33 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 11:08:33 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 11:08:33 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 11:08:33 volumio volumio[30920]: info: [yt-cast-receiver] DIAL server listening on port 8098 Jan 28 11:08:33 volumio volumio[30920]: info: CoreCommandRouter::volumioRetrievevolume Jan 28 11:08:34 volumio volumio[30920]: info: VolumeController:: Volume=100 Mute =false Jan 28 11:08:34 volumio volumio[30920]: info: CoreCommandRouter::volumioGetState Jan 28 11:08:34 volumio volumio[30920]: info: CorePlayQueue::getTrack 0 Jan 28 11:08:34 volumio volumio[30920]: info: CoreStateMachine::pushState Jan 28 11:08:34 volumio volumio[30920]: info: CorePlayQueue::getTrack 0 Jan 28 11:08:34 volumio volumio[30920]: info: CoreCommandRouter::volumioPushState Jan 28 11:08:34 volumio volumio[30920]: info: go-librespot daemon successfully initialized Jan 28 11:08:35 volumio mpd[31145]: 2026-01-28T11:08:35 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 28 11:08:35 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Jan 28 11:08:35 volumio systemd[1]: Started mpd.service - Music Player Daemon. Jan 28 11:08:35 volumio sudo[31105]: pam_unix(sudo:session): session closed for user root Jan 28 11:08:35 volumio sudo[31116]: pam_unix(sudo:session): session closed for user root Jan 28 11:08:35 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 11:08:35 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 11:08:35 volumio go-librespot[31259]: go-librespot daemon starting... Jan 28 11:08:35 volumio go-librespot[31262]: time="2026-01-28T11:08:35+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 11:08:35 volumio go-librespot[31262]: time="2026-01-28T11:08:35+07:00" level=debug msg="app state loaded" Jan 28 11:08:35 volumio go-librespot[31262]: time="2026-01-28T11:08:35+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 11:08:35 volumio volumio[30920]: error: MPD error: The expression evaluated to a falsy value: Jan 28 11:08:35 volumio volumio[30920]: assert.ok(self.idling) Jan 28 11:08:35 volumio volumio[30920]: error: The expression evaluated to a falsy value: Jan 28 11:08:35 volumio volumio[30920]: assert.ok(self.idling) Jan 28 11:08:35 volumio volumio[30920]: info: MPD running with PID31145 Jan 28 11:08:35 volumio volumio[30920]: ,establishing connection Jan 28 11:08:35 volumio volumio[30920]: error: updateQueue error: null Jan 28 11:08:35 volumio volumio[30920]: info: Completed starting Core Plugins Jan 28 11:08:35 volumio volumio[30920]: info: ------------------------------------------- Jan 28 11:08:35 volumio volumio[30920]: info: ----- MyVolumio plugins startup ---- Jan 28 11:08:35 volumio volumio[30920]: info: ------------------------------------------- Jan 28 11:08:35 volumio volumio[30920]: info: [MyVolumio PluginManager] Fetching plans data.... Jan 28 11:08:35 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 11:08:35 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 11:08:35 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 11:08:35 volumio volumio[30920]: error: updateQueue error: null Jan 28 11:08:36 volumio go-librespot[31262]: time="2026-01-28T11:08: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-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 28 11:08:36 volumio go-librespot[31262]: time="2026-01-28T11:08:36+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Jan 28 11:08:36 volumio go-librespot[31262]: time="2026-01-28T11:08:36+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Jan 28 11:08:36 volumio go-librespot[31262]: time="2026-01-28T11:08:36+07:00" level=info msg="zeroconf server listening on port 36197" Jan 28 11:08:36 volumio go-librespot[31262]: time="2026-01-28T11:08:36+07:00" level=debug msg="obtained new client token: AABs4Ek0jSjuXWIRS6vI437lzwAM+uUAJ9vH0vl43T/VTxtDH0mDxUApTXGQqM6h6i7ugU1yxQnF4x8rRRRpoDSUUvETnHkTMOkgFcANqG+RHx9l6Jc0hRP+/7XE1y+B0TA37mH89vBXo2HTEiLWRwgeMt4i1W15bzloSJ2ERrU+pkIAtOZ4fbuRvNUFBfByo8U3VsLs6A5VXFKV0xsjiNLcjt2ZCe+BO0Dv/ixkHJma59ZnqGBiCnMU3uU=" Jan 28 11:08:36 volumio go-librespot[31262]: time="2026-01-28T11:08:36+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 11:08:36 volumio go-librespot[31262]: time="2026-01-28T11:08:36+07:00" level=debug msg="completed keyexchange" Jan 28 11:08:36 volumio go-librespot[31262]: time="2026-01-28T11:08:36+07:00" level=debug msg="completed challenge" Jan 28 11:08:36 volumio go-librespot[31262]: time="2026-01-28T11:08:36+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 11:08:36 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 11:08:36 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 11:08:37 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 11:08:37 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 11:08:37 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 11:08:37 volumio volumio[30920]: info: Initializing connection to go-librespot Websocket Jan 28 11:08:37 volumio volumio[30920]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 28 11:08:39 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 11:08:39 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 11:08:39 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 11:08:39 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Jan 28 11:08:39 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 11:08:39 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 11:08:39 volumio go-librespot[31270]: go-librespot daemon starting... Jan 28 11:08:39 volumio go-librespot[31271]: time="2026-01-28T11:08:39+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 11:08:39 volumio go-librespot[31271]: time="2026-01-28T11:08:39+07:00" level=debug msg="app state loaded" Jan 28 11:08:39 volumio go-librespot[31271]: time="2026-01-28T11:08:39+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 11:08:40 volumio go-librespot[31271]: time="2026-01-28T11:08: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 11:08:40 volumio go-librespot[31271]: time="2026-01-28T11:08:40+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 28 11:08:40 volumio go-librespot[31271]: time="2026-01-28T11:08:40+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 28 11:08:40 volumio go-librespot[31271]: time="2026-01-28T11:08:40+07:00" level=info msg="zeroconf server listening on port 40545" Jan 28 11:08:40 volumio volumio[30920]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Jan 28 11:08:40 volumio go-librespot[31271]: time="2026-01-28T11:08:40+07:00" level=debug msg="obtained new client token: AABoZjp/yuQSfiGnqjTaMoc7tab3ZWX/dUKBMS3kzvlgJp+BuU1gswith8nyEchkvSSm1vSaO3OhR5uMxPD5LkArOIq6fhIw3lfh9hFi0TUMagAsJWWrqkT+hf+goZwhhuW/LG+C1+amu4r8fD2RxGrmu6RnfHxVNyMDVPEYY7/wLVdDevICfbXfrSLeAe+xiYuRUWFduNpTRDuwWkzt83/lFLD46Smcy/4ENVWnGZXIARWpzv8oKxNpICU=" Jan 28 11:08:40 volumio go-librespot[31271]: time="2026-01-28T11:08:40+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 11:08:40 volumio go-librespot[31271]: time="2026-01-28T11:08:40+07:00" level=debug msg="completed keyexchange" Jan 28 11:08:40 volumio go-librespot[31271]: time="2026-01-28T11:08:40+07:00" level=debug msg="completed challenge" Jan 28 11:08:40 volumio go-librespot[31271]: time="2026-01-28T11:08:40+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 11:08:40 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 11:08:40 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 11:08:40 volumio volumio[30920]: info: Initializing connection to go-librespot Websocket Jan 28 11:08:40 volumio volumio[30920]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 28 11:08:41 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 11:08:41 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 11:08:41 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 11:08:43 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 11:08:43 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 11:08:43 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 11:08:43 volumio volumio[30920]: info: Initializing connection to go-librespot Websocket Jan 28 11:08:43 volumio volumio[30920]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 28 11:08:43 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Jan 28 11:08:43 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 11:08:44 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 11:08:44 volumio go-librespot[31278]: go-librespot daemon starting... Jan 28 11:08:44 volumio go-librespot[31279]: time="2026-01-28T11:08:44+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 11:08:44 volumio go-librespot[31279]: time="2026-01-28T11:08:44+07:00" level=debug msg="app state loaded" Jan 28 11:08:44 volumio go-librespot[31279]: time="2026-01-28T11:08:44+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 11:08:44 volumio volumio[30920]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Jan 28 11:08:44 volumio volumio[30920]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Jan 28 11:08:44 volumio volumio[30920]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Jan 28 11:08:44 volumio volumio[30920]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Jan 28 11:08:44 volumio volumio[30920]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Jan 28 11:08:44 volumio volumio[30920]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Jan 28 11:08:44 volumio volumio[30920]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Jan 28 11:08:44 volumio volumio[30920]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Jan 28 11:08:44 volumio volumio[30920]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Jan 28 11:08:44 volumio volumio[30920]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Jan 28 11:08:44 volumio volumio[30920]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Jan 28 11:08:44 volumio volumio[30920]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Jan 28 11:08:44 volumio volumio[30920]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Jan 28 11:08:44 volumio volumio[30920]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Jan 28 11:08:44 volumio volumio[30920]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Jan 28 11:08:44 volumio volumio[30920]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Jan 28 11:08:44 volumio volumio[30920]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Jan 28 11:08:44 volumio volumio[30920]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Jan 28 11:08:44 volumio volumio[30920]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Jan 28 11:08:44 volumio volumio[30920]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Jan 28 11:08:44 volumio volumio[30920]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Jan 28 11:08:44 volumio volumio[30920]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Jan 28 11:08:44 volumio volumio[30920]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Jan 28 11:08:44 volumio volumio[30920]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Jan 28 11:08:44 volumio volumio[30920]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Jan 28 11:08:44 volumio volumio[30920]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Jan 28 11:08:44 volumio volumio[30920]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Jan 28 11:08:44 volumio volumio[30920]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Jan 28 11:08:44 volumio volumio[30920]: info: Adding plugin bluetooth to MyMusic Plugins Jan 28 11:08:44 volumio volumio[30920]: info: Adding plugin multiroom to MyMusic Plugins Jan 28 11:08:44 volumio volumio[30920]: info: Adding plugin metavolumio to MyMusic Plugins Jan 28 11:08:44 volumio volumio[30920]: info: Adding plugin cd_controller to MyMusic Plugins Jan 28 11:08:44 volumio volumio[30920]: info: Adding plugin qobuzconnect to MyMusic Plugins Jan 28 11:08:44 volumio volumio[30920]: info: Adding plugin smart_inputs to MyMusic Plugins Jan 28 11:08:44 volumio volumio[30920]: info: Adding plugin tidalconnect to MyMusic Plugins Jan 28 11:08:44 volumio volumio[30920]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Jan 28 11:08:44 volumio go-librespot[31279]: time="2026-01-28T11:08:44+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 28 11:08:44 volumio go-librespot[31279]: time="2026-01-28T11:08:44+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Jan 28 11:08:44 volumio go-librespot[31279]: time="2026-01-28T11:08:44+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Jan 28 11:08:44 volumio go-librespot[31279]: time="2026-01-28T11:08:44+07:00" level=info msg="zeroconf server listening on port 36517" Jan 28 11:08:44 volumio go-librespot[31279]: time="2026-01-28T11:08:44+07:00" level=debug msg="obtained new client token: AADMDINa3itv4oHbp1IDt4WIrh5uWVPVITHr8QBAvwDmZ+zsanExU60OfWrYStZDw//7VQR6Y1gcXC6L0HN53YBft3MwViOm1pqtzD9A/ynmDmLSI/gL/A5G+2qIB9UnwOuPDgL1GzFFMHeFXL+X4G92rAwkwZiU/3YYWCtHfhC2gEYRDssNfz33C+pyndlPoptPGJfFYTJcFogDHRumqHQOW6ENbuuInFLNFbL1T0M9zctxP+J2kR7iWrg=" Jan 28 11:08:44 volumio go-librespot[31279]: time="2026-01-28T11:08:44+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 11:08:45 volumio go-librespot[31279]: time="2026-01-28T11:08:45+07:00" level=debug msg="completed keyexchange" Jan 28 11:08:45 volumio go-librespot[31279]: time="2026-01-28T11:08:45+07:00" level=debug msg="completed challenge" Jan 28 11:08:45 volumio go-librespot[31279]: time="2026-01-28T11:08: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 28 11:08:45 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 11:08:45 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 11:08:45 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 11:08:45 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 11:08:45 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 11:08:46 volumio volumio[30920]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Jan 28 11:08:46 volumio volumio[30920]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Jan 28 11:08:46 volumio volumio[30920]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 11:08:46 volumio volumio[30920]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 11:08:46 volumio volumio[30920]: info: Starting MyVolumio Remote Streaming Endpoints Jan 28 11:08:46 volumio volumio[30920]: info: MyVolumio login type: Token Jan 28 11:08:46 volumio volumio[30920]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Jan 28 11:08:46 volumio volumio[30920]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Jan 28 11:08:47 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 11:08:47 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 11:08:47 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 11:08:48 volumio volumio[30920]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Jan 28 11:08:48 volumio volumio[30920]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Jan 28 11:08:48 volumio volumio[30920]: info: Streaming services startup Jan 28 11:08:48 volumio volumio[30920]: info: Starting Streaming Daemon Jan 28 11:08:48 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Jan 28 11:08:48 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 11:08:48 volumio sudo[31303]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jan 28 11:08:48 volumio sudo[31303]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:08:48 volumio volumio[30920]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Jan 28 11:08:48 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 11:08:48 volumio go-librespot[31306]: go-librespot daemon starting... Jan 28 11:08:48 volumio sudo[31303]: pam_unix(sudo:session): session closed for user root Jan 28 11:08:48 volumio go-librespot[31310]: time="2026-01-28T11:08:48+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 11:08:48 volumio go-librespot[31310]: time="2026-01-28T11:08:48+07:00" level=debug msg="app state loaded" Jan 28 11:08:48 volumio go-librespot[31310]: time="2026-01-28T11:08:48+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 11:08:48 volumio volumio[30920]: info: Initializing connection to go-librespot Websocket Jan 28 11:08:48 volumio volumio[30920]: error: Cannot start Volumio Streaming Daemon Jan 28 11:08:48 volumio volumio[30920]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Jan 28 11:08:48 volumio volumio[30920]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Jan 28 11:08:48 volumio go-librespot[31310]: time="2026-01-28T11:08:48+07:00" level=debug msg="new websocket client" Jan 28 11:08:48 volumio volumio[30920]: info: Connection to go-librespot Websocket established Jan 28 11:08:48 volumio go-librespot[31310]: time="2026-01-28T11:08:48+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 11:08:48 volumio go-librespot[31310]: time="2026-01-28T11:08:48+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 28 11:08:48 volumio go-librespot[31310]: time="2026-01-28T11:08:48+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 28 11:08:48 volumio go-librespot[31310]: time="2026-01-28T11:08:48+07:00" level=info msg="zeroconf server listening on port 42439" Jan 28 11:08:49 volumio go-librespot[31310]: time="2026-01-28T11:08:49+07:00" level=debug msg="obtained new client token: AACXkxVRtZ8pSdxSon0iX2h91c8+s1eW/QkLTC2lB1ApAetqJkM7eJYatzPA1lC5EcifARyyCxgwOk3z7EiWg0fXCz4wQQjBy9xPTs7qMeuA8CubrJJpoB2cJs4K7/klASiTQaska15yuLKLS+dmgysiBtbilh3vxotdhuC0WO3/BzF0ixn78+csWz1Pa5MnsgZW5tertCzUBCHTAIDxJYnfl6Zg8L0UcwK4wtNDtfxp6+a7rlOulnTX" Jan 28 11:08:49 volumio go-librespot[31310]: time="2026-01-28T11:08:49+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 11:08:49 volumio go-librespot[31310]: time="2026-01-28T11:08:49+07:00" level=debug msg="completed keyexchange" Jan 28 11:08:49 volumio go-librespot[31310]: time="2026-01-28T11:08:49+07:00" level=debug msg="completed challenge" Jan 28 11:08:49 volumio go-librespot[31310]: time="2026-01-28T11:08:49+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 11:08:49 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 11:08:49 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 11:08:49 volumio volumio[30920]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Jan 28 11:08:49 volumio volumio[30920]: info: Connection to go-librespot Websocket closed Jan 28 11:08:49 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 11:08:49 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 11:08:49 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 11:08:50 volumio volumio[30920]: info: MyVolumio token set successfully Jan 28 11:08:50 volumio volumio[30920]: info: MYVOLUMIO: Adding device Jan 28 11:08:50 volumio volumio[30920]: info: MYVOLUMIO: Evaluating Server Jan 28 11:08:51 volumio volumio[30920]: info: MyVolumio status changed Jan 28 11:08:51 volumio volumio[30920]: info: Streaming services startup Jan 28 11:08:51 volumio volumio[30920]: info: Starting Streaming Daemon Jan 28 11:08:51 volumio volumio[30920]: info: Removing browser output: myVolumio user plan is not superstar Jan 28 11:08:51 volumio volumio[30920]: info: Removing audio output: Jan 28 11:08:51 volumio volumio[30920]: info: Stoppping Tunnel 1 Jan 28 11:08:51 volumio sudo[31339]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jan 28 11:08:51 volumio sudo[31339]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:08:51 volumio sudo[31339]: pam_unix(sudo:session): session closed for user root Jan 28 11:08:51 volumio sudo[31342]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Jan 28 11:08:51 volumio volumio[30920]: error: Cannot start Volumio Streaming Daemon Jan 28 11:08:51 volumio sudo[31342]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:08:51 volumio volumio[30920]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Jan 28 11:08:51 volumio volumio[30920]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Jan 28 11:08:51 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 28 11:08:51 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 28 11:08:51 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 28 11:08:51 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 28 11:08:51 volumio volumio[30920]: info: Setting Geolocation for MyVolumio to as1 Jan 28 11:08:51 volumio volumio[30920]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 11:08:51 volumio volumio[30920]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 11:08:51 volumio volumio[30920]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 11:08:51 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 28 11:08:51 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 28 11:08:51 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 28 11:08:51 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 28 11:08:51 volumio sudo[31342]: pam_unix(sudo:session): session closed for user root Jan 28 11:08:51 volumio volumio[30920]: info: Remote SSH Stopped Jan 28 11:08:51 volumio volumio[30920]: info: Getting Spotify volume Jan 28 11:08:51 volumio volumio[30920]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 28 11:08:51 volumio volumio[30920]: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 28 11:08:51 volumio volumio[30920]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Jan 28 11:08:51 volumio volumio[30920]: errno: -111, Jan 28 11:08:51 volumio volumio[30920]: code: 'ECONNREFUSED', Jan 28 11:08:51 volumio volumio[30920]: syscall: 'connect', Jan 28 11:08:51 volumio volumio[30920]: address: '127.0.0.1', Jan 28 11:08:51 volumio volumio[30920]: port: 9879, Jan 28 11:08:51 volumio volumio[30920]: response: undefined Jan 28 11:08:51 volumio volumio[30920]: } Jan 28 11:08:51 volumio volumio[30920]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 28 11:08:51 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 11:08:51 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 11:08:51 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 11:08:52 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Jan 28 11:08:52 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 11:08:52 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 11:08:52 volumio go-librespot[31356]: go-librespot daemon starting... Jan 28 11:08:52 volumio go-librespot[31357]: time="2026-01-28T11:08:52+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 11:08:52 volumio go-librespot[31357]: time="2026-01-28T11:08:52+07:00" level=debug msg="app state loaded" Jan 28 11:08:52 volumio go-librespot[31357]: time="2026-01-28T11:08:52+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 11:08:52 volumio sudo[31367]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-01-28 11:07' Jan 28 11:08:53 volumio sudo[31367]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 11:08:53 volumio go-librespot[31357]: time="2026-01-28T11:08:53+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 11:08:53 volumio go-librespot[31357]: time="2026-01-28T11:08:53+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 28 11:08:53 volumio go-librespot[31357]: time="2026-01-28T11:08:53+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 28 11:08:53 volumio go-librespot[31357]: time="2026-01-28T11:08:53+07:00" level=info msg="zeroconf server listening on port 34449" Jan 28 11:08:53 volumio go-librespot[31357]: time="2026-01-28T11:08:53+07:00" level=debug msg="obtained new client token: AADeqUtk6sgNntDqZ16cfXhachSCgL2QWlKG1VSE5SPjyo5Jv2z9I2C/PWEjiGUqtH6nr6w3Zr1saayxaary7w3kXAwIumGAkqfDpdRYP+IyywFqbCfEM1RrhUL2H8J2qG41XCWqUotkccdgDCyl6fLt2QbN34QV0V+8y5hxZCjMp+tB5KncOBT8o2BEVy8+mfdNkylajAkQfSWAh3HOSPlHdGOzRyGFAOfS4IrcWbbaVJsbnMEqjSU6on4=" 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"