Jan 28 14:44:00 volumio volumio[9350]: info: Shairport-Sync Started Jan 28 14:44:00 volumio volumio[9350]: Error adding Membership: Error: addMembership EINVAL Jan 28 14:44:00 volumio volumio[9350]: info: Shairport-Sync Started Jan 28 14:44:00 volumio volumio[9350]: info: Shairport-Sync Started Jan 28 14:44:00 volumio volumio[9350]: info: CoreCommandRouter::volumioGetState Jan 28 14:44:00 volumio volumio[9350]: info: CorePlayQueue::getTrack 0 Jan 28 14:44:00 volumio volumio[9350]: 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 14:44:00 volumio volumio[9350]: info: Spotify Successfully logged in Jan 28 14:44:00 volumio volumio[9350]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 14:44:00 volumio volumio[9350]: info: [1769586240343] CoreMusicLibrary::Adding element Spotify Jan 28 14:44:00 volumio volumio[9350]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 14:44:00 volumio volumio[9350]: Cannot find translation for source YouTube Music Jan 28 14:44:00 volumio volumio[9350]: Cannot find translation for source Spotify Jan 28 14:44:00 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 14:44:00 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 14:44:00 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 14:44:00 volumio volumio[9350]: info: [yt-cast-receiver] DIAL server listening on port 8098 Jan 28 14:44:01 volumio volumio[9350]: info: CoreCommandRouter::volumioRetrievevolume Jan 28 14:44:01 volumio volumio[9350]: info: VolumeController:: Volume=100 Mute =false Jan 28 14:44:01 volumio volumio[9350]: info: CoreCommandRouter::volumioGetState Jan 28 14:44:01 volumio volumio[9350]: info: CorePlayQueue::getTrack 0 Jan 28 14:44:01 volumio volumio[9350]: info: CoreStateMachine::pushState Jan 28 14:44:01 volumio volumio[9350]: info: CorePlayQueue::getTrack 0 Jan 28 14:44:01 volumio volumio[9350]: info: CoreCommandRouter::volumioPushState Jan 28 14:44:02 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Jan 28 14:44:02 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 14:44:02 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 14:44:02 volumio go-librespot[9667]: go-librespot daemon starting... Jan 28 14:44:02 volumio volumio[9350]: info: go-librespot daemon successfully initialized Jan 28 14:44:02 volumio go-librespot[9668]: time="2026-01-28T14:44:02+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 14:44:02 volumio go-librespot[9668]: time="2026-01-28T14:44:02+07:00" level=debug msg="app state loaded" Jan 28 14:44:02 volumio go-librespot[9668]: time="2026-01-28T14:44:02+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 14:44:02 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 14:44:02 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 14:44:02 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 14:44:02 volumio mpd[9578]: 2026-01-28T14:44:02 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 28 14:44:02 volumio systemd[1]: Started mpd.service - Music Player Daemon. Jan 28 14:44:02 volumio sudo[9541]: pam_unix(sudo:session): session closed for user root Jan 28 14:44:02 volumio sudo[9550]: pam_unix(sudo:session): session closed for user root Jan 28 14:44:03 volumio go-librespot[9668]: time="2026-01-28T14:44:03+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 14:44:03 volumio go-librespot[9668]: time="2026-01-28T14:44:03+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 28 14:44:03 volumio go-librespot[9668]: time="2026-01-28T14:44:03+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 28 14:44:03 volumio go-librespot[9668]: time="2026-01-28T14:44:03+07:00" level=info msg="zeroconf server listening on port 35949" Jan 28 14:44:03 volumio volumio[9350]: error: MPD error: The expression evaluated to a falsy value: Jan 28 14:44:03 volumio volumio[9350]: assert.ok(self.idling) Jan 28 14:44:03 volumio volumio[9350]: error: The expression evaluated to a falsy value: Jan 28 14:44:03 volumio volumio[9350]: assert.ok(self.idling) Jan 28 14:44:03 volumio volumio[9350]: info: MPD running with PID9578 Jan 28 14:44:03 volumio volumio[9350]: ,establishing connection Jan 28 14:44:03 volumio volumio[9350]: error: updateQueue error: null Jan 28 14:44:03 volumio volumio[9350]: info: Completed starting Core Plugins Jan 28 14:44:03 volumio volumio[9350]: info: ------------------------------------------- Jan 28 14:44:03 volumio volumio[9350]: info: ----- MyVolumio plugins startup ---- Jan 28 14:44:03 volumio volumio[9350]: info: ------------------------------------------- Jan 28 14:44:03 volumio volumio[9350]: info: [MyVolumio PluginManager] Fetching plans data.... Jan 28 14:44:03 volumio go-librespot[9668]: time="2026-01-28T14:44:03+07:00" level=debug msg="obtained new client token: AABlFLpm/XrTv95gY0rxb3nqUKTUO39x+HjqF3oVFkoxM3ogpqOEEFziZaC/A+RZYyyDMzPfdpYhgeBWx4AKIt9A9LEUvHlauQFhiiu3lUHAS2FbUy4gIOYTHPnudWh6Bu+xiaTbvfk6FwMgic639Ew/8Na7dA2a98pa4m0yTd1g2eTF8fca/O7TK5QWwUshFiJRllHK2zH1ISLV2gjIoBez3Q5ps3TLH4Jd461a45X4S0fbGMOwIZv40lg=" Jan 28 14:44:03 volumio volumio[9350]: error: updateQueue error: null Jan 28 14:44:03 volumio go-librespot[9668]: time="2026-01-28T14:44:03+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 14:44:03 volumio go-librespot[9668]: time="2026-01-28T14:44:03+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Jan 28 14:44:03 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 14:44:03 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 14:44:04 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 14:44:04 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 14:44:04 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 14:44:05 volumio volumio[9350]: info: Initializing connection to go-librespot Websocket Jan 28 14:44:05 volumio volumio[9350]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 28 14:44:06 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 11. Jan 28 14:44:06 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 14:44:06 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 14:44:06 volumio go-librespot[9679]: go-librespot daemon starting... Jan 28 14:44:06 volumio go-librespot[9683]: time="2026-01-28T14:44:06+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 14:44:06 volumio go-librespot[9683]: time="2026-01-28T14:44:06+07:00" level=debug msg="app state loaded" Jan 28 14:44:06 volumio go-librespot[9683]: time="2026-01-28T14:44:06+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 14:44:06 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 14:44:06 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 14:44:06 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 14:44:07 volumio go-librespot[9683]: time="2026-01-28T14:44:07+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 28 14:44:07 volumio go-librespot[9683]: time="2026-01-28T14:44:07+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Jan 28 14:44:07 volumio go-librespot[9683]: time="2026-01-28T14:44:07+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Jan 28 14:44:07 volumio go-librespot[9683]: time="2026-01-28T14:44:07+07:00" level=info msg="zeroconf server listening on port 43677" Jan 28 14:44:07 volumio go-librespot[9683]: time="2026-01-28T14:44:07+07:00" level=debug msg="obtained new client token: AABECZ/3QAWN3PyjVShKSrANR043MZEKefKY9Ox/dw0vZOiT/f4B3/YfDHXzpcsYyvuRG6ZEp8KsKBKbRAZxxd94gA/264jcxSLF/nHkXPYlKhxVKxZYzBql4ZsmjJ3PYREXLcMTe9bKB1ET2WxNanbLF2QJiXmDnVa0sfU7vRoVNUOztC1heg8l3KeCmGBHqRIh+H2CN6NMi9WDpUX9fC0VCFlHUNo4Um2o4n3mAXzUruOfHnPX4ezp7oI=" Jan 28 14:44:07 volumio go-librespot[9683]: time="2026-01-28T14:44:07+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 14:44:07 volumio go-librespot[9683]: time="2026-01-28T14:44:07+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Jan 28 14:44:07 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 14:44:07 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 14:44:08 volumio volumio[9350]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Jan 28 14:44:08 volumio volumio[9350]: info: Initializing connection to go-librespot Websocket Jan 28 14:44:08 volumio volumio[9350]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 28 14:44:08 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 14:44:08 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 14:44:08 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 14:44:10 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 12. Jan 28 14:44:10 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 14:44:10 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 14:44:10 volumio go-librespot[9690]: go-librespot daemon starting... Jan 28 14:44:10 volumio go-librespot[9691]: time="2026-01-28T14:44:10+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 14:44:10 volumio go-librespot[9691]: time="2026-01-28T14:44:10+07:00" level=debug msg="app state loaded" Jan 28 14:44:10 volumio go-librespot[9691]: time="2026-01-28T14:44:10+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 14:44:10 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 14:44:10 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 14:44:10 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 14:44:11 volumio go-librespot[9691]: time="2026-01-28T14:44:11+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 28 14:44:11 volumio go-librespot[9691]: time="2026-01-28T14:44:11+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 14:44:11 volumio go-librespot[9691]: time="2026-01-28T14:44:11+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 14:44:11 volumio go-librespot[9691]: time="2026-01-28T14:44:11+07:00" level=info msg="zeroconf server listening on port 33533" Jan 28 14:44:11 volumio volumio[9350]: info: Initializing connection to go-librespot Websocket Jan 28 14:44:11 volumio go-librespot[9691]: time="2026-01-28T14:44:11+07:00" level=debug msg="new websocket client" Jan 28 14:44:11 volumio volumio[9350]: info: Connection to go-librespot Websocket established Jan 28 14:44:11 volumio go-librespot[9691]: time="2026-01-28T14:44:11+07:00" level=debug msg="obtained new client token: AADjZasye5r+KpSS0IcVNb9pm3NouyCTR/zK0XjoHvJ57X67JtliQ0dlYO+tf0CDFfHksXFkAjyATmTwh1GsI23GnUNaqWSp1C9Pn+5QH+8XZdxuyYQ3T6g0H/qPOP20erLcK1RCw2WlCL42PVMm5qiQqzwT1QnstzVKl/Fvg1qSmWMnm4TDfq00q1rZZf8eZD9FF6DfrlO9/IyoKBFbXPJo7xb9sTO7qiM0Hit7KMHIazX1Ir3VyzwaeMA=" Jan 28 14:44:11 volumio go-librespot[9691]: time="2026-01-28T14:44:11+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 14:44:11 volumio go-librespot[9691]: time="2026-01-28T14:44:11+07:00" level=debug msg="completed keyexchange" Jan 28 14:44:11 volumio go-librespot[9691]: time="2026-01-28T14:44:11+07:00" level=debug msg="completed challenge" Jan 28 14:44:11 volumio go-librespot[9691]: time="2026-01-28T14:44:11+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 14:44:11 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 14:44:11 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 14:44:11 volumio volumio[9350]: info: Connection to go-librespot Websocket closed Jan 28 14:44:12 volumio volumio[9350]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Jan 28 14:44:12 volumio volumio[9350]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Jan 28 14:44:12 volumio volumio[9350]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Jan 28 14:44:12 volumio volumio[9350]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Jan 28 14:44:12 volumio volumio[9350]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Jan 28 14:44:12 volumio volumio[9350]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Jan 28 14:44:12 volumio volumio[9350]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Jan 28 14:44:12 volumio volumio[9350]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Jan 28 14:44:12 volumio volumio[9350]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Jan 28 14:44:12 volumio volumio[9350]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Jan 28 14:44:12 volumio volumio[9350]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Jan 28 14:44:12 volumio volumio[9350]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Jan 28 14:44:12 volumio volumio[9350]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Jan 28 14:44:12 volumio volumio[9350]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Jan 28 14:44:12 volumio volumio[9350]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Jan 28 14:44:12 volumio volumio[9350]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Jan 28 14:44:12 volumio volumio[9350]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Jan 28 14:44:12 volumio volumio[9350]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Jan 28 14:44:12 volumio volumio[9350]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Jan 28 14:44:12 volumio volumio[9350]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Jan 28 14:44:12 volumio volumio[9350]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Jan 28 14:44:12 volumio volumio[9350]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Jan 28 14:44:12 volumio volumio[9350]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Jan 28 14:44:12 volumio volumio[9350]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Jan 28 14:44:12 volumio volumio[9350]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Jan 28 14:44:12 volumio volumio[9350]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Jan 28 14:44:12 volumio volumio[9350]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Jan 28 14:44:12 volumio volumio[9350]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Jan 28 14:44:12 volumio volumio[9350]: info: Adding plugin bluetooth to MyMusic Plugins Jan 28 14:44:12 volumio volumio[9350]: info: Adding plugin multiroom to MyMusic Plugins Jan 28 14:44:12 volumio volumio[9350]: info: Adding plugin metavolumio to MyMusic Plugins Jan 28 14:44:12 volumio volumio[9350]: info: Adding plugin cd_controller to MyMusic Plugins Jan 28 14:44:12 volumio volumio[9350]: info: Adding plugin qobuzconnect to MyMusic Plugins Jan 28 14:44:12 volumio volumio[9350]: info: Adding plugin smart_inputs to MyMusic Plugins Jan 28 14:44:12 volumio volumio[9350]: info: Adding plugin tidalconnect to MyMusic Plugins Jan 28 14:44:12 volumio volumio[9350]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Jan 28 14:44:12 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 14:44:12 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 14:44:12 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 14:44:14 volumio volumio[9350]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Jan 28 14:44:14 volumio volumio[9350]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Jan 28 14:44:14 volumio volumio[9350]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 14:44:14 volumio volumio[9350]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 14:44:14 volumio volumio[9350]: info: Starting MyVolumio Remote Streaming Endpoints Jan 28 14:44:14 volumio volumio[9350]: info: MyVolumio login type: Token Jan 28 14:44:14 volumio volumio[9350]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Jan 28 14:44:14 volumio volumio[9350]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Jan 28 14:44:14 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 14:44:14 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 14:44:14 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 14:44:14 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 13. Jan 28 14:44:14 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 14:44:15 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 14:44:15 volumio go-librespot[9712]: go-librespot daemon starting... Jan 28 14:44:15 volumio go-librespot[9713]: time="2026-01-28T14:44:15+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 14:44:15 volumio go-librespot[9713]: time="2026-01-28T14:44:15+07:00" level=debug msg="app state loaded" Jan 28 14:44:15 volumio go-librespot[9713]: time="2026-01-28T14:44:15+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 14:44:15 volumio go-librespot[9713]: time="2026-01-28T14:44:15+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 14:44:15 volumio go-librespot[9713]: time="2026-01-28T14:44:15+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 14:44:15 volumio go-librespot[9713]: time="2026-01-28T14:44:15+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 14:44:15 volumio go-librespot[9713]: time="2026-01-28T14:44:15+07:00" level=info msg="zeroconf server listening on port 42495" Jan 28 14:44:15 volumio volumio[9350]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Jan 28 14:44:15 volumio volumio[9350]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Jan 28 14:44:15 volumio volumio[9350]: info: Streaming services startup Jan 28 14:44:15 volumio volumio[9350]: info: Starting Streaming Daemon Jan 28 14:44:15 volumio go-librespot[9713]: time="2026-01-28T14:44:15+07:00" level=debug msg="obtained new client token: AAC+aTgXnfFtC+EF01Xfb0T1WTM6O62EDoRiqNzNMs1fapZhurXLqlEuxCd9SEZWUYJWi8C6lVBCnVU40U6N9o1qGtmdc1nN5JUMsLdgswkcMl16I3gEgqt5HDghxZAMjvnbGDc9tiY5Dw07xWvtYavoE0UmQy5h2COZXXVqRC/I4+zNwosQqgbu1rLCpCmxZr8617zO88EYlgAT6B0ozkndo6V+y4roN/yfnWaykI/9DOvOyA3Mhtj5MEI=" Jan 28 14:44:15 volumio sudo[9721]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jan 28 14:44:15 volumio sudo[9721]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 14:44:15 volumio volumio[9350]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Jan 28 14:44:15 volumio sudo[9721]: pam_unix(sudo:session): session closed for user root Jan 28 14:44:15 volumio go-librespot[9713]: time="2026-01-28T14:44:15+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 14:44:16 volumio volumio[9350]: info: Getting Spotify volume Jan 28 14:44:16 volumio volumio[9350]: info: Initializing connection to go-librespot Websocket Jan 28 14:44:16 volumio volumio[9350]: error: Cannot start Volumio Streaming Daemon Jan 28 14:44:16 volumio go-librespot[9713]: time="2026-01-28T14:44:16+07:00" level=debug msg="completed keyexchange" Jan 28 14:44:16 volumio go-librespot[9713]: time="2026-01-28T14:44:16+07:00" level=debug msg="completed challenge" Jan 28 14:44:16 volumio volumio[9350]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Jan 28 14:44:16 volumio volumio[9350]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Jan 28 14:44:16 volumio go-librespot[9713]: time="2026-01-28T14:44:16+07:00" level=debug msg="new websocket client" Jan 28 14:44:16 volumio volumio[9350]: 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 14:44:16 volumio volumio[9350]: info: Connection to go-librespot Websocket established Jan 28 14:44:16 volumio go-librespot[9713]: time="2026-01-28T14:44:16+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 14:44:16 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 14:44:16 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 14:44:16 volumio volumio[9350]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 28 14:44:16 volumio volumio[9350]: Error: socket hang up Jan 28 14:44:16 volumio volumio[9350]: at connResetException (node:internal/errors:720:14) Jan 28 14:44:16 volumio volumio[9350]: at Socket.socketOnEnd (node:_http_client:519:23) Jan 28 14:44:16 volumio volumio[9350]: at Socket.emit (node:events:526:35) Jan 28 14:44:16 volumio volumio[9350]: at endReadableNT (node:internal/streams/readable:1376:12) Jan 28 14:44:16 volumio volumio[9350]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Jan 28 14:44:16 volumio volumio[9350]: code: 'ECONNRESET', Jan 28 14:44:16 volumio volumio[9350]: response: undefined Jan 28 14:44:16 volumio volumio[9350]: } Jan 28 14:44:16 volumio volumio[9350]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 28 14:44:16 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 14:44:16 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 14:44:16 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 14:44:17 volumio sudo[9741]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-01-28 14:43' Jan 28 14:44:17 volumio sudo[9741]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 14:44:17 volumio sudo[9741]: pam_unix(sudo:session): session closed for user root Jan 28 14:44:18 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 14:44:18 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 14:44:18 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 14:44:19 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 14. Jan 28 14:44:19 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 14:44:19 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 14:44:19 volumio go-librespot[9750]: go-librespot daemon starting... Jan 28 14:44:19 volumio go-librespot[9751]: time="2026-01-28T14:44:19+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 14:44:19 volumio go-librespot[9751]: time="2026-01-28T14:44:19+07:00" level=debug msg="app state loaded" Jan 28 14:44:19 volumio go-librespot[9751]: time="2026-01-28T14:44:19+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 14:44:19 volumio volumio-remote-updater[628]: [2026-01-28 14:44:19] [error] handle_read_frame error: asio.system:104 (Connection reset by peer) Jan 28 14:44:19 volumio volumio-remote-updater[628]: [2026-01-28 14:44:19] [disconnect] Disconnect close local:[1006,Connection reset by peer] remote:[1006] Jan 28 14:44:19 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Jan 28 14:44:19 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Jan 28 14:44:19 volumio systemd[1]: volumio.service: Consumed 58.854s CPU time. Jan 28 14:44:19 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 28 14:44:19 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Jan 28 14:44:19 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 10275. Jan 28 14:44:19 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 28 14:44:19 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Jan 28 14:44:19 volumio systemd[1]: volumio.service: Consumed 58.854s CPU time. Jan 28 14:44:19 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Jan 28 14:44:19 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Jan 28 14:44:19 volumio go-librespot[9751]: time="2026-01-28T14:44:19+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 14:44:19 volumio go-librespot[9751]: time="2026-01-28T14:44:19+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 14:44:19 volumio go-librespot[9751]: time="2026-01-28T14:44:19+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 14:44:19 volumio go-librespot[9751]: time="2026-01-28T14:44:19+07:00" level=info msg="zeroconf server listening on port 42787" Jan 28 14:44:20 volumio go-librespot[9751]: time="2026-01-28T14:44:20+07:00" level=debug msg="obtained new client token: AADk3dJgYEbXr9O+zy2Oq6iwtj+YKqFq4yZUZCuKqTUDxZajpsp//Al2qYNypJWhqVpwdDrfZZWu4DA0c08IgmWV55+laXBnzZ0nF8o09tC6S18lBmI2aFGA/NGIvArhsKCG1Ui92Y+JC2yxlhx2ZDmJdGvw0zcCLEORhWScyt3i6YbF85XHK8f+MhaEf98G/gGBjQuFiynbrCj4S1JqZlCFV9wMESFBiqcNlXpaCk99datL3546O0Wv" Jan 28 14:44:20 volumio go-librespot[9751]: time="2026-01-28T14:44:20+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 14:44:20 volumio go-librespot[9751]: time="2026-01-28T14:44:20+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Jan 28 14:44:20 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 14:44:20 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 14:44:20 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 14:44:20 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 14:44:20 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 14:44:22 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 14:44:22 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 14:44:22 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 14:44:23 volumio volumio[9766]: info: ------------------------------------------- Jan 28 14:44:23 volumio volumio[9766]: info: ----- Volumio3 ---- Jan 28 14:44:23 volumio volumio[9766]: info: ------------------------------------------- Jan 28 14:44:23 volumio volumio[9766]: info: ----- System startup ---- Jan 28 14:44:23 volumio volumio[9766]: info: ------------------------------------------- Jan 28 14:44:23 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 15. Jan 28 14:44:23 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 14:44:23 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 14:44:23 volumio go-librespot[9788]: go-librespot daemon starting... Jan 28 14:44:23 volumio go-librespot[9789]: time="2026-01-28T14:44:23+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 14:44:23 volumio go-librespot[9789]: time="2026-01-28T14:44:23+07:00" level=debug msg="app state loaded" Jan 28 14:44:23 volumio go-librespot[9789]: time="2026-01-28T14:44:23+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 14:44:24 volumio go-librespot[9789]: time="2026-01-28T14:44:24+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 14:44:24 volumio go-librespot[9789]: time="2026-01-28T14:44:24+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 28 14:44:24 volumio go-librespot[9789]: time="2026-01-28T14:44:24+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 28 14:44:24 volumio go-librespot[9789]: time="2026-01-28T14:44:24+07:00" level=info msg="zeroconf server listening on port 44905" Jan 28 14:44:24 volumio volumio-remote-updater[628]: [2026-01-28 14:44:24] [connect] Successful connection Jan 28 14:44:24 volumio volumio[9766]: info: MYVOLUMIO Environment detected Jan 28 14:44:24 volumio go-librespot[9789]: time="2026-01-28T14:44:24+07:00" level=debug msg="obtained new client token: AAALdjX0Hg+CZtEbdB1WnLQd/X6tXpQcKF0l6sjF9WrgubrUwC8H1hjoNGY+eAw+m+ragQf6pG56vDpTksJ+6MJ7z48Fnl+QVeYuMg5PYaatBDDWbA1fKeTLtjO1nBLIEpkcPyMn7mNgsgWtPf3KIRrhm2JuOvnnpJL3SChvxKPMDbfsPnYOvVz5P4vjwJLmVaCRrk9+h3BYvga+8QMU3eW/J0ym04KELe5Hy9Z5hkM7wSaK0gqsKhlJCr0=" Jan 28 14:44:24 volumio go-librespot[9789]: time="2026-01-28T14:44:24+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 14:44:24 volumio volumio[9766]: info: Plugin folders cleanup Jan 28 14:44:24 volumio volumio[9766]: info: Scanning into folder /volumio/app/plugins/ Jan 28 14:44:24 volumio volumio[9766]: info: Scanning category audio_interface Jan 28 14:44:24 volumio volumio[9766]: info: Scanning category miscellanea Jan 28 14:44:24 volumio volumio[9766]: info: Scanning category music_service Jan 28 14:44:24 volumio volumio[9766]: info: Scanning category plugins.json Jan 28 14:44:24 volumio volumio[9766]: info: Scanning category system_controller Jan 28 14:44:24 volumio volumio[9766]: info: Scanning category user_interface Jan 28 14:44:24 volumio volumio[9766]: info: Scanning into folder /data/plugins/ Jan 28 14:44:24 volumio volumio[9766]: info: Scanning category music_service Jan 28 14:44:24 volumio volumio[9766]: info: Plugin folders cleanup completed Jan 28 14:44:24 volumio volumio[9766]: info: ------------------------------------------- Jan 28 14:44:24 volumio volumio[9766]: info: ----- Core plugins startup ---- Jan 28 14:44:24 volumio volumio[9766]: info: ------------------------------------------- Jan 28 14:44:24 volumio volumio[9766]: info: Loading plugins from folder /volumio/app/plugins/ Jan 28 14:44:24 volumio volumio[9766]: info: Adding plugin upnp to MyMusic Plugins Jan 28 14:44:24 volumio go-librespot[9789]: time="2026-01-28T14:44:24+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Jan 28 14:44:24 volumio volumio[9766]: info: Adding plugin airplay_emulation to MyMusic Plugins Jan 28 14:44:24 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 14:44:24 volumio volumio[9766]: info: Adding plugin upnp_browser to MyMusic Plugins Jan 28 14:44:24 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 14:44:24 volumio volumio[9766]: info: Loading plugins from folder /data/plugins/ Jan 28 14:44:24 volumio volumio[9766]: info: Loading plugin "system"... Jan 28 14:44:24 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 14:44:24 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 14:44:24 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 14:44:24 volumio volumio[9766]: info: Loading plugin "appearance"... Jan 28 14:44:26 volumio volumio[9766]: info: Loading plugin "network"... Jan 28 14:44:26 volumio volumio[9766]: info: Refreshing Cached IP Addresses Jan 28 14:44:26 volumio sudo[9803]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 28 14:44:26 volumio sudo[9803]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 14:44:26 volumio sudo[9805]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 28 14:44:26 volumio sudo[9805]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 14:44:26 volumio sudo[9803]: pam_unix(sudo:session): session closed for user root Jan 28 14:44:26 volumio sudo[9805]: pam_unix(sudo:session): session closed for user root Jan 28 14:44:26 volumio volumio[9766]: info: Loading plugin "services"... Jan 28 14:44:26 volumio volumio[9766]: info: Loading plugin "alsa_controller"... Jan 28 14:44:26 volumio sudo[9814]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Jan 28 14:44:26 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 14:44:26 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 14:44:26 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 14:44:26 volumio sudo[9814]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 14:44:27 volumio volumio[9766]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 28 14:44:27 volumio volumio[9766]: info: Loading plugin "wizard"... Jan 28 14:44:27 volumio volumio[9766]: info: Loading plugin "networkfs"... Jan 28 14:44:27 volumio volumio[9766]: info: Starting Udev Watcher for removable devices Jan 28 14:44:27 volumio volumio[9766]: info: Ignoring mount for partition: boot Jan 28 14:44:27 volumio volumio[9766]: info: Ignoring mount for partition: volumio Jan 28 14:44:27 volumio volumio[9766]: info: Ignoring mount for partition: volumio_data Jan 28 14:44:27 volumio volumio[9766]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 28 14:44:27 volumio volumio[9766]: info: Loading plugin "volumio_command_line_client"... Jan 28 14:44:27 volumio volumio[9766]: info: Loading plugin "upnp"... Jan 28 14:44:27 volumio volumio[9766]: info: [1769586267157] Starting Upmpd Daemon Jan 28 14:44:27 volumio volumio[9766]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 28 14:44:27 volumio volumio[9766]: info: Loading plugin "my_music"... Jan 28 14:44:27 volumio volumio[9766]: info: Loading plugin "mpd"... Jan 28 14:44:27 volumio volumio[9766]: info: Loading plugin "upnp_browser"... Jan 28 14:44:27 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 16. Jan 28 14:44:27 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 14:44:28 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 14:44:28 volumio go-librespot[9836]: go-librespot daemon starting... Jan 28 14:44:28 volumio go-librespot[9837]: time="2026-01-28T14:44:28+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 14:44:28 volumio go-librespot[9837]: time="2026-01-28T14:44:28+07:00" level=debug msg="app state loaded" Jan 28 14:44:28 volumio go-librespot[9837]: time="2026-01-28T14:44:28+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 14:44:28 volumio go-librespot[9837]: time="2026-01-28T14:44:28+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 14:44:28 volumio go-librespot[9837]: time="2026-01-28T14:44:28+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 28 14:44:28 volumio go-librespot[9837]: time="2026-01-28T14:44:28+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 28 14:44:28 volumio go-librespot[9837]: time="2026-01-28T14:44:28+07:00" level=info msg="zeroconf server listening on port 41079" Jan 28 14:44:28 volumio go-librespot[9837]: time="2026-01-28T14:44:28+07:00" level=debug msg="obtained new client token: AACB2mNFwZPd9Itjs1nH3l4L08BYA8b/VKf/b4p2SLem56pEN9z/P++dGH7oLp56PbVO+oqh0MXt4fSWTu3OwF7cLaNQTAT0JHWBtp5M/coAVadICjO4vVp9msaieOdSPTZKlVqAARibnO2wgBiSMDPikKbIejKNHgM3EmbiO+0Oj6jY3zG3QdGYR9DJYnn55ufJpDOeVfVdWw8bC4o8uPp+RY7vfDMO9a4JFw3ettR2XehKnxunsDeAtEo=" Jan 28 14:44:28 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 14:44:28 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 14:44:28 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 14:44:28 volumio go-librespot[9837]: time="2026-01-28T14:44:28+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 14:44:28 volumio go-librespot[9837]: time="2026-01-28T14:44:28+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Jan 28 14:44:28 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 14:44:28 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 14:44:29 volumio sudo[9814]: pam_unix(sudo:session): session closed for user root Jan 28 14:44:30 volumio volumio[9766]: info: Starting UPNP Browser Jan 28 14:44:30 volumio volumio[9766]: info: Loading plugin "alarm-clock"... Jan 28 14:44:30 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 14:44:30 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 14:44:30 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 14:44:31 volumio volumio[9766]: info: Loading plugin "airplay_emulation"... Jan 28 14:44:31 volumio volumio[9766]: info: Starting Shairport Sync Jan 28 14:44:31 volumio volumio[9766]: info: Loading plugin "last_100"... Jan 28 14:44:31 volumio volumio[9766]: info: Loading plugin "webradio"... Jan 28 14:44:31 volumio volumio[9766]: info: Loading plugin "i2s_dacs"... Jan 28 14:44:31 volumio volumio[9766]: info: Loading plugin "volumiodiscovery"... Jan 28 14:44:31 volumio volumio[9766]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 28 14:44:31 volumio volumio[9766]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 14:44:31 volumio node[9766]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 28 14:44:31 volumio volumio[9766]: *** WARNING *** For more information see Jan 28 14:44:31 volumio volumio[9766]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 28 14:44:31 volumio volumio[9766]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 14:44:31 volumio volumio[9766]: *** WARNING *** For more information see Jan 28 14:44:31 volumio node[9766]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 14:44:31 volumio node[9766]: *** WARNING *** For more information see Jan 28 14:44:31 volumio node[9766]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 28 14:44:31 volumio node[9766]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 14:44:31 volumio node[9766]: *** WARNING *** For more information see Jan 28 14:44:31 volumio volumio[9766]: info: Applying required configuration parameters for plugin volumiodiscovery Jan 28 14:44:31 volumio volumio[9766]: info: Discovery: Started advertising with name: Volumio Jan 28 14:44:31 volumio volumio[9766]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 28 14:44:31 volumio volumio[9766]: info: Loading plugin "spop"... Jan 28 14:44:32 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 17. Jan 28 14:44:32 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 14:44:32 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 14:44:32 volumio go-librespot[9846]: go-librespot daemon starting... Jan 28 14:44:32 volumio go-librespot[9847]: time="2026-01-28T14:44:32+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 14:44:32 volumio go-librespot[9847]: time="2026-01-28T14:44:32+07:00" level=debug msg="app state loaded" Jan 28 14:44:32 volumio go-librespot[9847]: time="2026-01-28T14:44:32+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 14:44:32 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 14:44:32 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 14:44:32 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 14:44:32 volumio go-librespot[9847]: time="2026-01-28T14:44:32+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 14:44:32 volumio go-librespot[9847]: time="2026-01-28T14:44:32+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 14:44:32 volumio go-librespot[9847]: time="2026-01-28T14:44:32+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 14:44:32 volumio go-librespot[9847]: time="2026-01-28T14:44:32+07:00" level=info msg="zeroconf server listening on port 42297" Jan 28 14:44:33 volumio go-librespot[9847]: time="2026-01-28T14:44:33+07:00" level=debug msg="obtained new client token: AAAap81M1oJpIqwXhdZJuzlWvK9wsGL0Ku6Km9ZRXrWqZbao7qQOx8qPfAmpc55TrvqOD3aPC2VV9glKcFWco075ujOkXJircjncOb2IknffMXl+kpZFcFW1K7ru+msI7NxCWpXngP1quklIs7hfoOntAqXmiHLS1oC6BEdgln15Om88XjiwyqI1r4/E010841yO5xRUdXcVhGcI33Jae6vPt2SXSpXW+Obh8QwMzr6ymXxo7QYlx8zN" Jan 28 14:44:33 volumio go-librespot[9847]: time="2026-01-28T14:44:33+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 14:44:33 volumio go-librespot[9847]: time="2026-01-28T14:44:33+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Jan 28 14:44:33 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 14:44:33 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 14:44:33 volumio volumio[9766]: info: Loading plugin "ytcr"... Jan 28 14:44:34 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 14:44:34 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 14:44:34 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 14:44:36 volumio volumio[9766]: info: Loading plugin "ytmusic"... Jan 28 14:44:36 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 18. Jan 28 14:44:36 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 14:44:36 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 14:44:36 volumio go-librespot[9857]: go-librespot daemon starting... Jan 28 14:44:36 volumio go-librespot[9858]: time="2026-01-28T14:44:36+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 14:44:36 volumio go-librespot[9858]: time="2026-01-28T14:44:36+07:00" level=debug msg="app state loaded" Jan 28 14:44:36 volumio go-librespot[9858]: time="2026-01-28T14:44:36+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 14:44:36 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 14:44:36 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 14:44:36 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 14:44:36 volumio volumio-remote-updater[628]: [2026-01-28 14:44:36] [connect] Successful connection Jan 28 14:44:37 volumio go-librespot[9858]: time="2026-01-28T14:44:37+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 28 14:44:37 volumio go-librespot[9858]: time="2026-01-28T14:44:37+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Jan 28 14:44:37 volumio go-librespot[9858]: time="2026-01-28T14:44:37+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Jan 28 14:44:37 volumio go-librespot[9858]: time="2026-01-28T14:44:37+07:00" level=info msg="zeroconf server listening on port 43661" Jan 28 14:44:37 volumio volumio[9766]: info: Loading plugin "outputs"... Jan 28 14:44:37 volumio volumio[9766]: info: Loading plugin "albumart"... Jan 28 14:44:37 volumio volumio[9766]: info: Plugin example_plugin is not enabled Jan 28 14:44:37 volumio volumio[9766]: info: Loading plugin "inputs"... Jan 28 14:44:37 volumio volumio[9766]: info: Loading plugin "updater_comm"... Jan 28 14:44:37 volumio go-librespot[9858]: time="2026-01-28T14:44:37+07:00" level=debug msg="obtained new client token: AADX8kuI/30fFZ6si2VC1cdfcPlWw0Npl+HLp3dGY9gw1h2V9uzASveYIb77g3Ah+JotesxbPpu8RfEtgILxgrrJJDNEZY5fdbqThJ+8jRCGVKsmYQrQgLMrGGcM16ZaDJuD9cCkBzirLBm7wvxeQ+kQIRBwtE1R3ZXjfHN+UdsrnXohyGbOU+J8P653S38sJhKfDFV16t8lNSPUD3l9wAaOZ0ZeNspAGjSpr6dg1WoWuOiUOz/+cerxKAM=" Jan 28 14:44:37 volumio volumio[9766]: info: Plugin mpdemulation is not enabled Jan 28 14:44:37 volumio volumio[9766]: info: Loading plugin "rest_api"... Jan 28 14:44:37 volumio volumio[9766]: info: Loading plugin "websocket"... Jan 28 14:44:37 volumio volumio[9766]: info: Starting Socket.io Server version 1.7.4 Jan 28 14:44:37 volumio volumio[9766]: info: Loading plugin "RoonBridge"... Jan 28 14:44:37 volumio go-librespot[9858]: time="2026-01-28T14:44:37+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 14:44:37 volumio go-librespot[9858]: time="2026-01-28T14:44:37+07:00" level=debug msg="completed keyexchange" Jan 28 14:44:37 volumio go-librespot[9858]: time="2026-01-28T14:44:37+07:00" level=debug msg="completed challenge" Jan 28 14:44:37 volumio go-librespot[9858]: time="2026-01-28T14:44:37+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 14:44:37 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 14:44:37 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 14:44:38 volumio volumio[9766]: info: Applying required configuration parameters for plugin RoonBridge Jan 28 14:44:38 volumio volumio[9766]: info: Loading i18n strings for locale en Jan 28 14:44:38 volumio volumio[9766]: Updating browse sources language Jan 28 14:44:38 volumio volumio[9766]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 14:44:38 volumio volumio[9880]: Forking 3 albumart workers Jan 28 14:44:38 volumio volumio[9766]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 28 14:44:38 volumio volumio[9766]: info: CoreCommandRouter::initPlayerControls Jan 28 14:44:38 volumio volumio[9766]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 14:44:38 volumio volumio[9766]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 14:44:38 volumio volumio[9766]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 14:44:38 volumio volumio[9766]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 14:44:38 volumio volumio[9766]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 14:44:38 volumio volumio[9766]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 14:44:38 volumio volumio[9766]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 14:44:38 volumio volumio[9766]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 14:44:38 volumio volumio[9766]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 28 14:44:38 volumio volumio[9766]: Express server listening on port 3000 Jan 28 14:44:38 volumio volumio[9766]: [Metrics] WebUI: 16s 194.18ms Jan 28 14:44:38 volumio volumio[9766]: info: CoreStateMachine::resetVolumioState Jan 28 14:44:38 volumio volumio[9766]: info: CoreStateMachine::getcurrentVolume Jan 28 14:44:38 volumio volumio[9766]: info: CoreCommandRouter::volumioRetrievevolume Jan 28 14:44:38 volumio sudo[9923]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 28 14:44:38 volumio sudo[9923]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 14:44:38 volumio volumio[9766]: info: Volumio Network Manager: Network status updated: 1 Jan 28 14:44:38 volumio sudo[9925]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 28 14:44:38 volumio sudo[9923]: pam_unix(sudo:session): session closed for user root Jan 28 14:44:38 volumio sudo[9925]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 14:44:38 volumio sudo[9925]: pam_unix(sudo:session): session closed for user root Jan 28 14:44:38 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 14:44:38 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 14:44:38 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 14:44:39 volumio volumio[9766]: info: VolumeController:: Volume=100 Mute =false Jan 28 14:44:39 volumio volumio[9766]: info: CoreStateMachine::pushState Jan 28 14:44:39 volumio volumio[9766]: info: CorePlayQueue::getTrack 0 Jan 28 14:44:39 volumio volumio[9766]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 28 14:44:39 volumio volumio[9766]: info: CoreCommandRouter::volumioPushState Jan 28 14:44:39 volumio volumio[9766]: info: CoreStateMachine::updateTrackBlock Jan 28 14:44:39 volumio volumio[9766]: info: CorePlayQueue::getTrackBlock Jan 28 14:44:39 volumio volumio[9766]: info: CoreCommandRouter::volumioRetrievevolume Jan 28 14:44:39 volumio volumio-remote-updater[628]: [2026-01-28 14:44:39] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1769586276 101 Jan 28 14:44:39 volumio volumio[9766]: 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 14:44:39 volumio volumio[9766]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 14:44:39 volumio volumio[9766]: info: Reloading queue from file Jan 28 14:44:39 volumio volumio[9766]: info: CoreStateMachine::setRepeat null single undefined Jan 28 14:44:39 volumio volumio[9766]: info: CoreStateMachine::pushState Jan 28 14:44:39 volumio volumio[9766]: info: CorePlayQueue::getTrack 0 Jan 28 14:44:39 volumio volumio[9766]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 28 14:44:39 volumio volumio[9766]: info: CoreCommandRouter::volumioPushState Jan 28 14:44:39 volumio volumio[9766]: info: CoreStateMachine::setRandom null Jan 28 14:44:39 volumio volumio[9766]: info: CoreStateMachine::pushState Jan 28 14:44:39 volumio volumio[9766]: info: CorePlayQueue::getTrack 0 Jan 28 14:44:39 volumio volumio[9766]: info: CoreCommandRouter::volumioPushState Jan 28 14:44:39 volumio volumio[9766]: info: Setting Device type: Raspberry PI Jan 28 14:44:39 volumio volumio[9766]: info: Completed loading Core Plugins Jan 28 14:44:39 volumio volumio[9766]: info: Preparing to generate the ALSA configuration file Jan 28 14:44:39 volumio volumio[9766]: info: VolumeController:: Volume=100 Mute =false Jan 28 14:44:39 volumio volumio[9766]: info: CoreStateMachine::pushState Jan 28 14:44:39 volumio volumio[9766]: info: CorePlayQueue::getTrack 0 Jan 28 14:44:39 volumio volumio[9766]: info: CoreCommandRouter::volumioPushState Jan 28 14:44:39 volumio volumio[9766]: info: Asound.conf file unchanged, so no further update is needed Jan 28 14:44:39 volumio volumio[9766]: info: Output device has changed, restarting MPD Jan 28 14:44:39 volumio sudo[9941]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Jan 28 14:44:39 volumio sudo[9941]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 14:44:39 volumio volumio[9766]: info: Output device has changed, restarting Shairport Sync Jan 28 14:44:39 volumio volumio[9766]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 14:44:39 volumio volumio[9766]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 14:44:39 volumio sudo[9944]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 28 14:44:39 volumio sudo[9944]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 14:44:39 volumio sudo[9946]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 28 14:44:39 volumio sudo[9946]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 14:44:39 volumio sudo[9944]: pam_unix(sudo:session): session closed for user root Jan 28 14:44:39 volumio sudo[9941]: pam_unix(sudo:session): session closed for user root Jan 28 14:44:39 volumio volumio[9766]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 28 14:44:39 volumio volumio[9766]: info: ___________ START PLUGINS ___________ Jan 28 14:44:39 volumio volumio[9766]: info: ControllerMpd::onStart: Initializing MPD Jan 28 14:44:39 volumio volumio[9766]: info: Creating MPD Configuration file Jan 28 14:44:39 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Jan 28 14:44:39 volumio sudo[9954]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 28 14:44:39 volumio sudo[9954]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 14:44:39 volumio sudo[9954]: pam_unix(sudo:session): session closed for user root Jan 28 14:44:39 volumio volumio[9766]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 28 14:44:39 volumio volumio[9766]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 14:44:39 volumio volumio[9766]: info: [1769586279980] CoreMusicLibrary::Adding element Media Servers Jan 28 14:44:39 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 28 14:44:39 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 28 14:44:40 volumio volumio[9766]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 14:44:39 volumio systemd[1]: mpd.service: Consumed 7.453s CPU time. Jan 28 14:44:40 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 28 14:44:40 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 28 14:44:40 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 28 14:44:40 volumio sudo[9957]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 28 14:44:40 volumio volumio[9766]: info: UPNP Browser: Client initialized successfully Jan 28 14:44:40 volumio sudo[9957]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 14:44:40 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 28 14:44:40 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 28 14:44:40 volumio volumio[9766]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 14:44:40 volumio volumio[9766]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 14:44:40 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 28 14:44:40 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 28 14:44:40 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 28 14:44:40 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 28 14:44:40 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 28 14:44:40 volumio volumio[9766]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 28 14:44:40 volumio volumio[9766]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 14:44:40 volumio volumio[9766]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 14:44:40 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 28 14:44:40 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 28 14:44:40 volumio volumio[9766]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 28 14:44:40 volumio volumio[9766]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 14:44:40 volumio volumio[9766]: info: [1769586280347] CoreMusicLibrary::Adding element Last_100 Jan 28 14:44:40 volumio volumio[9766]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 14:44:40 volumio volumio[9766]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 14:44:40 volumio volumio[9766]: info: [1769586280371] CoreMusicLibrary::Adding element Webradio Jan 28 14:44:40 volumio volumio[9766]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 14:44:40 volumio volumio[9766]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 28 14:44:40 volumio volumio[9766]: info: Initializing BBC Radios Jan 28 14:44:40 volumio volumio[9766]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 28 14:44:40 volumio volumio[9766]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 14:44:40 volumio volumio[9766]: info: Creating Spotify config file Jan 28 14:44:40 volumio volumio[9766]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 14:44:40 volumio sudo[9970]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 28 14:44:40 volumio sudo[9970]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jan 28 14:44:40 volumio sudo[9970]: pam_unix(sudo:session): session closed for user root Jan 28 14:44:40 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 14:44:40 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 14:44:40 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 14:44:40 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 19. Jan 28 14:44:40 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 14:44:40 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 14:44:41 volumio go-librespot[9986]: go-librespot daemon starting... Jan 28 14:44:41 volumio go-librespot[9987]: time="2026-01-28T14:44:41+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 14:44:41 volumio go-librespot[9987]: time="2026-01-28T14:44:41+07:00" level=info msg="zeroconf server listening on port 39163" Jan 28 14:44:41 volumio volumio[9893]: Starting albumart workers Jan 28 14:44:41 volumio volumio[9892]: Starting albumart workers Jan 28 14:44:41 volumio volumio[9891]: Starting albumart workers Jan 28 14:44:42 volumio volumio[9766]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 14:44:42 volumio volumio[9766]: info: [1769586282110] CoreMusicLibrary::Adding element YouTube Music Jan 28 14:44:42 volumio volumio[9766]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 14:44:42 volumio volumio[9766]: Cannot find translation for source YouTube Music Jan 28 14:44:42 volumio volumio[9766]: info: Volumio Calling Home Jan 28 14:44:42 volumio sudo[9995]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Jan 28 14:44:42 volumio sudo[9995]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 14:44:42 volumio sudo[9995]: pam_unix(sudo:session): session closed for user root Jan 28 14:44:42 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 14:44:42 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 14:44:42 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 14:44:43 volumio volumio[9766]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Jan 28 14:44:43 volumio volumio[9766]: info: Discovery: Found device Volumio Jan 28 14:44:43 volumio volumio[9766]: info: CoreCommandRouter::volumioGetState Jan 28 14:44:43 volumio volumio[9766]: info: CorePlayQueue::getTrack 0 Jan 28 14:44:43 volumio volumio[9766]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Jan 28 14:44:43 volumio volumio[9766]: info: Discovery: Found device Volumio Jan 28 14:44:43 volumio volumio[9766]: info: CoreCommandRouter::volumioGetState Jan 28 14:44:43 volumio volumio[9766]: info: CorePlayQueue::getTrack 0 Jan 28 14:44:43 volumio volumio[9766]: info: MPD Permissions set Jan 28 14:44:43 volumio volumio[9766]: info: MPD Permissions set Jan 28 14:44:43 volumio volumio[9766]: info: Upmpdcli Daemon Started Jan 28 14:44:43 volumio volumio[9766]: info: Spotify config file written Jan 28 14:44:43 volumio volumio[9766]: 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 14:44:43 volumio volumio[9766]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 14:44:43 volumio volumio[9766]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 14:44:43 volumio volumio[9766]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 14:44:43 volumio volumio[9766]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 14:44:43 volumio volumio[9766]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 14:44:43 volumio volumio[9766]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 14:44:43 volumio volumio[9766]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 14:44:43 volumio volumio[9766]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 14:44:43 volumio sudo[10001]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jan 28 14:44:43 volumio sudo[10001]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 14:44:43 volumio volumio[9766]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 14:44:43 volumio volumio[9766]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 14:44:43 volumio volumio[9766]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 14:44:43 volumio volumio[9766]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 14:44:43 volumio volumio[9766]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 14:44:43 volumio volumio[9766]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 14:44:43 volumio volumio[9766]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 14:44:43 volumio volumio[9766]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 14:44:43 volumio volumio[9766]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 14:44:43 volumio volumio[9766]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 14:44:43 volumio volumio[9766]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 14:44:43 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Jan 28 14:44:43 volumio volumio[9766]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 14:44:43 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Jan 28 14:44:43 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 14:44:43 volumio volumio[9766]: info: No need to fix Spotify hosts Jan 28 14:44:43 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 14:44:43 volumio go-librespot[10013]: go-librespot daemon starting... Jan 28 14:44:43 volumio sudo[10001]: pam_unix(sudo:session): session closed for user root Jan 28 14:44:43 volumio go-librespot[10014]: time="2026-01-28T14:44:43+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 14:44:43 volumio go-librespot[10014]: time="2026-01-28T14:44:43+07:00" level=debug msg="app state loaded" Jan 28 14:44:43 volumio go-librespot[10014]: time="2026-01-28T14:44:43+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 14:44:44 volumio go-librespot[10014]: time="2026-01-28T14:44: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-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 14:44:44 volumio go-librespot[10014]: time="2026-01-28T14:44:44+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 14:44:44 volumio go-librespot[10014]: time="2026-01-28T14:44:44+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 14:44:44 volumio go-librespot[10014]: time="2026-01-28T14:44:44+07:00" level=info msg="zeroconf server listening on port 36377" Jan 28 14:44:44 volumio go-librespot[10014]: time="2026-01-28T14:44:44+07:00" level=debug msg="obtained new client token: AADXw84grm27yYEHJoCuOpSKzNrhb/xGo+awokF+14jnfBaAOUEysQ4qkwbjRwvvEiINMOVNidrV1NmJsuVjCDbuksquDgZ7pD0RV1JTpt9NsjLe/nEApB22mnkMjonfH1aqto/XjxM4/qgsDr3T3lZGn+JACAUBslRt7GrJacO1WDqVsxx0FXWEwpfE45zOlOA31KmLkCoEOhCTuDjcYZROydHNp7UguaZqeaB/rAZDmv/v35sG1ystoPI=" Jan 28 14:44:44 volumio volumio[9766]: info: Volumio called home Jan 28 14:44:44 volumio volumio[9766]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 28 14:44:44 volumio volumio[9766]: SPOTIFY: BQBFPkNxdPy8fMAhhgNFj1NfzprvLr87d7fz9CTFyQ9uZiWA-9Yr3FFPiU5XcEzmJC2FYHKIro8KpPUOTakgBTB90zszUu0v1U0dXJOUC6Z2TJXALcbX0j8eNb2H7qMRgMZFzLOyv3DNMyx5uUhJU-kxeGRJz1KLbHC8ny8WDtZlrAaONknpiFfYBSAQPRcu6W5GoT0hONr8FQWGhZzM4VajWfztrVz6QVc5VztGhHT5NpRM5GrGWCbyNPYYFZV66ZyGhwSflep1s7B8xfNe8nK84r64LaQ-oCL8rFSrmxVJrR4gapqrgr8I Jan 28 14:44:44 volumio volumio[9766]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 28 14:44:44 volumio volumio[9766]: info: New Spotify access token = BQBFPkNxdPy8fMAhhgNFj1NfzprvLr87d7fz9CTFyQ9uZiWA-9Yr3FFPiU5XcEzmJC2FYHKIro8KpPUOTakgBTB90zszUu0v1U0dXJOUC6Z2TJXALcbX0j8eNb2H7qMRgMZFzLOyv3DNMyx5uUhJU-kxeGRJz1KLbHC8ny8WDtZlrAaONknpiFfYBSAQPRcu6W5GoT0hONr8FQWGhZzM4VajWfztrVz6QVc5VztGhHT5NpRM5GrGWCbyNPYYFZV66ZyGhwSflep1s7B8xfNe8nK84r64LaQ-oCL8rFSrmxVJrR4gapqrgr8I Jan 28 14:44:44 volumio volumio[9766]: info: Spotify credentials grant success - running version from March 24, 2019 Jan 28 14:44:44 volumio go-librespot[10014]: time="2026-01-28T14:44:44+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 14:44:44 volumio volumio[9766]: info: Starting Shairport Sync Jan 28 14:44:44 volumio volumio[9766]: info: Starting Shairport Sync Jan 28 14:44:44 volumio volumio[9766]: info: Starting Shairport Sync Jan 28 14:44:44 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 14:44:44 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 14:44:44 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 14:44:44 volumio go-librespot[10014]: time="2026-01-28T14:44:44+07:00" level=debug msg="completed keyexchange" Jan 28 14:44:44 volumio go-librespot[10014]: time="2026-01-28T14:44:44+07:00" level=debug msg="completed challenge" Jan 28 14:44:44 volumio sudo[10040]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 28 14:44:44 volumio sudo[10040]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 14:44:44 volumio sudo[10042]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 28 14:44:44 volumio sudo[10042]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 14:44:44 volumio sudo[10044]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 28 14:44:44 volumio sudo[10044]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 14:44:45 volumio go-librespot[10014]: time="2026-01-28T14:44: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 14:44:45 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 14:44:45 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 14:44:45 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 28 14:44:45 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Jan 28 14:44:45 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 28 14:44:45 volumio systemd[1]: shairport-sync.service: Consumed 2.392s CPU time. Jan 28 14:44:45 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 28 14:44:45 volumio sudo[10042]: pam_unix(sudo:session): session closed for user root Jan 28 14:44:45 volumio sudo[10044]: pam_unix(sudo:session): session closed for user root Jan 28 14:44:45 volumio sudo[10040]: pam_unix(sudo:session): session closed for user root Jan 28 14:44:45 volumio volumio[9766]: info: CoreCommandRouter::volumioGetState Jan 28 14:44:45 volumio volumio[9766]: info: CorePlayQueue::getTrack 0 Jan 28 14:44:45 volumio volumio[9766]: info: Shairport-Sync Started Jan 28 14:44:45 volumio volumio[9766]: Error adding Membership: Error: addMembership EINVAL Jan 28 14:44:45 volumio volumio[9766]: info: Shairport-Sync Started Jan 28 14:44:45 volumio volumio[9766]: info: Shairport-Sync Started Jan 28 14:44:45 volumio volumio[9766]: 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 14:44:45 volumio volumio[9766]: info: Spotify Successfully logged in Jan 28 14:44:45 volumio volumio[9766]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 14:44:45 volumio volumio[9766]: info: [1769586285717] CoreMusicLibrary::Adding element Spotify Jan 28 14:44:45 volumio volumio[9766]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 14:44:45 volumio volumio[9766]: Cannot find translation for source YouTube Music Jan 28 14:44:45 volumio volumio[9766]: Cannot find translation for source Spotify Jan 28 14:44:46 volumio volumio[9766]: info: [yt-cast-receiver] DIAL server listening on port 8098 Jan 28 14:44:46 volumio volumio[9766]: info: CoreCommandRouter::volumioRetrievevolume Jan 28 14:44:46 volumio volumio[9766]: info: VolumeController:: Volume=100 Mute =false Jan 28 14:44:46 volumio volumio[9766]: info: CoreCommandRouter::volumioGetState Jan 28 14:44:46 volumio volumio[9766]: info: CorePlayQueue::getTrack 0 Jan 28 14:44:46 volumio volumio[9766]: info: CoreStateMachine::pushState Jan 28 14:44:46 volumio volumio[9766]: info: CorePlayQueue::getTrack 0 Jan 28 14:44:46 volumio volumio[9766]: info: CoreCommandRouter::volumioPushState Jan 28 14:44:46 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 14:44:46 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 14:44:46 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 14:44:47 volumio volumio[9766]: info: go-librespot daemon successfully initialized Jan 28 14:44:48 volumio mpd[9985]: 2026-01-28T14:44:48 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 28 14:44:48 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Jan 28 14:44:48 volumio systemd[1]: Started mpd.service - Music Player Daemon. Jan 28 14:44:48 volumio sudo[9957]: pam_unix(sudo:session): session closed for user root Jan 28 14:44:48 volumio sudo[9946]: pam_unix(sudo:session): session closed for user root Jan 28 14:44:48 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 14:44:48 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 14:44:48 volumio go-librespot[10084]: go-librespot daemon starting... Jan 28 14:44:48 volumio go-librespot[10087]: time="2026-01-28T14:44:48+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 14:44:48 volumio go-librespot[10087]: time="2026-01-28T14:44:48+07:00" level=debug msg="app state loaded" Jan 28 14:44:48 volumio go-librespot[10087]: time="2026-01-28T14:44:48+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 14:44:48 volumio volumio[9766]: error: MPD error: The expression evaluated to a falsy value: Jan 28 14:44:48 volumio volumio[9766]: assert.ok(self.idling) Jan 28 14:44:48 volumio volumio[9766]: error: The expression evaluated to a falsy value: Jan 28 14:44:48 volumio volumio[9766]: assert.ok(self.idling) Jan 28 14:44:48 volumio volumio[9766]: error: updateQueue error: null Jan 28 14:44:48 volumio volumio[9766]: info: MPD running with PID9985 Jan 28 14:44:48 volumio volumio[9766]: ,establishing connection Jan 28 14:44:48 volumio volumio[9766]: info: Completed starting Core Plugins Jan 28 14:44:48 volumio volumio[9766]: info: ------------------------------------------- Jan 28 14:44:48 volumio volumio[9766]: info: ----- MyVolumio plugins startup ---- Jan 28 14:44:48 volumio volumio[9766]: info: ------------------------------------------- Jan 28 14:44:48 volumio volumio[9766]: info: [MyVolumio PluginManager] Fetching plans data.... Jan 28 14:44:48 volumio volumio[9766]: error: updateQueue error: null Jan 28 14:44:48 volumio go-librespot[10087]: time="2026-01-28T14:44: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 14:44:48 volumio go-librespot[10087]: time="2026-01-28T14:44:48+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 14:44:48 volumio go-librespot[10087]: time="2026-01-28T14:44:48+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 14:44:48 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 14:44:48 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 14:44:48 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 14:44:48 volumio go-librespot[10087]: time="2026-01-28T14:44:48+07:00" level=info msg="zeroconf server listening on port 35757" Jan 28 14:44:49 volumio go-librespot[10087]: time="2026-01-28T14:44:49+07:00" level=debug msg="obtained new client token: AADjDpUq1PDy/HjeEK4ZTxqaztihsQ/VJmt4O8B6nKi8cLnHnougrALjfCQTJivNvCgMcRsvW3QIg/2cMfJuNlHOaje4pfhsce1fslWGDbjwrYlP2c3braKJbWBGipGBZwzvTQIYyeN0IibZOj+Jc3NOnV4xNUIFPRbE8XFmgomcadZmR/tNEx5sL97JPYSIpx5CV1oSih0o0iuRUPJxdo5G9Z23qz5DaJhUaHtS62+ivYR/yy7Oa/1H" Jan 28 14:44:49 volumio go-librespot[10087]: time="2026-01-28T14:44:49+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 14:44:49 volumio go-librespot[10087]: time="2026-01-28T14:44:49+07:00" level=debug msg="completed keyexchange" Jan 28 14:44:49 volumio go-librespot[10087]: time="2026-01-28T14:44:49+07:00" level=debug msg="completed challenge" Jan 28 14:44:49 volumio go-librespot[10087]: time="2026-01-28T14:44: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 14:44:49 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 14:44:49 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 14:44:50 volumio volumio[9766]: info: Initializing connection to go-librespot Websocket Jan 28 14:44:50 volumio volumio[9766]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 28 14:44:50 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 14:44:50 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 14:44:50 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 14:44:52 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Jan 28 14:44:52 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 14:44:52 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 14:44:52 volumio go-librespot[10094]: go-librespot daemon starting... Jan 28 14:44:52 volumio go-librespot[10095]: time="2026-01-28T14:44:52+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 14:44:52 volumio go-librespot[10095]: time="2026-01-28T14:44:52+07:00" level=debug msg="app state loaded" Jan 28 14:44:52 volumio go-librespot[10095]: time="2026-01-28T14:44:52+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 14:44:52 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 14:44:52 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 14:44:52 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 14:44:53 volumio go-librespot[10095]: time="2026-01-28T14:44: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 14:44:53 volumio go-librespot[10095]: time="2026-01-28T14:44:53+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 14:44:53 volumio go-librespot[10095]: time="2026-01-28T14:44:53+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 14:44:53 volumio go-librespot[10095]: time="2026-01-28T14:44:53+07:00" level=info msg="zeroconf server listening on port 34913" Jan 28 14:44:53 volumio volumio[9766]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Jan 28 14:44:53 volumio go-librespot[10095]: time="2026-01-28T14:44:53+07:00" level=debug msg="obtained new client token: AADrs+xPIOaDzWbq1qCkDqlpwWayQBoq+9bICnze2F7Lp8ShpOW12vXp/V3SgHXx75eJ+xUuyLctYFFtp1PwR7l1XsPEqHVzmXoJA3KAjngRNiSGhsR39w3106BN7R10CbtgGniCYbCxU2q2KGn5iCPpIDGmk3FRebaM2d8K05M6KcmWmjwD8kUSRjZ+xwTGSdyrUoyauiYVxdOZaHmtxhsAveOjgNyHtrGJzjeK2u/CwT7TPf5yygdJm/c=" Jan 28 14:44:53 volumio go-librespot[10095]: time="2026-01-28T14:44:53+07:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:4070, retrying with a different AP" error="dial tcp 104.199.241.202:4070: connect: connection refused" Jan 28 14:44:53 volumio go-librespot[10095]: time="2026-01-28T14:44:53+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Jan 28 14:44:53 volumio go-librespot[10095]: time="2026-01-28T14:44:53+07:00" level=debug msg="completed keyexchange" Jan 28 14:44:53 volumio go-librespot[10095]: time="2026-01-28T14:44:53+07:00" level=debug msg="completed challenge" Jan 28 14:44:53 volumio go-librespot[10095]: time="2026-01-28T14:44:53+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 14:44:53 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 14:44:53 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 14:44:53 volumio volumio[9766]: info: Initializing connection to go-librespot Websocket Jan 28 14:44:53 volumio volumio[9766]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 28 14:44:54 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 14:44:54 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 14:44:54 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 14:44:56 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Jan 28 14:44:56 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 14:44:56 volumio volumio[9766]: info: Initializing connection to go-librespot Websocket Jan 28 14:44:56 volumio volumio[9766]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 28 14:44:56 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 14:44:56 volumio go-librespot[10102]: go-librespot daemon starting... Jan 28 14:44:56 volumio go-librespot[10103]: time="2026-01-28T14:44:56+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 14:44:56 volumio go-librespot[10103]: time="2026-01-28T14:44:56+07:00" level=debug msg="app state loaded" Jan 28 14:44:56 volumio go-librespot[10103]: time="2026-01-28T14:44:56+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 14:44:56 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 14:44:56 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 14:44:56 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 14:44:57 volumio go-librespot[10103]: time="2026-01-28T14:44:57+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 28 14:44:57 volumio go-librespot[10103]: time="2026-01-28T14:44:57+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 14:44:57 volumio go-librespot[10103]: time="2026-01-28T14:44:57+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 14:44:57 volumio go-librespot[10103]: time="2026-01-28T14:44:57+07:00" level=info msg="zeroconf server listening on port 39197" Jan 28 14:44:57 volumio volumio[9766]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Jan 28 14:44:57 volumio volumio[9766]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Jan 28 14:44:57 volumio volumio[9766]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Jan 28 14:44:57 volumio volumio[9766]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Jan 28 14:44:57 volumio volumio[9766]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Jan 28 14:44:57 volumio volumio[9766]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Jan 28 14:44:57 volumio volumio[9766]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Jan 28 14:44:57 volumio volumio[9766]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Jan 28 14:44:57 volumio volumio[9766]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Jan 28 14:44:57 volumio volumio[9766]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Jan 28 14:44:57 volumio volumio[9766]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Jan 28 14:44:57 volumio volumio[9766]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Jan 28 14:44:57 volumio volumio[9766]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Jan 28 14:44:57 volumio volumio[9766]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Jan 28 14:44:57 volumio volumio[9766]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Jan 28 14:44:57 volumio volumio[9766]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Jan 28 14:44:57 volumio volumio[9766]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Jan 28 14:44:57 volumio volumio[9766]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Jan 28 14:44:57 volumio volumio[9766]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Jan 28 14:44:57 volumio volumio[9766]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Jan 28 14:44:57 volumio volumio[9766]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Jan 28 14:44:57 volumio volumio[9766]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Jan 28 14:44:57 volumio volumio[9766]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Jan 28 14:44:57 volumio volumio[9766]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Jan 28 14:44:57 volumio volumio[9766]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Jan 28 14:44:57 volumio volumio[9766]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Jan 28 14:44:57 volumio volumio[9766]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Jan 28 14:44:57 volumio volumio[9766]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Jan 28 14:44:57 volumio volumio[9766]: info: Adding plugin bluetooth to MyMusic Plugins Jan 28 14:44:57 volumio volumio[9766]: info: Adding plugin multiroom to MyMusic Plugins Jan 28 14:44:57 volumio volumio[9766]: info: Adding plugin metavolumio to MyMusic Plugins Jan 28 14:44:57 volumio volumio[9766]: info: Adding plugin cd_controller to MyMusic Plugins Jan 28 14:44:57 volumio volumio[9766]: info: Adding plugin qobuzconnect to MyMusic Plugins Jan 28 14:44:57 volumio volumio[9766]: info: Adding plugin smart_inputs to MyMusic Plugins Jan 28 14:44:57 volumio volumio[9766]: info: Adding plugin tidalconnect to MyMusic Plugins Jan 28 14:44:57 volumio volumio[9766]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Jan 28 14:44:57 volumio go-librespot[10103]: time="2026-01-28T14:44:57+07:00" level=debug msg="obtained new client token: AACgjLE42EVr4AJZwJ77mzGFRQiRewTKNUNOuZpHkq3rYYU9ziXwDhwxT3dL37GROnkCkxmI6xfRbeIznlEL2i2Vi8omPgW2ZcZv463eospdU+da/hJAQrCNnYHIXeg4POJKBZ90oajTqLNCqmHUo2NpsSGe7+IElOztnKQS0PEUBYOteP2/NZLZRHdl5wXqi8om7lAhxk4DdqNMDTuhpO3jX0n8xA2whEk87DGdx1y3k8zadKDI7lrsep8=" Jan 28 14:44:57 volumio go-librespot[10103]: time="2026-01-28T14:44:57+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 14:44:57 volumio go-librespot[10103]: time="2026-01-28T14:44:57+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Jan 28 14:44:57 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 14:44:57 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 14:44:58 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 14:44:58 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 14:44:58 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 14:44:59 volumio volumio[9766]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Jan 28 14:44:59 volumio volumio[9766]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Jan 28 14:44:59 volumio volumio[9766]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 14:44:59 volumio volumio[9766]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 14:44:59 volumio volumio[9766]: info: Starting MyVolumio Remote Streaming Endpoints Jan 28 14:44:59 volumio volumio[9766]: info: MyVolumio login type: Token Jan 28 14:44:59 volumio volumio[9766]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Jan 28 14:44:59 volumio volumio[9766]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Jan 28 14:45:00 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Jan 28 14:45:00 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 14:45:00 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 14:45:00 volumio go-librespot[10125]: go-librespot daemon starting... Jan 28 14:45:00 volumio go-librespot[10126]: time="2026-01-28T14:45:00+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 14:45:00 volumio go-librespot[10126]: time="2026-01-28T14:45:00+07:00" level=debug msg="app state loaded" Jan 28 14:45:00 volumio go-librespot[10126]: time="2026-01-28T14:45:00+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 14:45:00 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 14:45:00 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 14:45:00 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 14:45:01 volumio volumio[9766]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Jan 28 14:45:01 volumio volumio[9766]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Jan 28 14:45:01 volumio volumio[9766]: info: Streaming services startup Jan 28 14:45:01 volumio volumio[9766]: info: Starting Streaming Daemon Jan 28 14:45:01 volumio sudo[10133]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jan 28 14:45:01 volumio volumio[9766]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Jan 28 14:45:01 volumio sudo[10133]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 14:45:01 volumio sudo[10133]: pam_unix(sudo:session): session closed for user root Jan 28 14:45:01 volumio volumio[9766]: info: Initializing connection to go-librespot Websocket Jan 28 14:45:01 volumio volumio[9766]: error: Cannot start Volumio Streaming Daemon Jan 28 14:45:01 volumio volumio[9766]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Jan 28 14:45:01 volumio volumio[9766]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Jan 28 14:45:01 volumio go-librespot[10126]: time="2026-01-28T14:45:01+07:00" level=debug msg="new websocket client" Jan 28 14:45:01 volumio volumio[9766]: info: Connection to go-librespot Websocket established Jan 28 14:45:01 volumio go-librespot[10126]: time="2026-01-28T14:45: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 14:45:01 volumio go-librespot[10126]: time="2026-01-28T14:45: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 14:45:01 volumio go-librespot[10126]: time="2026-01-28T14:45: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 14:45:01 volumio go-librespot[10126]: time="2026-01-28T14:45:01+07:00" level=info msg="zeroconf server listening on port 37965" Jan 28 14:45:01 volumio go-librespot[10126]: time="2026-01-28T14:45:01+07:00" level=debug msg="obtained new client token: AABFAEdsZGqXhCOMf50YQL/4P+AFuDoSfzxyqM0Ip15wm5ZZ979ZWtyU4Fm4fOGV9VfJWS1GElRvxbJm5cJNMrE5tO2V8WUFF7AUjdpIsC8XcuRBPTKPUnH/01CIcuYtvpbymgiXaMr6CLA72XEu53Byxk+RwmQSTdUzxtSXUGsT3hhFvpyclmvs+BqAFxEXMEY/xrPybI14ZRT9kAkubQ7dSJ6+I3KnFtjz7dZFj93Mr06qkrGYVNkbcRI=" Jan 28 14:45:01 volumio go-librespot[10126]: time="2026-01-28T14:45:01+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 14:45:01 volumio go-librespot[10126]: time="2026-01-28T14:45:01+07:00" level=debug msg="completed keyexchange" Jan 28 14:45:01 volumio go-librespot[10126]: time="2026-01-28T14:45:01+07:00" level=debug msg="completed challenge" Jan 28 14:45:01 volumio go-librespot[10126]: time="2026-01-28T14:45: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 14:45:01 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 14:45:01 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 14:45:01 volumio volumio[9766]: info: Connection to go-librespot Websocket closed Jan 28 14:45:02 volumio volumio[9766]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Jan 28 14:45:02 volumio volumio[9766]: info: MyVolumio token set successfully Jan 28 14:45:02 volumio volumio[9766]: info: MYVOLUMIO: Adding device Jan 28 14:45:02 volumio volumio[9766]: info: MYVOLUMIO: Evaluating Server Jan 28 14:45:02 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 14:45:02 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 14:45:02 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 14:45:03 volumio volumio[9766]: info: MyVolumio status changed Jan 28 14:45:03 volumio volumio[9766]: info: Streaming services startup Jan 28 14:45:03 volumio volumio[9766]: info: Starting Streaming Daemon Jan 28 14:45:03 volumio volumio[9766]: info: Removing browser output: myVolumio user plan is not superstar Jan 28 14:45:03 volumio volumio[9766]: info: Removing audio output: Jan 28 14:45:03 volumio volumio[9766]: info: Stoppping Tunnel 1 Jan 28 14:45:03 volumio sudo[10163]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jan 28 14:45:03 volumio sudo[10163]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 14:45:03 volumio sudo[10163]: pam_unix(sudo:session): session closed for user root Jan 28 14:45:03 volumio volumio[9766]: error: Cannot start Volumio Streaming Daemon Jan 28 14:45:03 volumio volumio[9766]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Jan 28 14:45:03 volumio volumio[9766]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Jan 28 14:45:03 volumio sudo[10166]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Jan 28 14:45:03 volumio sudo[10166]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 14:45:03 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 14:45:03 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 14:45:03 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 14:45:03 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 14:45:03 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 14:45:03 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 14:45:03 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 14:45:03 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 14:45:03 volumio sudo[10166]: pam_unix(sudo:session): session closed for user root Jan 28 14:45:03 volumio volumio[9766]: info: Remote SSH Stopped Jan 28 14:45:03 volumio volumio[9766]: info: Setting Geolocation for MyVolumio to as1 Jan 28 14:45:03 volumio volumio[9766]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 14:45:03 volumio volumio[9766]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 14:45:03 volumio volumio[9766]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 14:45:04 volumio volumio[9766]: info: Getting Spotify volume Jan 28 14:45:04 volumio volumio[9766]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 28 14:45:04 volumio volumio[9766]: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 28 14:45:04 volumio volumio[9766]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Jan 28 14:45:04 volumio volumio[9766]: errno: -111, Jan 28 14:45:04 volumio volumio[9766]: code: 'ECONNREFUSED', Jan 28 14:45:04 volumio volumio[9766]: syscall: 'connect', Jan 28 14:45:04 volumio volumio[9766]: address: '127.0.0.1', Jan 28 14:45:04 volumio volumio[9766]: port: 9879, Jan 28 14:45:04 volumio volumio[9766]: response: undefined Jan 28 14:45:04 volumio volumio[9766]: } Jan 28 14:45:04 volumio volumio[9766]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 28 14:45:04 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 14:45:04 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 14:45:04 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 14:45:04 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Jan 28 14:45:04 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 14:45:05 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 14:45:05 volumio go-librespot[10180]: go-librespot daemon starting... Jan 28 14:45:05 volumio go-librespot[10181]: time="2026-01-28T14:45:05+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 14:45:05 volumio go-librespot[10181]: time="2026-01-28T14:45:05+07:00" level=debug msg="app state loaded" Jan 28 14:45:05 volumio go-librespot[10181]: time="2026-01-28T14:45:05+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 14:45:05 volumio go-librespot[10181]: time="2026-01-28T14:45:05+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 14:45:05 volumio go-librespot[10181]: time="2026-01-28T14:45:05+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 28 14:45:05 volumio go-librespot[10181]: time="2026-01-28T14:45:05+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 28 14:45:05 volumio go-librespot[10181]: time="2026-01-28T14:45:05+07:00" level=info msg="zeroconf server listening on port 34829" Jan 28 14:45:05 volumio sudo[10191]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-01-28 14:44' Jan 28 14:45:05 volumio sudo[10191]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 14:45:05 volumio go-librespot[10181]: time="2026-01-28T14:45:05+07:00" level=debug msg="obtained new client token: AADb8BdFfQW4eNBCtjyCz6eiB7NPYAHYCOfcgmDml/0ENHp4mdu1KQwx4ZaJqgYrC04GlmlOIrqMsNEScm1UraBrU+rgCHMCcgx+JDoNOAv6pqY5Xlo5U7ViYaJTSmDNFFU1VdHadEz5Hve5l/FGrZ5rsiFnlTyfdJRt79zHHs9abORepsX+pFt08pxsTxLeeLSQTDLEgrw1Mj87F4q5FpKCrPMwLUrogQ+oMlN6cHVh7QyLvcUOzuOKad4=" Jan 28 14:45:06 volumio go-librespot[10181]: time="2026-01-28T14:45:06+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 14:45:06 volumio go-librespot[10181]: time="2026-01-28T14:45:06+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Jan 28 14:45:06 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 14:45:06 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 14:45:06 volumio sudo[10191]: pam_unix(sudo:session): session closed for user root Jan 28 14:45:06 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 14:45:06 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 14:45:06 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 14:45:07 volumio volumio-remote-updater[628]: [2026-01-28 14:45:07] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Jan 28 14:45:07 volumio volumio-remote-updater[628]: [2026-01-28 14:45:07] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Jan 28 14:45:07 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Jan 28 14:45:07 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Jan 28 14:45:07 volumio systemd[1]: volumio.service: Consumed 1min 591ms CPU time. Jan 28 14:45:07 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 28 14:45:07 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Jan 28 14:45:07 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 10276. Jan 28 14:45:08 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 28 14:45:08 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Jan 28 14:45:08 volumio systemd[1]: volumio.service: Consumed 1min 591ms CPU time. Jan 28 14:45:08 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Jan 28 14:45:08 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Jan 28 14:45:08 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 14:45:08 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 14:45:08 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 14:45:09 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Jan 28 14:45:09 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 14:45:09 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 14:45:09 volumio go-librespot[10238]: go-librespot daemon starting... Jan 28 14:45:09 volumio go-librespot[10239]: time="2026-01-28T14:45:09+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 14:45:09 volumio go-librespot[10239]: time="2026-01-28T14:45:09+07:00" level=debug msg="app state loaded" Jan 28 14:45:09 volumio go-librespot[10239]: time="2026-01-28T14:45:09+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 14:45:09 volumio go-librespot[10239]: time="2026-01-28T14:45:09+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 14:45:09 volumio go-librespot[10239]: time="2026-01-28T14:45:09+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 14:45:09 volumio go-librespot[10239]: time="2026-01-28T14:45:09+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 14:45:09 volumio go-librespot[10239]: time="2026-01-28T14:45:09+07:00" level=info msg="zeroconf server listening on port 38211" Jan 28 14:45:10 volumio go-librespot[10239]: time="2026-01-28T14:45:10+07:00" level=debug msg="obtained new client token: AAC+zQquUsjgoG5C9cUGNvtUN0L95HfQpZ0NZdoGo2bB08Sg1rOqq89Lyx/ccrwDD4jV+GqzmgWHPuxDe/1BMjHi0eNqDVlvJklikkJZXWw4BXS6xD9lFZwva2xLbUL+8AFUER8+6ZMy7L2HiMkthm2DqckYHedbqUKGBH23YBVY3q6jGoVMrdjtLRPkn90vLJWy/B0tXlXOhIch7SnraV1uv6J6UtW908kZu0Mg+2RHHls9mETRlbnh" Jan 28 14:45:10 volumio go-librespot[10239]: time="2026-01-28T14:45:10+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 14:45:10 volumio go-librespot[10239]: time="2026-01-28T14:45:10+07:00" level=debug msg="completed keyexchange" Jan 28 14:45:10 volumio go-librespot[10239]: time="2026-01-28T14:45:10+07:00" level=debug msg="completed challenge" Jan 28 14:45:10 volumio go-librespot[10239]: time="2026-01-28T14:45: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 14:45:10 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 14:45:10 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 14:45:10 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 14:45:10 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 14:45:10 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 14:45:11 volumio volumio[10223]: info: ------------------------------------------- Jan 28 14:45:11 volumio volumio[10223]: info: ----- Volumio3 ---- Jan 28 14:45:11 volumio volumio[10223]: info: ------------------------------------------- Jan 28 14:45:11 volumio volumio[10223]: info: ----- System startup ---- Jan 28 14:45:11 volumio volumio[10223]: info: ------------------------------------------- Jan 28 14:45:12 volumio volumio-remote-updater[628]: [2026-01-28 14:45:12] [connect] Successful connection Jan 28 14:45:12 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 14:45:12 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 14:45:12 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 14:45:13 volumio volumio[10223]: info: MYVOLUMIO Environment detected Jan 28 14:45:13 volumio volumio[10223]: info: Plugin folders cleanup Jan 28 14:45:13 volumio volumio[10223]: info: Scanning into folder /volumio/app/plugins/ Jan 28 14:45:13 volumio volumio[10223]: info: Scanning category audio_interface Jan 28 14:45:13 volumio volumio[10223]: info: Scanning category miscellanea Jan 28 14:45:13 volumio volumio[10223]: info: Scanning category music_service Jan 28 14:45:13 volumio volumio[10223]: info: Scanning category plugins.json Jan 28 14:45:13 volumio volumio[10223]: info: Scanning category system_controller Jan 28 14:45:13 volumio volumio[10223]: info: Scanning category user_interface Jan 28 14:45:13 volumio volumio[10223]: info: Scanning into folder /data/plugins/ Jan 28 14:45:13 volumio volumio[10223]: info: Scanning category music_service Jan 28 14:45:13 volumio volumio[10223]: info: Plugin folders cleanup completed Jan 28 14:45:13 volumio volumio[10223]: info: ------------------------------------------- Jan 28 14:45:13 volumio volumio[10223]: info: ----- Core plugins startup ---- Jan 28 14:45:13 volumio volumio[10223]: info: ------------------------------------------- Jan 28 14:45:13 volumio volumio[10223]: info: Loading plugins from folder /volumio/app/plugins/ Jan 28 14:45:13 volumio volumio[10223]: info: Adding plugin upnp to MyMusic Plugins Jan 28 14:45:13 volumio volumio[10223]: info: Adding plugin airplay_emulation to MyMusic Plugins Jan 28 14:45:13 volumio volumio[10223]: info: Adding plugin upnp_browser to MyMusic Plugins Jan 28 14:45:13 volumio volumio[10223]: info: Loading plugins from folder /data/plugins/ Jan 28 14:45:13 volumio volumio[10223]: info: Loading plugin "system"... Jan 28 14:45:13 volumio volumio[10223]: info: Loading plugin "appearance"... Jan 28 14:45:13 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Jan 28 14:45:13 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 14:45:13 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 14:45:13 volumio go-librespot[10259]: go-librespot daemon starting... Jan 28 14:45:13 volumio go-librespot[10260]: time="2026-01-28T14:45:13+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 14:45:13 volumio go-librespot[10260]: time="2026-01-28T14:45:13+07:00" level=debug msg="app state loaded" Jan 28 14:45:13 volumio go-librespot[10260]: time="2026-01-28T14:45:13+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 14:45:14 volumio go-librespot[10260]: time="2026-01-28T14:45: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-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 14:45:14 volumio go-librespot[10260]: time="2026-01-28T14:45:14+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 14:45:14 volumio go-librespot[10260]: time="2026-01-28T14:45:14+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 14:45:14 volumio go-librespot[10260]: time="2026-01-28T14:45:14+07:00" level=info msg="zeroconf server listening on port 36321" Jan 28 14:45:14 volumio go-librespot[10260]: time="2026-01-28T14:45:14+07:00" level=debug msg="obtained new client token: AABP90ETy3LfUwqnb03UM2Qx30SAnGaC4nynNdgWiQ4XCVy96i29PcWn1VoO3dbkYweMH+5uSHUHUb37V99a6nEYzmUb3TP3CmFiHKwVPJoWBMuHHb7q92YERqWsb0GwNbdunlJC3/wmKsnkbB4m2Wsr8+5UfLr5oR657009qUVaWHIrK7zKXunXYa96iyh7uC9XwDZF5zJRHXdFZDxwkT5/6R7+FgN+0aM+Paz1eqkB8xA4MuQvUQaYxHE=" Jan 28 14:45:14 volumio go-librespot[10260]: time="2026-01-28T14:45:14+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 14:45:14 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 14:45:14 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 14:45:14 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 14:45:14 volumio go-librespot[10260]: time="2026-01-28T14:45:14+07:00" level=debug msg="completed keyexchange" Jan 28 14:45:14 volumio go-librespot[10260]: time="2026-01-28T14:45:14+07:00" level=debug msg="completed challenge" Jan 28 14:45:15 volumio go-librespot[10260]: time="2026-01-28T14:45:15+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 14:45:15 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 14:45:15 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 14:45:15 volumio volumio[10223]: info: Loading plugin "network"... Jan 28 14:45:15 volumio volumio[10223]: info: Refreshing Cached IP Addresses Jan 28 14:45:15 volumio sudo[10268]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 28 14:45:15 volumio sudo[10268]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 14:45:15 volumio sudo[10270]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 28 14:45:15 volumio sudo[10270]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 14:45:15 volumio volumio[10223]: info: Loading plugin "services"... Jan 28 14:45:15 volumio sudo[10268]: pam_unix(sudo:session): session closed for user root Jan 28 14:45:15 volumio sudo[10270]: pam_unix(sudo:session): session closed for user root Jan 28 14:45:15 volumio volumio[10223]: info: Loading plugin "alsa_controller"... Jan 28 14:45:15 volumio sudo[10278]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Jan 28 14:45:15 volumio sudo[10278]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 14:45:15 volumio volumio[10223]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 28 14:45:15 volumio volumio[10223]: info: Loading plugin "wizard"... Jan 28 14:45:15 volumio volumio[10223]: info: Loading plugin "networkfs"... Jan 28 14:45:15 volumio volumio[10223]: info: Starting Udev Watcher for removable devices Jan 28 14:45:15 volumio volumio[10223]: info: Ignoring mount for partition: boot Jan 28 14:45:15 volumio volumio[10223]: info: Ignoring mount for partition: volumio Jan 28 14:45:15 volumio volumio[10223]: info: Ignoring mount for partition: volumio_data Jan 28 14:45:15 volumio volumio[10223]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 28 14:45:15 volumio volumio[10223]: info: Loading plugin "volumio_command_line_client"... Jan 28 14:45:15 volumio volumio[10223]: info: Loading plugin "upnp"... Jan 28 14:45:15 volumio volumio[10223]: info: [1769586315665] Starting Upmpd Daemon Jan 28 14:45:15 volumio volumio[10223]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 28 14:45:15 volumio volumio[10223]: info: Loading plugin "my_music"... Jan 28 14:45:15 volumio volumio[10223]: info: Loading plugin "mpd"... Jan 28 14:45:16 volumio volumio[10223]: info: Loading plugin "upnp_browser"... Jan 28 14:45:16 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 14:45:16 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 14:45:16 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 14:45:18 volumio sudo[10278]: pam_unix(sudo:session): session closed for user root Jan 28 14:45:18 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Jan 28 14:45:18 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 14:45:18 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 14:45:18 volumio go-librespot[10302]: go-librespot daemon starting... Jan 28 14:45:18 volumio go-librespot[10303]: time="2026-01-28T14:45:18+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 14:45:18 volumio go-librespot[10303]: time="2026-01-28T14:45:18+07:00" level=debug msg="app state loaded" Jan 28 14:45:18 volumio go-librespot[10303]: time="2026-01-28T14:45:18+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 14:45:18 volumio go-librespot[10303]: time="2026-01-28T14:45:18+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 14:45:18 volumio go-librespot[10303]: time="2026-01-28T14:45:18+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 28 14:45:18 volumio go-librespot[10303]: time="2026-01-28T14:45:18+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 28 14:45:18 volumio go-librespot[10303]: time="2026-01-28T14:45:18+07:00" level=info msg="zeroconf server listening on port 40399" Jan 28 14:45:18 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 14:45:18 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 14:45:18 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 14:45:19 volumio go-librespot[10303]: time="2026-01-28T14:45:19+07:00" level=debug msg="obtained new client token: AADGmrjRON6a23pjpiM9ju8gdFGpwuy4yPDWRTFXfKbAoCRugr4uCq9pF1EYLeMDTxIX4O7479WSzVF40sd1JlzHUVB/i2GQK5POotOPz9M6LI9Sbo1Wl9/v8adt+WIo4GJAz7FIWDq9h4n1AU20RZ6Wn+H57hcw8Je7jCcRteD6M0iVxrevH8LelBz1bfkg2iPrbSPlsNVpnstNQ9iWBC/4rEIULMcGoTNymDcsGt/76MlZykvEeQBd" Jan 28 14:45:19 volumio go-librespot[10303]: time="2026-01-28T14:45:19+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 14:45:19 volumio go-librespot[10303]: time="2026-01-28T14:45:19+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Jan 28 14:45:19 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 14:45:19 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 14:45:19 volumio volumio[10223]: info: Starting UPNP Browser Jan 28 14:45:19 volumio volumio[10223]: info: Loading plugin "alarm-clock"... Jan 28 14:45:19 volumio volumio[10223]: info: Loading plugin "airplay_emulation"... Jan 28 14:45:19 volumio volumio[10223]: info: Starting Shairport Sync Jan 28 14:45:19 volumio volumio[10223]: info: Loading plugin "last_100"... Jan 28 14:45:19 volumio volumio[10223]: info: Loading plugin "webradio"... Jan 28 14:45:19 volumio volumio[10223]: info: Loading plugin "i2s_dacs"... Jan 28 14:45:19 volumio volumio[10223]: info: Loading plugin "volumiodiscovery"... Jan 28 14:45:19 volumio volumio[10223]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 28 14:45:19 volumio volumio[10223]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 14:45:19 volumio node[10223]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 28 14:45:19 volumio volumio[10223]: *** WARNING *** For more information see Jan 28 14:45:19 volumio volumio[10223]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 28 14:45:19 volumio volumio[10223]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 14:45:19 volumio volumio[10223]: *** WARNING *** For more information see Jan 28 14:45:19 volumio node[10223]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 14:45:19 volumio node[10223]: *** WARNING *** For more information see Jan 28 14:45:19 volumio node[10223]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 28 14:45:19 volumio node[10223]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 14:45:19 volumio node[10223]: *** WARNING *** For more information see Jan 28 14:45:19 volumio volumio[10223]: info: Applying required configuration parameters for plugin volumiodiscovery Jan 28 14:45:19 volumio volumio[10223]: info: Discovery: Started advertising with name: Volumio Jan 28 14:45:19 volumio volumio[10223]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 28 14:45:19 volumio volumio[10223]: info: Loading plugin "spop"... Jan 28 14:45:20 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 14:45:20 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 14:45:20 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 14:45:21 volumio volumio[10223]: info: Loading plugin "ytcr"... Jan 28 14:45:22 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Jan 28 14:45:22 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 14:45:22 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 14:45:22 volumio go-librespot[10312]: go-librespot daemon starting... Jan 28 14:45:22 volumio go-librespot[10313]: time="2026-01-28T14:45:22+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 14:45:22 volumio go-librespot[10313]: time="2026-01-28T14:45:22+07:00" level=debug msg="app state loaded" Jan 28 14:45:22 volumio go-librespot[10313]: time="2026-01-28T14:45:22+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 14:45:22 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 14:45:22 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 14:45:22 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 14:45:23 volumio go-librespot[10313]: time="2026-01-28T14:45: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 14:45:23 volumio go-librespot[10313]: time="2026-01-28T14:45: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 14:45:23 volumio go-librespot[10313]: time="2026-01-28T14:45: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 14:45:23 volumio go-librespot[10313]: time="2026-01-28T14:45:23+07:00" level=info msg="zeroconf server listening on port 39267" Jan 28 14:45:23 volumio go-librespot[10313]: time="2026-01-28T14:45:23+07:00" level=debug msg="obtained new client token: AAB+df272ew9u63xnmVMjhyZYxSBZJIOksoHnOX6oUfmADJgsqvXJx1vwl78dhwUjXQGRQt4zugap0109o+pd7A1qpUwBRDGARcCjLyn/X/O9gA8NhYwok6DBhV9NemouAqXMz9ligcvYe7ZdWxu35yUw8DUNka9gAHrWrJtI9hJStEfxr7fTxWWrJHJmBsH83L8W1S8bUnvqFIR+CIjLOB1cOrKEPWNq32dYosJ3KmmUNSi4zCG5BE5Swo=" Jan 28 14:45:23 volumio go-librespot[10313]: time="2026-01-28T14:45:23+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 14:45:23 volumio go-librespot[10313]: time="2026-01-28T14:45:23+07:00" level=debug msg="completed keyexchange" Jan 28 14:45:23 volumio go-librespot[10313]: time="2026-01-28T14:45:23+07:00" level=debug msg="completed challenge" Jan 28 14:45:23 volumio go-librespot[10313]: time="2026-01-28T14:45: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 14:45:23 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 14:45:23 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 14:45:24 volumio volumio[10223]: info: Loading plugin "ytmusic"... Jan 28 14:45:24 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 14:45:24 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 14:45:24 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 14:45:25 volumio volumio-remote-updater[628]: [2026-01-28 14:45:25] [connect] Successful connection Jan 28 14:45:25 volumio volumio[10223]: info: Loading plugin "outputs"... Jan 28 14:45:25 volumio volumio[10223]: info: Loading plugin "albumart"... Jan 28 14:45:25 volumio volumio[10223]: info: Plugin example_plugin is not enabled Jan 28 14:45:25 volumio volumio[10223]: info: Loading plugin "inputs"... Jan 28 14:45:25 volumio volumio[10223]: info: Loading plugin "updater_comm"... Jan 28 14:45:25 volumio volumio[10223]: info: Plugin mpdemulation is not enabled Jan 28 14:45:25 volumio volumio[10223]: info: Loading plugin "rest_api"... Jan 28 14:45:25 volumio volumio[10223]: info: Loading plugin "websocket"... Jan 28 14:45:25 volumio volumio[10223]: info: Starting Socket.io Server version 1.7.4 Jan 28 14:45:25 volumio volumio[10223]: info: Loading plugin "RoonBridge"... Jan 28 14:45:26 volumio volumio[10223]: info: Applying required configuration parameters for plugin RoonBridge Jan 28 14:45:26 volumio volumio[10223]: info: Loading i18n strings for locale en Jan 28 14:45:26 volumio volumio[10223]: Updating browse sources language Jan 28 14:45:26 volumio volumio[10223]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 14:45:26 volumio volumio[10223]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 28 14:45:26 volumio volumio[10223]: info: CoreCommandRouter::initPlayerControls Jan 28 14:45:26 volumio volumio[10223]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 14:45:26 volumio volumio[10223]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 14:45:26 volumio volumio[10223]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 14:45:26 volumio volumio[10223]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 14:45:26 volumio volumio[10223]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 14:45:26 volumio volumio[10223]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 14:45:26 volumio volumio[10223]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 14:45:26 volumio volumio[10223]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 14:45:26 volumio volumio[10223]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 28 14:45:26 volumio volumio[10223]: Express server listening on port 3000 Jan 28 14:45:26 volumio volumio[10223]: [Metrics] WebUI: 15s 872.95ms Jan 28 14:45:26 volumio volumio[10223]: info: CoreStateMachine::resetVolumioState Jan 28 14:45:26 volumio volumio[10223]: info: CoreStateMachine::getcurrentVolume Jan 28 14:45:26 volumio volumio[10223]: info: CoreCommandRouter::volumioRetrievevolume Jan 28 14:45:26 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Jan 28 14:45:26 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 14:45:26 volumio volumio[10336]: Forking 3 albumart workers Jan 28 14:45:26 volumio sudo[10354]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 28 14:45:26 volumio sudo[10352]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 28 14:45:26 volumio sudo[10352]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 14:45:26 volumio sudo[10354]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 14:45:26 volumio sudo[10352]: pam_unix(sudo:session): session closed for user root Jan 28 14:45:26 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 14:45:26 volumio go-librespot[10351]: go-librespot daemon starting... Jan 28 14:45:26 volumio sudo[10354]: pam_unix(sudo:session): session closed for user root Jan 28 14:45:26 volumio volumio[10223]: info: Volumio Network Manager: Network status updated: 1 Jan 28 14:45:26 volumio go-librespot[10359]: time="2026-01-28T14:45:26+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 14:45:26 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 14:45:26 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 14:45:26 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 14:45:26 volumio go-librespot[10359]: time="2026-01-28T14:45:26+07:00" level=debug msg="app state loaded" Jan 28 14:45:26 volumio go-librespot[10359]: time="2026-01-28T14:45:26+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 14:45:27 volumio volumio[10223]: info: VolumeController:: Volume=100 Mute =false Jan 28 14:45:27 volumio volumio[10223]: info: CoreStateMachine::pushState Jan 28 14:45:27 volumio volumio[10223]: info: CorePlayQueue::getTrack 0 Jan 28 14:45:27 volumio volumio[10223]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 28 14:45:27 volumio volumio[10223]: info: CoreCommandRouter::volumioPushState Jan 28 14:45:27 volumio volumio[10223]: info: CoreStateMachine::updateTrackBlock Jan 28 14:45:27 volumio volumio[10223]: info: CorePlayQueue::getTrackBlock Jan 28 14:45:27 volumio volumio[10223]: info: CoreCommandRouter::volumioRetrievevolume Jan 28 14:45:27 volumio volumio-remote-updater[628]: [2026-01-28 14:45:27] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1769586325 101 Jan 28 14:45:27 volumio go-librespot[10359]: time="2026-01-28T14:45: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 14:45:27 volumio go-librespot[10359]: time="2026-01-28T14:45: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 14:45:27 volumio go-librespot[10359]: time="2026-01-28T14:45: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 14:45:27 volumio volumio[10223]: 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 14:45:27 volumio go-librespot[10359]: time="2026-01-28T14:45:27+07:00" level=info msg="zeroconf server listening on port 34689" Jan 28 14:45:27 volumio volumio[10223]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 14:45:27 volumio volumio[10223]: info: Reloading queue from file Jan 28 14:45:27 volumio volumio[10223]: info: CoreStateMachine::setRepeat null single undefined Jan 28 14:45:27 volumio volumio[10223]: info: CoreStateMachine::pushState Jan 28 14:45:27 volumio volumio[10223]: info: CorePlayQueue::getTrack 0 Jan 28 14:45:27 volumio volumio[10223]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 28 14:45:27 volumio volumio[10223]: info: CoreCommandRouter::volumioPushState Jan 28 14:45:27 volumio volumio[10223]: info: CoreStateMachine::setRandom null Jan 28 14:45:27 volumio volumio[10223]: info: CoreStateMachine::pushState Jan 28 14:45:27 volumio volumio[10223]: info: CorePlayQueue::getTrack 0 Jan 28 14:45:27 volumio volumio[10223]: info: CoreCommandRouter::volumioPushState Jan 28 14:45:27 volumio volumio[10223]: info: Setting Device type: Raspberry PI Jan 28 14:45:27 volumio volumio[10223]: info: Completed loading Core Plugins Jan 28 14:45:27 volumio volumio[10223]: info: Preparing to generate the ALSA configuration file Jan 28 14:45:27 volumio go-librespot[10359]: time="2026-01-28T14:45:27+07:00" level=debug msg="obtained new client token: AAA4+BvXAMnQEV9aw2jqT8XJApDfV4pTK7+FMYmKp1jXsUP8sRvdW446eqYyxoqCQstulYEANju6EHUtcKiQQnyZDuutZbg5sWszXk0pWWp0y5doMo3UZDDcfyQ2wrrseEN5aHzCpBckGsaOiKFoCK3F0g18Q5aBeoqDv8V6rcqgYaDX1OZMJcMND23kedLHRj1xtnEhMjl0RyI2tGUoX+YGV/5ZKx64/jaVC5deCGiTD/iXtHZg/Ygt/O4=" Jan 28 14:45:27 volumio volumio[10223]: info: VolumeController:: Volume=100 Mute =false Jan 28 14:45:27 volumio volumio[10223]: info: CoreStateMachine::pushState Jan 28 14:45:27 volumio volumio[10223]: info: CorePlayQueue::getTrack 0 Jan 28 14:45:27 volumio volumio[10223]: info: CoreCommandRouter::volumioPushState Jan 28 14:45:27 volumio go-librespot[10359]: time="2026-01-28T14:45:27+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 14:45:27 volumio volumio[10223]: info: Asound.conf file unchanged, so no further update is needed Jan 28 14:45:27 volumio volumio[10223]: info: Output device has changed, restarting MPD Jan 28 14:45:27 volumio volumio[10223]: info: Output device has changed, restarting Shairport Sync Jan 28 14:45:27 volumio go-librespot[10359]: time="2026-01-28T14:45:27+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Jan 28 14:45:27 volumio volumio[10223]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 14:45:27 volumio volumio[10223]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 14:45:27 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 14:45:27 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 14:45:28 volumio sudo[10406]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Jan 28 14:45:28 volumio sudo[10406]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 14:45:28 volumio sudo[10410]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 28 14:45:28 volumio sudo[10408]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 28 14:45:28 volumio sudo[10408]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 14:45:28 volumio sudo[10410]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 14:45:28 volumio sudo[10408]: pam_unix(sudo:session): session closed for user root Jan 28 14:45:28 volumio volumio[10223]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 28 14:45:28 volumio volumio[10223]: info: ___________ START PLUGINS ___________ Jan 28 14:45:28 volumio volumio[10223]: info: ControllerMpd::onStart: Initializing MPD Jan 28 14:45:28 volumio volumio[10223]: info: Creating MPD Configuration file Jan 28 14:45:28 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Jan 28 14:45:28 volumio sudo[10406]: pam_unix(sudo:session): session closed for user root Jan 28 14:45:28 volumio volumio[10223]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 28 14:45:28 volumio volumio[10223]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 14:45:28 volumio volumio[10223]: info: [1769586328299] CoreMusicLibrary::Adding element Media Servers Jan 28 14:45:28 volumio sudo[10419]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 28 14:45:28 volumio sudo[10419]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 14:45:28 volumio volumio[10223]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 14:45:28 volumio sudo[10419]: pam_unix(sudo:session): session closed for user root Jan 28 14:45:28 volumio sudo[10421]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 28 14:45:28 volumio sudo[10421]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 14:45:28 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 28 14:45:28 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 28 14:45:28 volumio systemd[1]: mpd.service: Consumed 7.369s CPU time. Jan 28 14:45:28 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 28 14:45:28 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 28 14:45:28 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 28 14:45:28 volumio volumio[10223]: info: UPNP Browser: Client initialized successfully Jan 28 14:45:28 volumio volumio[10223]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 14:45:28 volumio volumio[10223]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 14:45:28 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 28 14:45:28 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 28 14:45:28 volumio volumio[10223]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 28 14:45:28 volumio volumio[10223]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 14:45:28 volumio volumio[10223]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 14:45:28 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 28 14:45:28 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 28 14:45:28 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 28 14:45:28 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 28 14:45:28 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 28 14:45:28 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 28 14:45:28 volumio volumio[10223]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 28 14:45:28 volumio volumio[10223]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 14:45:28 volumio volumio[10223]: info: [1769586328645] CoreMusicLibrary::Adding element Last_100 Jan 28 14:45:28 volumio volumio[10223]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 14:45:28 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 28 14:45:28 volumio volumio[10223]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 14:45:28 volumio volumio[10223]: info: [1769586328668] CoreMusicLibrary::Adding element Webradio Jan 28 14:45:28 volumio volumio[10223]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 14:45:28 volumio volumio[10223]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 28 14:45:28 volumio volumio[10223]: info: Initializing BBC Radios Jan 28 14:45:28 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 14:45:28 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 14:45:28 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 14:45:28 volumio volumio[10223]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 28 14:45:28 volumio volumio[10223]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 14:45:29 volumio volumio[10223]: info: Creating Spotify config file Jan 28 14:45:29 volumio volumio[10223]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 14:45:29 volumio sudo[10435]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 28 14:45:29 volumio sudo[10435]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jan 28 14:45:29 volumio sudo[10435]: pam_unix(sudo:session): session closed for user root Jan 28 14:45:29 volumio volumio[10356]: Starting albumart workers Jan 28 14:45:30 volumio volumio[10223]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 14:45:30 volumio volumio[10223]: info: [1769586330313] CoreMusicLibrary::Adding element YouTube Music Jan 28 14:45:30 volumio volumio[10223]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 14:45:30 volumio volumio[10223]: Cannot find translation for source YouTube Music Jan 28 14:45:30 volumio volumio[10223]: info: Volumio Calling Home Jan 28 14:45:30 volumio sudo[10452]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Jan 28 14:45:30 volumio sudo[10452]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 14:45:30 volumio volumio[10365]: Starting albumart workers Jan 28 14:45:30 volumio sudo[10452]: pam_unix(sudo:session): session closed for user root Jan 28 14:45:30 volumio volumio[10360]: Starting albumart workers Jan 28 14:45:30 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 14:45:30 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 14:45:30 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 14:45:31 volumio volumio[10223]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Jan 28 14:45:31 volumio volumio[10223]: info: Discovery: Found device Volumio Jan 28 14:45:31 volumio volumio[10223]: info: CoreCommandRouter::volumioGetState Jan 28 14:45:31 volumio volumio[10223]: info: CorePlayQueue::getTrack 0 Jan 28 14:45:31 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 11. Jan 28 14:45:31 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 14:45:31 volumio volumio[10223]: info: MPD Permissions set Jan 28 14:45:31 volumio volumio[10223]: info: MPD Permissions set Jan 28 14:45:31 volumio volumio[10223]: info: Upmpdcli Daemon Started Jan 28 14:45:31 volumio volumio[10223]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Jan 28 14:45:31 volumio volumio[10223]: info: Discovery: Found device Volumio Jan 28 14:45:31 volumio volumio[10223]: info: CoreCommandRouter::volumioGetState Jan 28 14:45:31 volumio volumio[10223]: info: CorePlayQueue::getTrack 0 Jan 28 14:45:31 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 14:45:31 volumio go-librespot[10457]: go-librespot daemon starting... Jan 28 14:45:31 volumio go-librespot[10458]: time="2026-01-28T14:45:31+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 14:45:31 volumio go-librespot[10458]: time="2026-01-28T14:45:31+07:00" level=debug msg="app state loaded" Jan 28 14:45:31 volumio go-librespot[10458]: time="2026-01-28T14:45:31+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 14:45:31 volumio volumio[10223]: info: Volumio called home Jan 28 14:45:31 volumio volumio[10223]: info: Spotify config file written Jan 28 14:45:31 volumio sudo[10465]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jan 28 14:45:31 volumio sudo[10465]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 14:45:31 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Jan 28 14:45:31 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Jan 28 14:45:31 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 14:45:31 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 14:45:32 volumio go-librespot[10474]: go-librespot daemon starting... Jan 28 14:45:32 volumio sudo[10465]: pam_unix(sudo:session): session closed for user root Jan 28 14:45:32 volumio go-librespot[10475]: time="2026-01-28T14:45:32+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 14:45:32 volumio go-librespot[10475]: time="2026-01-28T14:45:32+07:00" level=debug msg="app state loaded" Jan 28 14:45:32 volumio go-librespot[10475]: time="2026-01-28T14:45:32+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 14:45:32 volumio volumio[10223]: 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 14:45:32 volumio volumio[10223]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 14:45:32 volumio volumio[10223]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 14:45:32 volumio volumio[10223]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 14:45:32 volumio volumio[10223]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 14:45:32 volumio volumio[10223]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 14:45:32 volumio volumio[10223]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 14:45:32 volumio volumio[10223]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 14:45:32 volumio volumio[10223]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 14:45:32 volumio volumio[10223]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 14:45:32 volumio volumio[10223]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 14:45:32 volumio volumio[10223]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 14:45:32 volumio volumio[10223]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 14:45:32 volumio volumio[10223]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 14:45:32 volumio volumio[10223]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 14:45:32 volumio volumio[10223]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 14:45:32 volumio volumio[10223]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 14:45:32 volumio volumio[10223]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 14:45:32 volumio volumio[10223]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 14:45:32 volumio volumio[10223]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 14:45:32 volumio volumio[10223]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 14:45:32 volumio volumio[10223]: info: No need to fix Spotify hosts Jan 28 14:45:32 volumio go-librespot[10475]: time="2026-01-28T14:45:32+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 14:45:32 volumio go-librespot[10475]: time="2026-01-28T14:45:32+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 28 14:45:32 volumio go-librespot[10475]: time="2026-01-28T14:45:32+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 28 14:45:32 volumio go-librespot[10475]: time="2026-01-28T14:45:32+07:00" level=info msg="zeroconf server listening on port 37807" Jan 28 14:45:32 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 14:45:32 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 14:45:32 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 14:45:33 volumio go-librespot[10475]: time="2026-01-28T14:45:33+07:00" level=debug msg="obtained new client token: AACQlXzwWVCry1bFdeV6zYX+0r6qJ6SgTQMhdBaO2D8R0K94VwO7ep8TjNf9Vax/X9qjgZXZVyH8U5UO3RYOomzH9cGOThYnf4h9BAEubAPFM5GDOEZva7aZhrEb7d55vI4iJM+ITnqGFGTTiVwAUJxpvp4xCMzGz0vIYfG1OT2gFi+12eHaX9P9TZft85nPR9F2Z/CyD/edKNJvEX3bB7B4NOx/rTa6LDYK/1eJl4zIt4wEs6IExcHQ" Jan 28 14:45:33 volumio go-librespot[10475]: time="2026-01-28T14:45:33+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 14:45:33 volumio go-librespot[10475]: time="2026-01-28T14:45:33+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Jan 28 14:45:33 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 14:45:33 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 14:45:33 volumio volumio[10223]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 28 14:45:33 volumio volumio[10223]: SPOTIFY: BQC5qRnYW0aS8hYWmQFyMaWfBBD7aSsBjeEeWYKec5Bs918Q_zmHkNejTTgrOKvV3qO0fR9WGa98dJK67_Oy36yq9Nlgrso7S4Dku6JousqsMth6qwIc56mEWRbjjYIknHoD1i6ve_uaMeH_Y79Qma76uoUp_UxTWcmpBVktMN0eX-um_PBqqgAoPr8FdHFifTuvsOHRrAnpB9Zx7KuCImvxrjCClYUWis56nSgcTgiUTy-UHxbr5F82IPZf-SdXgu5gC9Or8BoLyFduZddNhQUmTImHTC7eqcdQBg3xOTcrIK6sYjsRAtTY Jan 28 14:45:33 volumio volumio[10223]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 28 14:45:33 volumio volumio[10223]: info: New Spotify access token = BQC5qRnYW0aS8hYWmQFyMaWfBBD7aSsBjeEeWYKec5Bs918Q_zmHkNejTTgrOKvV3qO0fR9WGa98dJK67_Oy36yq9Nlgrso7S4Dku6JousqsMth6qwIc56mEWRbjjYIknHoD1i6ve_uaMeH_Y79Qma76uoUp_UxTWcmpBVktMN0eX-um_PBqqgAoPr8FdHFifTuvsOHRrAnpB9Zx7KuCImvxrjCClYUWis56nSgcTgiUTy-UHxbr5F82IPZf-SdXgu5gC9Or8BoLyFduZddNhQUmTImHTC7eqcdQBg3xOTcrIK6sYjsRAtTY Jan 28 14:45:33 volumio volumio[10223]: info: Spotify credentials grant success - running version from March 24, 2019 Jan 28 14:45:33 volumio volumio[10223]: info: Starting Shairport Sync Jan 28 14:45:33 volumio volumio[10223]: info: Starting Shairport Sync Jan 28 14:45:33 volumio volumio[10223]: info: Starting Shairport Sync Jan 28 14:45:33 volumio sudo[10505]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 28 14:45:33 volumio sudo[10505]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 14:45:33 volumio sudo[10509]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 28 14:45:33 volumio sudo[10509]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 14:45:33 volumio sudo[10507]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 28 14:45:33 volumio sudo[10507]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 14:45:33 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 28 14:45:33 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Jan 28 14:45:33 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 28 14:45:33 volumio systemd[1]: shairport-sync.service: Consumed 2.404s CPU time. Jan 28 14:45:33 volumio volumio[10223]: info: CoreCommandRouter::volumioGetState Jan 28 14:45:33 volumio volumio[10223]: info: CorePlayQueue::getTrack 0 Jan 28 14:45:33 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 28 14:45:33 volumio sudo[10505]: pam_unix(sudo:session): session closed for user root Jan 28 14:45:33 volumio sudo[10509]: pam_unix(sudo:session): session closed for user root Jan 28 14:45:33 volumio sudo[10507]: pam_unix(sudo:session): session closed for user root Jan 28 14:45:33 volumio volumio[10223]: info: Shairport-Sync Started Jan 28 14:45:33 volumio volumio[10223]: Error adding Membership: Error: addMembership EINVAL Jan 28 14:45:33 volumio volumio[10223]: info: Shairport-Sync Started Jan 28 14:45:33 volumio volumio[10223]: info: Shairport-Sync Started Jan 28 14:45:34 volumio volumio[10223]: 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 14:45:34 volumio volumio[10223]: info: Spotify Successfully logged in Jan 28 14:45:34 volumio volumio[10223]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 14:45:34 volumio volumio[10223]: info: [1769586334089] CoreMusicLibrary::Adding element Spotify Jan 28 14:45:34 volumio volumio[10223]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 14:45:34 volumio volumio[10223]: Cannot find translation for source YouTube Music Jan 28 14:45:34 volumio volumio[10223]: Cannot find translation for source Spotify Jan 28 14:45:34 volumio volumio[10223]: info: [yt-cast-receiver] DIAL server listening on port 8098 Jan 28 14:45:34 volumio volumio[10223]: info: CoreCommandRouter::volumioRetrievevolume Jan 28 14:45:34 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 14:45:34 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 14:45:34 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 14:45:35 volumio volumio[10223]: info: VolumeController:: Volume=100 Mute =false Jan 28 14:45:35 volumio volumio[10223]: info: CoreCommandRouter::volumioGetState Jan 28 14:45:35 volumio volumio[10223]: info: CorePlayQueue::getTrack 0 Jan 28 14:45:35 volumio volumio[10223]: info: CoreStateMachine::pushState Jan 28 14:45:35 volumio volumio[10223]: info: CorePlayQueue::getTrack 0 Jan 28 14:45:35 volumio volumio[10223]: info: CoreCommandRouter::volumioPushState Jan 28 14:45:36 volumio volumio[10223]: info: go-librespot daemon successfully initialized Jan 28 14:45:36 volumio mpd[10450]: 2026-01-28T14:45:36 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 28 14:45:36 volumio systemd[1]: Started mpd.service - Music Player Daemon. Jan 28 14:45:36 volumio sudo[10410]: pam_unix(sudo:session): session closed for user root Jan 28 14:45:36 volumio sudo[10421]: pam_unix(sudo:session): session closed for user root Jan 28 14:45:36 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Jan 28 14:45:36 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 14:45:36 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 14:45:36 volumio go-librespot[10548]: go-librespot daemon starting... Jan 28 14:45:36 volumio go-librespot[10551]: time="2026-01-28T14:45:36+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 14:45:36 volumio go-librespot[10551]: time="2026-01-28T14:45:36+07:00" level=debug msg="app state loaded" Jan 28 14:45:36 volumio go-librespot[10551]: time="2026-01-28T14:45:36+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 14:45:36 volumio volumio[10223]: error: MPD error: The expression evaluated to a falsy value: Jan 28 14:45:36 volumio volumio[10223]: assert.ok(self.idling) Jan 28 14:45:36 volumio volumio[10223]: error: The expression evaluated to a falsy value: Jan 28 14:45:36 volumio volumio[10223]: assert.ok(self.idling) Jan 28 14:45:36 volumio volumio[10223]: error: updateQueue error: null Jan 28 14:45:36 volumio volumio[10223]: info: MPD running with PID10450 Jan 28 14:45:36 volumio volumio[10223]: ,establishing connection Jan 28 14:45:36 volumio volumio[10223]: info: Completed starting Core Plugins Jan 28 14:45:36 volumio volumio[10223]: info: ------------------------------------------- Jan 28 14:45:36 volumio volumio[10223]: info: ----- MyVolumio plugins startup ---- Jan 28 14:45:36 volumio volumio[10223]: info: ------------------------------------------- Jan 28 14:45:36 volumio volumio[10223]: info: [MyVolumio PluginManager] Fetching plans data.... Jan 28 14:45:36 volumio volumio[10223]: error: updateQueue error: null Jan 28 14:45:36 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 14:45:36 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 14:45:36 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 14:45:37 volumio go-librespot[10551]: time="2026-01-28T14:45: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-gew4.spotify.com:80]" Jan 28 14:45:37 volumio go-librespot[10551]: time="2026-01-28T14:45:36+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 14:45:37 volumio go-librespot[10551]: time="2026-01-28T14:45:36+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 14:45:37 volumio go-librespot[10551]: time="2026-01-28T14:45:37+07:00" level=info msg="zeroconf server listening on port 45025" Jan 28 14:45:37 volumio go-librespot[10551]: time="2026-01-28T14:45:37+07:00" level=debug msg="obtained new client token: AACrS+iOifcBKmIKlh+Isv7m03DlU9qy3eRwL34HbzlGtng/95GK7O9wK4khFYoO9fdDYh0brTzCfmNUiesfYxAyh2Hwotl6UVuaHJbWuH9SoIYlbqRsKIskRwUDhT1xBp1oAox9ZUuh8SvC+cJjHE6dWI0JcYEV5PKb9A9GhAVK7zjokWvF2onmjhz31nDNZ5Wh31GsvVkVBfJjfCNP4ZEnT6IYBIq5PQsFfJmYsiqFxTfnrCGVpBPK" Jan 28 14:45:37 volumio go-librespot[10551]: time="2026-01-28T14:45:37+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 14:45:37 volumio go-librespot[10551]: time="2026-01-28T14:45:37+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: read tcp 192.168.1.107:43346->104.199.241.202:4070: read: connection reset by peer" Jan 28 14:45:37 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 14:45:37 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 14:45:38 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 14:45:38 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 14:45:38 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 14:45:39 volumio volumio[10223]: info: Initializing connection to go-librespot Websocket Jan 28 14:45:39 volumio volumio[10223]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 28 14:45:40 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Jan 28 14:45:40 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 14:45:40 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 14:45:40 volumio go-librespot[10559]: go-librespot daemon starting... Jan 28 14:45:40 volumio go-librespot[10560]: time="2026-01-28T14:45:40+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 14:45:40 volumio go-librespot[10560]: time="2026-01-28T14:45:40+07:00" level=debug msg="app state loaded" Jan 28 14:45:40 volumio go-librespot[10560]: time="2026-01-28T14:45:40+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 14:45:40 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 14:45:40 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 14:45:40 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 14:45:41 volumio go-librespot[10560]: time="2026-01-28T14:45:41+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 28 14:45:41 volumio go-librespot[10560]: time="2026-01-28T14:45:41+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Jan 28 14:45:41 volumio go-librespot[10560]: time="2026-01-28T14:45:41+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Jan 28 14:45:41 volumio go-librespot[10560]: time="2026-01-28T14:45:41+07:00" level=info msg="zeroconf server listening on port 42605" Jan 28 14:45:41 volumio go-librespot[10560]: time="2026-01-28T14:45:41+07:00" level=debug msg="obtained new client token: AADbDeCd6AaXrrtITzUAUXScKFugL5PAtLc27YvvX0NuOORdJV3yJXs4xri/+NZ8vttedZk0jye122UxHYIw1dxztsYWGtR4D2x77a8PK71wp3Hf59/7GKloYmHBfa41YVjhuIIXahB2zEvmcD6IgOD+uJ1AAPmI2mWKDXvZqW2k5mJwnZ5SZgEU64nyLYDMORA/s4QNQg3UmnD21YxmcgFm4vVxddTqD/WXrf/DqiTPG7J+dIwJKgL9c3Y=" Jan 28 14:45:41 volumio go-librespot[10560]: time="2026-01-28T14:45:41+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 14:45:41 volumio volumio[10223]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Jan 28 14:45:41 volumio go-librespot[10560]: time="2026-01-28T14:45:41+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Jan 28 14:45:41 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 14:45:41 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 14:45:42 volumio volumio[10223]: info: Initializing connection to go-librespot Websocket Jan 28 14:45:42 volumio volumio[10223]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 28 14:45:42 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 14:45:42 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 14:45:42 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 14:45:44 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Jan 28 14:45:44 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 14:45:44 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 14:45:44 volumio go-librespot[10568]: go-librespot daemon starting... Jan 28 14:45:44 volumio go-librespot[10569]: time="2026-01-28T14:45:44+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 14:45:44 volumio go-librespot[10569]: time="2026-01-28T14:45:44+07:00" level=debug msg="app state loaded" Jan 28 14:45:44 volumio go-librespot[10569]: time="2026-01-28T14:45:44+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 14:45:44 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 14:45:44 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 14:45:44 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 14:45:45 volumio volumio[10223]: info: Initializing connection to go-librespot Websocket Jan 28 14:45:45 volumio go-librespot[10569]: time="2026-01-28T14:45:45+07:00" level=debug msg="new websocket client" Jan 28 14:45:45 volumio volumio[10223]: info: Connection to go-librespot Websocket established Jan 28 14:45:45 volumio go-librespot[10569]: time="2026-01-28T14:45:45+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 14:45:45 volumio go-librespot[10569]: time="2026-01-28T14:45:45+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 28 14:45:45 volumio go-librespot[10569]: time="2026-01-28T14:45:45+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 28 14:45:45 volumio go-librespot[10569]: time="2026-01-28T14:45:45+07:00" level=info msg="zeroconf server listening on port 42589" Jan 28 14:45:45 volumio volumio[10223]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Jan 28 14:45:45 volumio volumio[10223]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Jan 28 14:45:45 volumio volumio[10223]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Jan 28 14:45:45 volumio volumio[10223]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Jan 28 14:45:45 volumio volumio[10223]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Jan 28 14:45:45 volumio volumio[10223]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Jan 28 14:45:45 volumio volumio[10223]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Jan 28 14:45:45 volumio volumio[10223]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Jan 28 14:45:45 volumio volumio[10223]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Jan 28 14:45:45 volumio volumio[10223]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Jan 28 14:45:45 volumio volumio[10223]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Jan 28 14:45:45 volumio volumio[10223]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Jan 28 14:45:45 volumio volumio[10223]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Jan 28 14:45:45 volumio volumio[10223]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Jan 28 14:45:45 volumio volumio[10223]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Jan 28 14:45:45 volumio volumio[10223]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Jan 28 14:45:45 volumio volumio[10223]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Jan 28 14:45:45 volumio volumio[10223]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Jan 28 14:45:45 volumio volumio[10223]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Jan 28 14:45:45 volumio volumio[10223]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Jan 28 14:45:45 volumio volumio[10223]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Jan 28 14:45:45 volumio volumio[10223]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Jan 28 14:45:45 volumio volumio[10223]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Jan 28 14:45:45 volumio volumio[10223]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Jan 28 14:45:45 volumio volumio[10223]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Jan 28 14:45:45 volumio volumio[10223]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Jan 28 14:45:45 volumio volumio[10223]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Jan 28 14:45:45 volumio volumio[10223]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Jan 28 14:45:45 volumio volumio[10223]: info: Adding plugin bluetooth to MyMusic Plugins Jan 28 14:45:45 volumio volumio[10223]: info: Adding plugin multiroom to MyMusic Plugins Jan 28 14:45:45 volumio volumio[10223]: info: Adding plugin metavolumio to MyMusic Plugins Jan 28 14:45:45 volumio volumio[10223]: info: Adding plugin cd_controller to MyMusic Plugins Jan 28 14:45:45 volumio volumio[10223]: info: Adding plugin qobuzconnect to MyMusic Plugins Jan 28 14:45:45 volumio volumio[10223]: info: Adding plugin smart_inputs to MyMusic Plugins Jan 28 14:45:45 volumio volumio[10223]: info: Adding plugin tidalconnect to MyMusic Plugins Jan 28 14:45:45 volumio volumio[10223]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Jan 28 14:45:45 volumio go-librespot[10569]: time="2026-01-28T14:45:45+07:00" level=debug msg="obtained new client token: AACZ4ZfbZIU9+8M+32Q94tFPj7JkVzmEVeIsxlpMjpkFzDaw2ZR7wquY4kDktbLTSt9VFEMNpyIC/JiYwuhTpIJNGWeO+wju0DVUcGPwyuqkph9NhR1m1foQ9U9DgDdIhCIFcI/Y4Noj//nZWhpFq+capRkzZBjHkAocT6Jybj78dAD861Aplas8NQjdEsajRXJVQAJ6fNdixSw6m63csHXwM02Zy0p5AcMZwAOT4X3p1qIKaczZSZEM7Ps=" Jan 28 14:45:45 volumio go-librespot[10569]: time="2026-01-28T14:45:45+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 14:45:45 volumio go-librespot[10569]: time="2026-01-28T14:45:45+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Jan 28 14:45:45 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 14:45:45 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 14:45:46 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 14:45:46 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 14:45:46 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 14:45:47 volumio volumio[10223]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Jan 28 14:45:47 volumio volumio[10223]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Jan 28 14:45:47 volumio volumio[10223]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 14:45:47 volumio volumio[10223]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 14:45:47 volumio volumio[10223]: info: Starting MyVolumio Remote Streaming Endpoints Jan 28 14:45:47 volumio volumio[10223]: info: MyVolumio login type: Token Jan 28 14:45:47 volumio volumio[10223]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Jan 28 14:45:47 volumio volumio[10223]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Jan 28 14:45:48 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 14:45:48 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 14:45:48 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 14:45:48 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Jan 28 14:45:48 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 14:45:49 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 14:45:49 volumio go-librespot[10592]: go-librespot daemon starting... Jan 28 14:45:49 volumio go-librespot[10593]: time="2026-01-28T14:45:49+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 14:45:49 volumio go-librespot[10593]: time="2026-01-28T14:45:49+07:00" level=debug msg="app state loaded" Jan 28 14:45:49 volumio go-librespot[10593]: time="2026-01-28T14:45:49+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 14:45:49 volumio volumio[10223]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Jan 28 14:45:49 volumio volumio[10223]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Jan 28 14:45:49 volumio volumio[10223]: info: Streaming services startup Jan 28 14:45:49 volumio volumio[10223]: info: Starting Streaming Daemon Jan 28 14:45:49 volumio volumio[10223]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Jan 28 14:45:49 volumio sudo[10600]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jan 28 14:45:49 volumio sudo[10600]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 14:45:49 volumio sudo[10600]: pam_unix(sudo:session): session closed for user root Jan 28 14:45:49 volumio volumio[10223]: info: Getting Spotify volume Jan 28 14:45:49 volumio volumio[10223]: info: Connection to go-librespot Websocket closed Jan 28 14:45:49 volumio volumio[10223]: error: Cannot start Volumio Streaming Daemon Jan 28 14:45:49 volumio volumio[10223]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Jan 28 14:45:49 volumio volumio[10223]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Jan 28 14:45:49 volumio volumio[10223]: 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 14:45:49 volumio volumio[10223]: info: CoreCommandRouter::volumioGetState Jan 28 14:45:49 volumio volumio[10223]: info: CorePlayQueue::getTrack 0 Jan 28 14:45:49 volumio volumio[10223]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jan 28 14:45:49 volumio volumio[10223]: SPOTIFY: SPOTIFY VOLUME undefined Jan 28 14:45:49 volumio volumio[10223]: SPOTIFY: VOLUMIO VOLUME 100 Jan 28 14:45:49 volumio volumio[10223]: info: Aligning Spotify Volume to Volumio Volume Jan 28 14:45:49 volumio volumio[10223]: info: CoreCommandRouter::volumioGetState Jan 28 14:45:49 volumio volumio[10223]: info: CorePlayQueue::getTrack 0 Jan 28 14:45:49 volumio volumio[10223]: info: Setting Spotify Volume from Volumio: 100 Jan 28 14:45:49 volumio go-librespot[10593]: time="2026-01-28T14:45:49+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 14:45:49 volumio go-librespot[10593]: time="2026-01-28T14:45:49+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 14:45:49 volumio go-librespot[10593]: time="2026-01-28T14:45:49+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 14:45:49 volumio go-librespot[10593]: time="2026-01-28T14:45:49+07:00" level=info msg="zeroconf server listening on port 44005" Jan 28 14:45:50 volumio go-librespot[10593]: time="2026-01-28T14:45:50+07:00" level=debug msg="obtained new client token: AAB3Icwe9cNNfaLQtSlrugBfsT7KUxBKAzm+W5dcmJjXvTe9H6eu4wNm/VrHsvK3oVXV5aMoTp+0rdHZvkWat61fHSso3ndL8SzzlivsdTYBHdZD5ddwiZTRTbrYCT27Ejh34gcq4H+baPQIDxaSTilCBQiPG68ZWHcnYSPd/9zIekV4yA+7EC/vW4DOIn8IcianVrqorbb9p1wA9EDIXlyCXM3AOdU4EKbUpg2Wtctqca3ndgHLtVfh6ys=" Jan 28 14:45:50 volumio go-librespot[10593]: time="2026-01-28T14:45:50+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 14:45:50 volumio go-librespot[10593]: time="2026-01-28T14:45:50+07:00" level=debug msg="completed keyexchange" Jan 28 14:45:50 volumio go-librespot[10593]: time="2026-01-28T14:45:50+07:00" level=debug msg="completed challenge" Jan 28 14:45:50 volumio go-librespot[10593]: time="2026-01-28T14:45:50+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 14:45:50 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 14:45:50 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 14:45:50 volumio volumio[10223]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Jan 28 14:45:50 volumio volumio[10223]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 28 14:45:50 volumio volumio[10223]: Error: socket hang up Jan 28 14:45:50 volumio volumio[10223]: at connResetException (node:internal/errors:720:14) Jan 28 14:45:50 volumio volumio[10223]: at Socket.socketOnEnd (node:_http_client:519:23) Jan 28 14:45:50 volumio volumio[10223]: at Socket.emit (node:events:526:35) Jan 28 14:45:50 volumio volumio[10223]: at endReadableNT (node:internal/streams/readable:1376:12) Jan 28 14:45:50 volumio volumio[10223]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Jan 28 14:45:50 volumio volumio[10223]: code: 'ECONNRESET', Jan 28 14:45:50 volumio volumio[10223]: response: undefined Jan 28 14:45:50 volumio volumio[10223]: } Jan 28 14:45:50 volumio volumio[10223]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 28 14:45:50 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 14:45:50 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 14:45:50 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 14:45:51 volumio sudo[10621]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-01-28 14:44' Jan 28 14:45:51 volumio sudo[10621]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) PRETTY_NAME="Raspbian GNU/Linux 12 (bookworm)" NAME="Raspbian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="b05a530ca81d05eb9a84d0acf82089f0a60b8ee6" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="4ad85e2147d972f0b838d33c21382d2d813b2ae8" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu Dec 25 09:13:19 UTC 2025" VOLUMIO_VERSION="4.084" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="792f09af7488531aecd1aadcaa9b175e"