Jan 27 05:52:00 volumio volumio[13360]: info: [yt-cast-receiver] DIAL server listening on port 8098 Jan 27 05:52:00 volumio volumio[13360]: info: CoreCommandRouter::volumioRetrievevolume Jan 27 05:52:01 volumio volumio[13360]: info: VolumeController:: Volume=100 Mute =false Jan 27 05:52:01 volumio volumio[13360]: info: CoreCommandRouter::volumioGetState Jan 27 05:52:01 volumio volumio[13360]: info: CorePlayQueue::getTrack 0 Jan 27 05:52:01 volumio volumio[13360]: info: CoreStateMachine::pushState Jan 27 05:52:01 volumio volumio[13360]: info: CorePlayQueue::getTrack 0 Jan 27 05:52:01 volumio volumio[13360]: info: CoreCommandRouter::volumioPushState Jan 27 05:52:01 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 05:52:01 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 05:52:01 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 05:52:02 volumio volumio[13360]: info: go-librespot daemon successfully initialized Jan 27 05:52:02 volumio mpd[13593]: 2026-01-27T05:52:02 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 27 05:52:02 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 54. Jan 27 05:52:02 volumio systemd[1]: Started mpd.service - Music Player Daemon. Jan 27 05:52:02 volumio sudo[13551]: pam_unix(sudo:session): session closed for user root Jan 27 05:52:02 volumio sudo[13565]: pam_unix(sudo:session): session closed for user root Jan 27 05:52:02 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 05:52:02 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 05:52:02 volumio go-librespot[13695]: go-librespot daemon starting... Jan 27 05:52:02 volumio go-librespot[13698]: time="2026-01-27T05:52:02+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 05:52:02 volumio go-librespot[13698]: time="2026-01-27T05:52:02+07:00" level=debug msg="app state loaded" Jan 27 05:52:02 volumio go-librespot[13698]: time="2026-01-27T05:52:02+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 05:52:02 volumio volumio[13360]: error: MPD error: The expression evaluated to a falsy value: Jan 27 05:52:02 volumio volumio[13360]: assert.ok(self.idling) Jan 27 05:52:02 volumio volumio[13360]: error: The expression evaluated to a falsy value: Jan 27 05:52:02 volumio volumio[13360]: assert.ok(self.idling) Jan 27 05:52:02 volumio volumio[13360]: error: updateQueue error: null Jan 27 05:52:02 volumio volumio[13360]: info: MPD running with PID13593 Jan 27 05:52:02 volumio volumio[13360]: ,establishing connection Jan 27 05:52:02 volumio volumio[13360]: info: Completed starting Core Plugins Jan 27 05:52:02 volumio volumio[13360]: info: ------------------------------------------- Jan 27 05:52:02 volumio volumio[13360]: info: ----- MyVolumio plugins startup ---- Jan 27 05:52:02 volumio volumio[13360]: info: ------------------------------------------- Jan 27 05:52:02 volumio volumio[13360]: info: [MyVolumio PluginManager] Fetching plans data.... Jan 27 05:52:02 volumio volumio[13360]: error: updateQueue error: null Jan 27 05:52:03 volumio go-librespot[13698]: time="2026-01-27T05:52:03+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 27 05:52:03 volumio go-librespot[13698]: time="2026-01-27T05:52:03+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 27 05:52:03 volumio go-librespot[13698]: time="2026-01-27T05:52:03+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 27 05:52:03 volumio go-librespot[13698]: time="2026-01-27T05:52:03+07:00" level=info msg="zeroconf server listening on port 41503" Jan 27 05:52:03 volumio go-librespot[13698]: time="2026-01-27T05:52:03+07:00" level=debug msg="obtained new client token: AAAb/fjCb1eL7PUbIVJ4GCxY6rw3QYBcfroUxoIb+ThCpwktHg/UWFaCpMu6m7KxNeomTGSoz6E/gFSPa9F33cJfMaQfcbx/u435TJyImk9J+j/2iKiAYgNQ+kkZ3FRy7SvyrBcW5ntwT/pMzSZuWQWr/25+5XLWF809uSD2OHfnI6+o1CFtSroJjLldNgrhbbhzGZv+TGZT8ymaNTaBRndGxGI9y+v70lJbZ8CxB1YMGfK/viM+gOI/Jg4=" Jan 27 05:52:03 volumio go-librespot[13698]: time="2026-01-27T05:52:03+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 05:52:03 volumio go-librespot[13698]: time="2026-01-27T05:52:03+07:00" level=debug msg="completed keyexchange" Jan 27 05:52:03 volumio go-librespot[13698]: time="2026-01-27T05:52:03+07:00" level=debug msg="completed challenge" Jan 27 05:52:03 volumio go-librespot[13698]: time="2026-01-27T05:52:03+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 27 05:52:03 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 05:52:03 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 05:52:03 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 05:52:03 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 05:52:03 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 05:52:05 volumio volumio[13360]: info: Initializing connection to go-librespot Websocket Jan 27 05:52:05 volumio volumio[13360]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 27 05:52:05 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 05:52:05 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 05:52:05 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 05:52:06 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 55. Jan 27 05:52:06 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 05:52:06 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 05:52:06 volumio go-librespot[13705]: go-librespot daemon starting... Jan 27 05:52:06 volumio go-librespot[13706]: time="2026-01-27T05:52:06+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 05:52:06 volumio go-librespot[13706]: time="2026-01-27T05:52:06+07:00" level=debug msg="app state loaded" Jan 27 05:52:06 volumio go-librespot[13706]: time="2026-01-27T05:52:06+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 05:52:07 volumio go-librespot[13706]: time="2026-01-27T05:52: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-gew4.spotify.com:80]" Jan 27 05:52:07 volumio go-librespot[13706]: time="2026-01-27T05:52:07+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 27 05:52:07 volumio go-librespot[13706]: time="2026-01-27T05:52:07+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 27 05:52:07 volumio go-librespot[13706]: time="2026-01-27T05:52:07+07:00" level=info msg="zeroconf server listening on port 44437" Jan 27 05:52:07 volumio volumio[13360]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Jan 27 05:52:07 volumio go-librespot[13706]: time="2026-01-27T05:52:07+07:00" level=debug msg="obtained new client token: AACQ0Phcd6bb9Xv6f0mdVBUm+QyOWD/u4uTVH3304lehPNYrEGHZkqdvX6X8/V+JhpwskqU2/wZdsC1e8QQHcK9W4y7sbYH+w8zWJ2J9FewHHJqtmC+BHoFmwdu8uQB2Od/8rjpwsXsOe3rJ1loI2QD39PorSer6pKs2jgKO8addZxh1z+92i8W6ysLsTeQSETertSE7og90j9pVigyO1y9tDE/ILlGilexn+ozewsc1NUx1SVFoVFyAmiU=" Jan 27 05:52:07 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 05:52:07 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 05:52:07 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 05:52:07 volumio go-librespot[13706]: time="2026-01-27T05:52:07+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 05:52:08 volumio go-librespot[13706]: time="2026-01-27T05:52:08+07:00" level=debug msg="completed keyexchange" Jan 27 05:52:08 volumio go-librespot[13706]: time="2026-01-27T05:52:08+07:00" level=debug msg="completed challenge" Jan 27 05:52:08 volumio go-librespot[13706]: time="2026-01-27T05:52:08+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 27 05:52:08 volumio volumio[13360]: info: Initializing connection to go-librespot Websocket Jan 27 05:52:08 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 05:52:08 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 05:52:08 volumio volumio[13360]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 27 05:52:09 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 05:52:09 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 05:52:09 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 05:52:11 volumio volumio[13360]: info: Initializing connection to go-librespot Websocket Jan 27 05:52:11 volumio volumio[13360]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 27 05:52:11 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 56. Jan 27 05:52:11 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 05:52:11 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 05:52:11 volumio go-librespot[13716]: go-librespot daemon starting... Jan 27 05:52:11 volumio go-librespot[13717]: time="2026-01-27T05:52:11+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 05:52:11 volumio go-librespot[13717]: time="2026-01-27T05:52:11+07:00" level=debug msg="app state loaded" Jan 27 05:52:11 volumio go-librespot[13717]: time="2026-01-27T05:52:11+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 05:52:11 volumio volumio[13360]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Jan 27 05:52:11 volumio volumio[13360]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Jan 27 05:52:11 volumio volumio[13360]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Jan 27 05:52:11 volumio volumio[13360]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Jan 27 05:52:11 volumio volumio[13360]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Jan 27 05:52:11 volumio volumio[13360]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Jan 27 05:52:11 volumio volumio[13360]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Jan 27 05:52:11 volumio volumio[13360]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Jan 27 05:52:11 volumio volumio[13360]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Jan 27 05:52:11 volumio volumio[13360]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Jan 27 05:52:11 volumio volumio[13360]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Jan 27 05:52:11 volumio volumio[13360]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Jan 27 05:52:11 volumio volumio[13360]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Jan 27 05:52:11 volumio volumio[13360]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Jan 27 05:52:11 volumio volumio[13360]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Jan 27 05:52:11 volumio volumio[13360]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Jan 27 05:52:11 volumio volumio[13360]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Jan 27 05:52:11 volumio volumio[13360]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Jan 27 05:52:11 volumio volumio[13360]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Jan 27 05:52:11 volumio volumio[13360]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Jan 27 05:52:11 volumio volumio[13360]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Jan 27 05:52:11 volumio volumio[13360]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Jan 27 05:52:11 volumio volumio[13360]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Jan 27 05:52:11 volumio volumio[13360]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Jan 27 05:52:11 volumio volumio[13360]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Jan 27 05:52:11 volumio volumio[13360]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Jan 27 05:52:11 volumio volumio[13360]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Jan 27 05:52:11 volumio volumio[13360]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Jan 27 05:52:11 volumio volumio[13360]: info: Adding plugin bluetooth to MyMusic Plugins Jan 27 05:52:11 volumio volumio[13360]: info: Adding plugin multiroom to MyMusic Plugins Jan 27 05:52:11 volumio volumio[13360]: info: Adding plugin metavolumio to MyMusic Plugins Jan 27 05:52:11 volumio volumio[13360]: info: Adding plugin cd_controller to MyMusic Plugins Jan 27 05:52:11 volumio volumio[13360]: info: Adding plugin qobuzconnect to MyMusic Plugins Jan 27 05:52:11 volumio volumio[13360]: info: Adding plugin smart_inputs to MyMusic Plugins Jan 27 05:52:11 volumio volumio[13360]: info: Adding plugin tidalconnect to MyMusic Plugins Jan 27 05:52:11 volumio volumio[13360]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Jan 27 05:52:11 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 05:52:11 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 05:52:11 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 05:52:11 volumio go-librespot[13717]: time="2026-01-27T05:52:11+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 27 05:52:11 volumio go-librespot[13717]: time="2026-01-27T05:52:11+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 27 05:52:11 volumio go-librespot[13717]: time="2026-01-27T05:52:11+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 27 05:52:11 volumio go-librespot[13717]: time="2026-01-27T05:52:11+07:00" level=info msg="zeroconf server listening on port 37465" Jan 27 05:52:12 volumio go-librespot[13717]: time="2026-01-27T05:52:12+07:00" level=debug msg="obtained new client token: AAAl5bTS6uhXmUYOQlho5Xen2UwJNUnPFzcww4Je68MuAueuTNwLrXzB9DysM31r66jnskCX0Lhi+MWBHMSO8kEt/IApXw5woX/kGZ+DG5Ci6WAbXNnNle57Zg+uGFzXgOaSZ7zc7rgVkS2UKEz77YVcy2nFYHfAnQmmVInM1kYt38ewnCNF2t5GLc5Ts8pTWF3w/AJ6WOT5AIlcgathmN5goj1AvAzFw/0XNcDEKm0phfZh3UXVHkau" Jan 27 05:52:12 volumio go-librespot[13717]: time="2026-01-27T05:52:12+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 05:52:12 volumio go-librespot[13717]: time="2026-01-27T05:52:12+07:00" level=debug msg="completed keyexchange" Jan 27 05:52:12 volumio go-librespot[13717]: time="2026-01-27T05:52:12+07:00" level=debug msg="completed challenge" Jan 27 05:52:12 volumio go-librespot[13717]: time="2026-01-27T05:52:12+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 27 05:52:12 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 05:52:12 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 05:52:13 volumio volumio[13360]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Jan 27 05:52:13 volumio volumio[13360]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Jan 27 05:52:13 volumio volumio[13360]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 05:52:13 volumio volumio[13360]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 05:52:13 volumio volumio[13360]: info: Starting MyVolumio Remote Streaming Endpoints Jan 27 05:52:13 volumio volumio[13360]: info: MyVolumio login type: Token Jan 27 05:52:13 volumio volumio[13360]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Jan 27 05:52:13 volumio volumio[13360]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Jan 27 05:52:13 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 05:52:13 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 05:52:13 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 05:52:15 volumio volumio[13360]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Jan 27 05:52:15 volumio volumio[13360]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Jan 27 05:52:15 volumio volumio[13360]: info: Streaming services startup Jan 27 05:52:15 volumio volumio[13360]: info: Starting Streaming Daemon Jan 27 05:52:15 volumio sudo[13739]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jan 27 05:52:15 volumio volumio[13360]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Jan 27 05:52:15 volumio sudo[13739]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 05:52:15 volumio sudo[13739]: pam_unix(sudo:session): session closed for user root Jan 27 05:52:15 volumio volumio[13360]: info: Initializing connection to go-librespot Websocket Jan 27 05:52:15 volumio volumio[13360]: error: Cannot start Volumio Streaming Daemon Jan 27 05:52:15 volumio volumio[13360]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Jan 27 05:52:15 volumio volumio[13360]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Jan 27 05:52:15 volumio volumio[13360]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 27 05:52:15 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 57. Jan 27 05:52:15 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 05:52:15 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 05:52:15 volumio go-librespot[13746]: go-librespot daemon starting... Jan 27 05:52:15 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 05:52:15 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 05:52:15 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 05:52:15 volumio go-librespot[13747]: time="2026-01-27T05:52:15+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 05:52:15 volumio go-librespot[13747]: time="2026-01-27T05:52:15+07:00" level=debug msg="app state loaded" Jan 27 05:52:15 volumio go-librespot[13747]: time="2026-01-27T05:52:15+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 05:52:16 volumio go-librespot[13747]: time="2026-01-27T05:52:16+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 27 05:52:16 volumio go-librespot[13747]: time="2026-01-27T05:52:16+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Jan 27 05:52:16 volumio go-librespot[13747]: time="2026-01-27T05:52:16+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Jan 27 05:52:16 volumio volumio[13360]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Jan 27 05:52:16 volumio go-librespot[13747]: time="2026-01-27T05:52:16+07:00" level=info msg="zeroconf server listening on port 46733" Jan 27 05:52:16 volumio go-librespot[13747]: time="2026-01-27T05:52:16+07:00" level=debug msg="obtained new client token: AAASLICyhwROaBnQQBQOpT5LENpS0c8wZ24/drNi2cMJXUkl9WZAOzT0yCpshpv4mAG/9JLyMXQRAfdaBz/+5uOtF+X6sscCXvnFW+qlreTFqqVEkHwsl/5rDLQ8ydp6TUU4gS4uRh1qzbzSls1BlU9D+Y/yMp3zOnb2kVayAJeUsMHsM11+FNgULqx5Kt4IKR+g79gRldODzZRKPcEh+Z1vPWa+Qcpl3T2vEtNeAVRW3BGvWcQfyOIInz0=" Jan 27 05:52:16 volumio go-librespot[13747]: time="2026-01-27T05:52:16+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 05:52:16 volumio go-librespot[13747]: time="2026-01-27T05:52:16+07:00" level=debug msg="completed keyexchange" Jan 27 05:52:16 volumio go-librespot[13747]: time="2026-01-27T05:52:16+07:00" level=debug msg="completed challenge" Jan 27 05:52:17 volumio go-librespot[13747]: time="2026-01-27T05:52:17+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 27 05:52:17 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 05:52:17 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 05:52:17 volumio volumio[13360]: info: MyVolumio token set successfully Jan 27 05:52:17 volumio volumio[13360]: info: MYVOLUMIO: Adding device Jan 27 05:52:17 volumio volumio[13360]: info: MYVOLUMIO: Evaluating Server Jan 27 05:52:17 volumio volumio[13360]: info: MyVolumio status changed Jan 27 05:52:17 volumio volumio[13360]: info: Streaming services startup Jan 27 05:52:17 volumio volumio[13360]: info: Starting Streaming Daemon Jan 27 05:52:17 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 05:52:17 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 05:52:17 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 05:52:17 volumio volumio[13360]: info: Removing browser output: myVolumio user plan is not superstar Jan 27 05:52:17 volumio volumio[13360]: info: Removing audio output: Jan 27 05:52:17 volumio volumio[13360]: info: Stoppping Tunnel 1 Jan 27 05:52:17 volumio sudo[13775]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jan 27 05:52:17 volumio sudo[13775]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 05:52:17 volumio sudo[13777]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Jan 27 05:52:17 volumio sudo[13777]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 05:52:18 volumio sudo[13775]: pam_unix(sudo:session): session closed for user root Jan 27 05:52:18 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jan 27 05:52:18 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jan 27 05:52:18 volumio volumio[13360]: error: Cannot start Volumio Streaming Daemon Jan 27 05:52:18 volumio volumio[13360]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Jan 27 05:52:18 volumio volumio[13360]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Jan 27 05:52:18 volumio volumio[13360]: info: Setting Geolocation for MyVolumio to as1 Jan 27 05:52:18 volumio volumio[13360]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 05:52:18 volumio volumio[13360]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 05:52:18 volumio volumio[13360]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 05:52:18 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jan 27 05:52:18 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jan 27 05:52:18 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jan 27 05:52:18 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jan 27 05:52:18 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jan 27 05:52:18 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jan 27 05:52:18 volumio sudo[13777]: pam_unix(sudo:session): session closed for user root Jan 27 05:52:18 volumio volumio[13360]: info: Remote SSH Stopped Jan 27 05:52:18 volumio volumio[13360]: info: Initializing connection to go-librespot Websocket Jan 27 05:52:18 volumio volumio[13360]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 27 05:52:18 volumio volumio[13360]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Jan 27 05:52:19 volumio volumio[13360]: info: Updating MyVolumio device info Jan 27 05:52:19 volumio volumio[13360]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 05:52:19 volumio volumio[13360]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 05:52:19 volumio volumio[13360]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 05:52:19 volumio volumio[13360]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Jan 27 05:52:19 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 05:52:19 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 05:52:19 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 05:52:20 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 58. Jan 27 05:52:20 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 05:52:20 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 05:52:20 volumio go-librespot[13780]: go-librespot daemon starting... Jan 27 05:52:20 volumio go-librespot[13781]: time="2026-01-27T05:52:20+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 05:52:20 volumio go-librespot[13781]: time="2026-01-27T05:52:20+07:00" level=debug msg="app state loaded" Jan 27 05:52:20 volumio go-librespot[13781]: time="2026-01-27T05:52:20+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 05:52:20 volumio go-librespot[13781]: time="2026-01-27T05:52:20+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 27 05:52:20 volumio go-librespot[13781]: time="2026-01-27T05:52:20+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 27 05:52:20 volumio go-librespot[13781]: time="2026-01-27T05:52:20+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 27 05:52:20 volumio go-librespot[13781]: time="2026-01-27T05:52:20+07:00" level=info msg="zeroconf server listening on port 32797" Jan 27 05:52:21 volumio go-librespot[13781]: time="2026-01-27T05:52:21+07:00" level=debug msg="obtained new client token: AAD4HCfzm1o31GshDbu6mFjgW1+yRDiNBhZvHWLt22OSaFanrcGoDR8fXZknvaMPvqaXa1aBlIlNW7yw4381KVGXDG07u7FTZSrqKKvp3SDrtZkYOztLepa9P7XJtjRlDgGMmFu5YEZp8kqy0GjfLD5mvya61uzz/EZFjAhb29BcbOVx8HlJvr8b/nmwqBWfGU9+O7iQtw8TD0TN3ljsHsm0t5MNcKmbu8TpUZU+Oity5BwVS1iW91lo" Jan 27 05:52:21 volumio go-librespot[13781]: time="2026-01-27T05:52:21+07:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:4070, retrying with a different AP" error="dial tcp 104.199.241.202:4070: connect: connection refused" Jan 27 05:52:21 volumio go-librespot[13781]: time="2026-01-27T05:52:21+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Jan 27 05:52:21 volumio go-librespot[13781]: time="2026-01-27T05:52:21+07:00" level=debug msg="completed keyexchange" Jan 27 05:52:21 volumio go-librespot[13781]: time="2026-01-27T05:52:21+07:00" level=debug msg="completed challenge" Jan 27 05:52:21 volumio volumio[13360]: info: Initializing connection to go-librespot Websocket Jan 27 05:52:21 volumio go-librespot[13781]: time="2026-01-27T05:52:21+07:00" level=debug msg="new websocket client" Jan 27 05:52:21 volumio volumio[13360]: info: Connection to go-librespot Websocket established Jan 27 05:52:21 volumio go-librespot[13781]: time="2026-01-27T05:52:21+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 27 05:52:21 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 05:52:21 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 05:52:21 volumio volumio[13360]: info: Connection to go-librespot Websocket closed Jan 27 05:52:21 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 05:52:21 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 05:52:21 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 05:52:22 volumio volumio[13360]: info: MYVOLUMIO: Adding device Jan 27 05:52:22 volumio volumio[13360]: info: MYVOLUMIO: Evaluating Server Jan 27 05:52:23 volumio volumio[13360]: info: Setting Geolocation for MyVolumio to as1 Jan 27 05:52:23 volumio volumio[13360]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 05:52:23 volumio volumio[13360]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 05:52:23 volumio volumio[13360]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 05:52:23 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 05:52:23 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 05:52:23 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 05:52:24 volumio volumio[13360]: info: Updating MyVolumio device info Jan 27 05:52:24 volumio volumio[13360]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 05:52:24 volumio volumio[13360]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 05:52:24 volumio volumio[13360]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 05:52:24 volumio volumio[13360]: info: Getting Spotify volume Jan 27 05:52:24 volumio volumio[13360]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 27 05:52:24 volumio volumio[13360]: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 27 05:52:24 volumio volumio[13360]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Jan 27 05:52:24 volumio volumio[13360]: errno: -111, Jan 27 05:52:24 volumio volumio[13360]: code: 'ECONNREFUSED', Jan 27 05:52:24 volumio volumio[13360]: syscall: 'connect', Jan 27 05:52:24 volumio volumio[13360]: address: '127.0.0.1', Jan 27 05:52:24 volumio volumio[13360]: port: 9879, Jan 27 05:52:24 volumio volumio[13360]: response: undefined Jan 27 05:52:24 volumio volumio[13360]: } Jan 27 05:52:24 volumio volumio[13360]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 27 05:52:24 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 59. Jan 27 05:52:24 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 05:52:24 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 05:52:24 volumio go-librespot[13831]: go-librespot daemon starting... Jan 27 05:52:24 volumio go-librespot[13833]: time="2026-01-27T05:52:24+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 05:52:24 volumio go-librespot[13833]: time="2026-01-27T05:52:24+07:00" level=debug msg="app state loaded" Jan 27 05:52:24 volumio go-librespot[13833]: time="2026-01-27T05:52:24+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 05:52:25 volumio go-librespot[13833]: time="2026-01-27T05:52:25+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 27 05:52:25 volumio go-librespot[13833]: time="2026-01-27T05:52:25+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 27 05:52:25 volumio go-librespot[13833]: time="2026-01-27T05:52:25+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 27 05:52:25 volumio go-librespot[13833]: time="2026-01-27T05:52:25+07:00" level=info msg="zeroconf server listening on port 40947" Jan 27 05:52:25 volumio go-librespot[13833]: time="2026-01-27T05:52:25+07:00" level=debug msg="obtained new client token: AACLNbn7KdXdk7A+nWf1+XSMPJqwSybMBDC64l4DVr5L4ubYF9eyCxiz4ByjnmUV9Dywi+gxH70b2GaYjOA1mjctn0MFTSB32p8jrvJdBuUrzBV2e27y/MlH3UQ+fGc7uhuHKm8f9lL9Yzaf1WYEsAum1DGmQ+Fze+MbXJqGcK6BMzltszXoItqZak9FDKvQOOoctT/COccTemw8/zOrhKwQ9zlLwqmotWYVNQzVaaQofHFSSMZ4Cm1RG4g=" Jan 27 05:52:25 volumio go-librespot[13833]: time="2026-01-27T05:52:25+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 05:52:25 volumio go-librespot[13833]: time="2026-01-27T05:52:25+07:00" level=debug msg="completed keyexchange" Jan 27 05:52:25 volumio go-librespot[13833]: time="2026-01-27T05:52:25+07:00" level=debug msg="completed challenge" Jan 27 05:52:25 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 05:52:25 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 05:52:25 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 05:52:25 volumio go-librespot[13833]: time="2026-01-27T05:52:25+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 27 05:52:25 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 05:52:25 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 05:52:26 volumio sudo[13842]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-01-27 05:51' Jan 27 05:52:26 volumio sudo[13842]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 05:52:26 volumio sudo[13842]: pam_unix(sudo:session): session closed for user root Jan 27 05:52:26 volumio volumio-remote-updater[628]: [2026-01-27 05:52:26] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Jan 27 05:52:26 volumio volumio-remote-updater[628]: [2026-01-27 05:52:26] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Jan 27 05:52:26 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Jan 27 05:52:26 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Jan 27 05:52:26 volumio systemd[1]: volumio.service: Consumed 1min 15.010s CPU time. Jan 27 05:52:26 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 27 05:52:26 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Jan 27 05:52:26 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 8097. Jan 27 05:52:26 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 27 05:52:26 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Jan 27 05:52:26 volumio systemd[1]: volumio.service: Consumed 1min 15.010s CPU time. Jan 27 05:52:26 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Jan 27 05:52:26 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Jan 27 05:52:27 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 05:52:27 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 05:52:27 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 05:52:28 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 60. Jan 27 05:52:28 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 05:52:29 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 05:52:29 volumio go-librespot[13870]: go-librespot daemon starting... Jan 27 05:52:29 volumio go-librespot[13871]: time="2026-01-27T05:52:29+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 05:52:29 volumio go-librespot[13871]: time="2026-01-27T05:52:29+07:00" level=debug msg="app state loaded" Jan 27 05:52:29 volumio go-librespot[13871]: time="2026-01-27T05:52:29+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 05:52:29 volumio go-librespot[13871]: time="2026-01-27T05:52:29+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 27 05:52:29 volumio go-librespot[13871]: time="2026-01-27T05:52:29+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Jan 27 05:52:29 volumio go-librespot[13871]: time="2026-01-27T05:52:29+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Jan 27 05:52:29 volumio go-librespot[13871]: time="2026-01-27T05:52:29+07:00" level=info msg="zeroconf server listening on port 44245" Jan 27 05:52:29 volumio go-librespot[13871]: time="2026-01-27T05:52:29+07:00" level=debug msg="obtained new client token: AADKSFKhSY17M5ILn+TP10YOLc3cuUGk9GaUbjSUWoqkBQAuit0ONidwFwpRJ+yQQRU7KqMLzZI3t/nK/3xztAYx0xwLn3KHM+tWOpd9cFcoiNr+JRzUUU1SVJjtKoh7qbuO4KHh4tKKZA9godVzX9TFlODGNu+svY2nBv8j39UsTf04pP6IgG/F3ZdzfBNdH1DdrD/NSdO4b3HuyHtykYjDAAbBkStjf/VquwF4oMl1cC3KDEePcRaHexY=" Jan 27 05:52:29 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 05:52:29 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 05:52:29 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 05:52:29 volumio go-librespot[13871]: time="2026-01-27T05:52:29+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 05:52:30 volumio go-librespot[13871]: time="2026-01-27T05:52:30+07:00" level=debug msg="completed keyexchange" Jan 27 05:52:30 volumio go-librespot[13871]: time="2026-01-27T05:52:30+07:00" level=debug msg="completed challenge" Jan 27 05:52:30 volumio go-librespot[13871]: time="2026-01-27T05:52:30+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 27 05:52:30 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 05:52:30 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 05:52:30 volumio volumio[13855]: info: ------------------------------------------- Jan 27 05:52:30 volumio volumio[13855]: info: ----- Volumio3 ---- Jan 27 05:52:30 volumio volumio[13855]: info: ------------------------------------------- Jan 27 05:52:30 volumio volumio[13855]: info: ----- System startup ---- Jan 27 05:52:30 volumio volumio[13855]: info: ------------------------------------------- Jan 27 05:52:31 volumio volumio-remote-updater[628]: [2026-01-27 05:52:31] [connect] Successful connection Jan 27 05:52:31 volumio volumio[13855]: info: MYVOLUMIO Environment detected Jan 27 05:52:31 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 05:52:31 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 05:52:31 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 05:52:31 volumio volumio[13855]: info: Plugin folders cleanup Jan 27 05:52:31 volumio volumio[13855]: info: Scanning into folder /volumio/app/plugins/ Jan 27 05:52:31 volumio volumio[13855]: info: Scanning category audio_interface Jan 27 05:52:31 volumio volumio[13855]: info: Scanning category miscellanea Jan 27 05:52:31 volumio volumio[13855]: info: Scanning category music_service Jan 27 05:52:31 volumio volumio[13855]: info: Scanning category plugins.json Jan 27 05:52:31 volumio volumio[13855]: info: Scanning category system_controller Jan 27 05:52:31 volumio volumio[13855]: info: Scanning category user_interface Jan 27 05:52:31 volumio volumio[13855]: info: Scanning into folder /data/plugins/ Jan 27 05:52:31 volumio volumio[13855]: info: Scanning category music_service Jan 27 05:52:31 volumio volumio[13855]: info: Plugin folders cleanup completed Jan 27 05:52:31 volumio volumio[13855]: info: ------------------------------------------- Jan 27 05:52:31 volumio volumio[13855]: info: ----- Core plugins startup ---- Jan 27 05:52:31 volumio volumio[13855]: info: ------------------------------------------- Jan 27 05:52:31 volumio volumio[13855]: info: Loading plugins from folder /volumio/app/plugins/ Jan 27 05:52:31 volumio volumio[13855]: info: Adding plugin upnp to MyMusic Plugins Jan 27 05:52:32 volumio volumio[13855]: info: Adding plugin airplay_emulation to MyMusic Plugins Jan 27 05:52:32 volumio volumio[13855]: info: Adding plugin upnp_browser to MyMusic Plugins Jan 27 05:52:32 volumio volumio[13855]: info: Loading plugins from folder /data/plugins/ Jan 27 05:52:32 volumio volumio[13855]: info: Loading plugin "system"... Jan 27 05:52:32 volumio volumio[13855]: info: Loading plugin "appearance"... Jan 27 05:52:33 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 61. Jan 27 05:52:33 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 05:52:33 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 05:52:33 volumio go-librespot[13891]: go-librespot daemon starting... Jan 27 05:52:33 volumio go-librespot[13892]: time="2026-01-27T05:52:33+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 05:52:33 volumio go-librespot[13892]: time="2026-01-27T05:52:33+07:00" level=debug msg="app state loaded" Jan 27 05:52:33 volumio go-librespot[13892]: time="2026-01-27T05:52:33+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 05:52:33 volumio go-librespot[13892]: time="2026-01-27T05:52:33+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 27 05:52:33 volumio go-librespot[13892]: time="2026-01-27T05:52:33+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 27 05:52:33 volumio go-librespot[13892]: time="2026-01-27T05:52:33+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 27 05:52:33 volumio go-librespot[13892]: time="2026-01-27T05:52:33+07:00" level=info msg="zeroconf server listening on port 41089" Jan 27 05:52:33 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 05:52:33 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 05:52:33 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 05:52:34 volumio volumio[13855]: info: Loading plugin "network"... Jan 27 05:52:34 volumio volumio[13855]: info: Refreshing Cached IP Addresses Jan 27 05:52:34 volumio sudo[13900]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 27 05:52:34 volumio sudo[13900]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 05:52:34 volumio sudo[13902]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 27 05:52:34 volumio sudo[13902]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 05:52:34 volumio sudo[13900]: pam_unix(sudo:session): session closed for user root Jan 27 05:52:34 volumio volumio[13855]: info: Loading plugin "services"... Jan 27 05:52:34 volumio go-librespot[13892]: time="2026-01-27T05:52:34+07:00" level=debug msg="obtained new client token: AAARlMMQdJPGF6zN65+jwfsmtcqpIYvX7yjRHkqoLYLqWtQSngrxvuqBCqdjAq1J10bS4AaF6/GxpFYpUv0g7LGupJIBXkSvJNPAPmG1/RqZQzOMXPYvPqSTebklf50XJYFRhz1U1BtkoFCNkNNefdKxe2o8otgcMd5+7TXTPXcwekPJLLaCda+qpbydNZv4wd2SOMbobTgMS1pxvsAPzIoqeGXjj3N/ImlMWYJnHY+amk1lOWL9DU6d" Jan 27 05:52:34 volumio sudo[13902]: pam_unix(sudo:session): session closed for user root Jan 27 05:52:34 volumio volumio[13855]: info: Loading plugin "alsa_controller"... Jan 27 05:52:34 volumio sudo[13909]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Jan 27 05:52:34 volumio sudo[13909]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 05:52:34 volumio go-librespot[13892]: time="2026-01-27T05:52:34+07:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:4070, retrying with a different AP" error="dial tcp 104.199.241.202:4070: connect: connection refused" Jan 27 05:52:34 volumio volumio[13855]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 27 05:52:34 volumio volumio[13855]: info: Loading plugin "wizard"... Jan 27 05:52:34 volumio volumio[13855]: info: Loading plugin "networkfs"... Jan 27 05:52:34 volumio go-librespot[13892]: time="2026-01-27T05:52:34+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Jan 27 05:52:34 volumio volumio[13855]: info: Starting Udev Watcher for removable devices Jan 27 05:52:34 volumio go-librespot[13892]: time="2026-01-27T05:52:34+07:00" level=debug msg="completed keyexchange" Jan 27 05:52:34 volumio go-librespot[13892]: time="2026-01-27T05:52:34+07:00" level=debug msg="completed challenge" Jan 27 05:52:34 volumio volumio[13855]: info: Ignoring mount for partition: boot Jan 27 05:52:34 volumio volumio[13855]: info: Ignoring mount for partition: volumio Jan 27 05:52:34 volumio volumio[13855]: info: Ignoring mount for partition: volumio_data Jan 27 05:52:34 volumio volumio[13855]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 27 05:52:34 volumio volumio[13855]: info: Loading plugin "volumio_command_line_client"... Jan 27 05:52:34 volumio volumio[13855]: info: Loading plugin "upnp"... Jan 27 05:52:34 volumio volumio[13855]: info: [1769467954477] Starting Upmpd Daemon Jan 27 05:52:34 volumio volumio[13855]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 27 05:52:34 volumio volumio[13855]: info: Loading plugin "my_music"... Jan 27 05:52:34 volumio volumio[13855]: info: Loading plugin "mpd"... Jan 27 05:52:34 volumio go-librespot[13892]: time="2026-01-27T05:52:34+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 27 05:52:34 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 05:52:34 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 05:52:35 volumio volumio[13855]: info: Loading plugin "upnp_browser"... Jan 27 05:52:35 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 05:52:35 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 05:52:35 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 05:52:37 volumio sudo[13909]: pam_unix(sudo:session): session closed for user root Jan 27 05:52:37 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 62. Jan 27 05:52:37 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 05:52:37 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 05:52:37 volumio go-librespot[13934]: go-librespot daemon starting... Jan 27 05:52:37 volumio go-librespot[13935]: time="2026-01-27T05:52:37+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 05:52:37 volumio go-librespot[13935]: time="2026-01-27T05:52:37+07:00" level=debug msg="app state loaded" Jan 27 05:52:37 volumio go-librespot[13935]: time="2026-01-27T05:52:37+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 05:52:37 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 05:52:37 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 05:52:37 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 05:52:38 volumio volumio[13855]: info: Starting UPNP Browser Jan 27 05:52:38 volumio volumio[13855]: info: Loading plugin "alarm-clock"... Jan 27 05:52:38 volumio go-librespot[13935]: time="2026-01-27T05:52:38+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 27 05:52:38 volumio go-librespot[13935]: time="2026-01-27T05:52:38+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 27 05:52:38 volumio go-librespot[13935]: time="2026-01-27T05:52:38+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 27 05:52:38 volumio go-librespot[13935]: time="2026-01-27T05:52:38+07:00" level=info msg="zeroconf server listening on port 44055" Jan 27 05:52:38 volumio volumio[13855]: info: Loading plugin "airplay_emulation"... Jan 27 05:52:38 volumio volumio[13855]: info: Starting Shairport Sync Jan 27 05:52:38 volumio volumio[13855]: info: Loading plugin "last_100"... Jan 27 05:52:38 volumio volumio[13855]: info: Loading plugin "webradio"... Jan 27 05:52:38 volumio go-librespot[13935]: time="2026-01-27T05:52:38+07:00" level=debug msg="obtained new client token: AACJjsVD1EOwEZ1g2KVc3zcrdpjRiNqdT/ymgnVM1prnqFaRdvLqMH8nxVI+fOLFHsdL2lsqrGo7OZ+C9YjofBJlW8W7q5D2rKMNiUvHt6plsXQHHuh7PsinwnfVKlj0zRrQdWL0VTwkrXaW1umwm7eX+evL5cz6+BoWM4nP62zZQ3qCVZ3LBPiYcfXl5OIMDGEBeilaZ+0xo+o9KJdIIhMqiX0aXra0iQifBhVl+ej0TFHCiCh4ZZQMDjI=" Jan 27 05:52:38 volumio volumio[13855]: info: Loading plugin "i2s_dacs"... Jan 27 05:52:38 volumio volumio[13855]: info: Loading plugin "volumiodiscovery"... Jan 27 05:52:38 volumio go-librespot[13935]: time="2026-01-27T05:52:38+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 05:52:38 volumio volumio[13855]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 27 05:52:38 volumio volumio[13855]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 27 05:52:38 volumio volumio[13855]: *** WARNING *** For more information see Jan 27 05:52:38 volumio volumio[13855]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 27 05:52:38 volumio volumio[13855]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 27 05:52:38 volumio volumio[13855]: *** WARNING *** For more information see Jan 27 05:52:38 volumio node[13855]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 27 05:52:38 volumio node[13855]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 27 05:52:38 volumio node[13855]: *** WARNING *** For more information see Jan 27 05:52:38 volumio node[13855]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 27 05:52:38 volumio node[13855]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 27 05:52:38 volumio node[13855]: *** WARNING *** For more information see Jan 27 05:52:38 volumio volumio[13855]: info: Applying required configuration parameters for plugin volumiodiscovery Jan 27 05:52:38 volumio volumio[13855]: info: Discovery: Started advertising with name: Volumio Jan 27 05:52:38 volumio volumio[13855]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 27 05:52:38 volumio volumio[13855]: info: Loading plugin "spop"... Jan 27 05:52:38 volumio go-librespot[13935]: time="2026-01-27T05:52:38+07:00" level=debug msg="completed keyexchange" Jan 27 05:52:38 volumio go-librespot[13935]: time="2026-01-27T05:52:38+07:00" level=debug msg="completed challenge" Jan 27 05:52:38 volumio go-librespot[13935]: time="2026-01-27T05:52:38+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 27 05:52:38 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 05:52:38 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 05:52:39 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 05:52:39 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 05:52:39 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 05:52:40 volumio volumio[13855]: info: Loading plugin "ytcr"... Jan 27 05:52:41 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 05:52:41 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 05:52:41 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 05:52:42 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 63. Jan 27 05:52:42 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 05:52:42 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 05:52:42 volumio go-librespot[13946]: go-librespot daemon starting... Jan 27 05:52:42 volumio go-librespot[13947]: time="2026-01-27T05:52:42+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 05:52:42 volumio go-librespot[13947]: time="2026-01-27T05:52:42+07:00" level=debug msg="app state loaded" Jan 27 05:52:42 volumio go-librespot[13947]: time="2026-01-27T05:52:42+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 05:52:42 volumio go-librespot[13947]: time="2026-01-27T05:52:42+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 27 05:52:42 volumio go-librespot[13947]: time="2026-01-27T05:52:42+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 27 05:52:42 volumio go-librespot[13947]: time="2026-01-27T05:52:42+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 27 05:52:42 volumio go-librespot[13947]: time="2026-01-27T05:52:42+07:00" level=info msg="zeroconf server listening on port 34103" Jan 27 05:52:43 volumio go-librespot[13947]: time="2026-01-27T05:52:43+07:00" level=debug msg="obtained new client token: AAA6Atx7H7bSleDsO4zeil67tHCuF9EdrAjQwWmTJKgBiNm3XeDXbnNiF9FWFF20vov0K0WFQDsLypgFpB6iOK25jdWblADOXu7CSkbwBjxO37hg+Ol1k4Xl05qwJLFiwn/SKorZIaUkDRr75N+7AQClD48ZyirGSfu9y1tfY9vahARJxro+c0rMtNkMdzci6Yasp64sq1rtk/Wl9M+G/YnhFH8nuBNZ9NXY6bPmYOXI9GZStLy36Txc" Jan 27 05:52:43 volumio go-librespot[13947]: time="2026-01-27T05:52:43+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 05:52:43 volumio go-librespot[13947]: time="2026-01-27T05:52:43+07:00" level=debug msg="completed keyexchange" Jan 27 05:52:43 volumio go-librespot[13947]: time="2026-01-27T05:52:43+07:00" level=debug msg="completed challenge" Jan 27 05:52:43 volumio volumio[13855]: info: Loading plugin "ytmusic"... Jan 27 05:52:43 volumio go-librespot[13947]: time="2026-01-27T05:52:43+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 27 05:52:43 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 05:52:43 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 05:52:43 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 05:52:43 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 05:52:43 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 05:52:44 volumio volumio-remote-updater[628]: [2026-01-27 05:52:44] [connect] Successful connection Jan 27 05:52:44 volumio volumio[13855]: info: Loading plugin "outputs"... Jan 27 05:52:44 volumio volumio[13855]: info: Loading plugin "albumart"... Jan 27 05:52:44 volumio volumio[13855]: info: Plugin example_plugin is not enabled Jan 27 05:52:44 volumio volumio[13855]: info: Loading plugin "inputs"... Jan 27 05:52:44 volumio volumio[13855]: info: Loading plugin "updater_comm"... Jan 27 05:52:44 volumio volumio[13855]: info: Plugin mpdemulation is not enabled Jan 27 05:52:44 volumio volumio[13855]: info: Loading plugin "rest_api"... Jan 27 05:52:44 volumio volumio[13855]: info: Loading plugin "websocket"... Jan 27 05:52:44 volumio volumio[13855]: info: Starting Socket.io Server version 1.7.4 Jan 27 05:52:44 volumio volumio[13855]: info: Loading plugin "RoonBridge"... Jan 27 05:52:45 volumio volumio[13855]: info: Applying required configuration parameters for plugin RoonBridge Jan 27 05:52:45 volumio volumio[13855]: info: Loading i18n strings for locale en Jan 27 05:52:45 volumio volumio[13855]: Updating browse sources language Jan 27 05:52:45 volumio volumio[13855]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 27 05:52:45 volumio volumio[13855]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 27 05:52:45 volumio volumio[13855]: info: CoreCommandRouter::initPlayerControls Jan 27 05:52:45 volumio volumio[13855]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 05:52:45 volumio volumio[13855]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 05:52:45 volumio volumio[13855]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 05:52:45 volumio volumio[13855]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 05:52:45 volumio volumio[13855]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 05:52:45 volumio volumio[13855]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 05:52:45 volumio volumio[13855]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 05:52:45 volumio volumio[13855]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 05:52:45 volumio volumio[13968]: Forking 3 albumart workers Jan 27 05:52:45 volumio volumio[13855]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 27 05:52:45 volumio volumio[13855]: Express server listening on port 3000 Jan 27 05:52:45 volumio volumio[13855]: [Metrics] WebUI: 16s 176.62ms Jan 27 05:52:45 volumio volumio[13855]: info: CoreStateMachine::resetVolumioState Jan 27 05:52:45 volumio volumio[13855]: info: CoreStateMachine::getcurrentVolume Jan 27 05:52:45 volumio volumio[13855]: info: CoreCommandRouter::volumioRetrievevolume Jan 27 05:52:45 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 05:52:45 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 05:52:45 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 05:52:45 volumio sudo[14002]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 27 05:52:45 volumio sudo[14002]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 05:52:45 volumio sudo[14012]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 27 05:52:45 volumio sudo[14012]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 05:52:45 volumio sudo[14002]: pam_unix(sudo:session): session closed for user root Jan 27 05:52:45 volumio sudo[14012]: pam_unix(sudo:session): session closed for user root Jan 27 05:52:45 volumio volumio[13855]: info: Volumio Network Manager: Network status updated: 1 Jan 27 05:52:46 volumio volumio[13855]: info: VolumeController:: Volume=100 Mute =false Jan 27 05:52:46 volumio volumio[13855]: info: CoreStateMachine::pushState Jan 27 05:52:46 volumio volumio[13855]: info: CorePlayQueue::getTrack 0 Jan 27 05:52:46 volumio volumio[13855]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 27 05:52:46 volumio volumio[13855]: info: CoreCommandRouter::volumioPushState Jan 27 05:52:46 volumio volumio[13855]: info: CoreStateMachine::updateTrackBlock Jan 27 05:52:46 volumio volumio[13855]: info: CorePlayQueue::getTrackBlock Jan 27 05:52:46 volumio volumio[13855]: info: CoreCommandRouter::volumioRetrievevolume Jan 27 05:52:46 volumio volumio-remote-updater[628]: [2026-01-27 05:52:46] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1769467964 101 Jan 27 05:52:46 volumio volumio[13855]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 1 Jan 27 05:52:46 volumio volumio[13855]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 05:52:46 volumio volumio[13855]: info: Reloading queue from file Jan 27 05:52:46 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 64. Jan 27 05:52:46 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 05:52:46 volumio volumio[13855]: info: CoreStateMachine::setRepeat null single undefined Jan 27 05:52:46 volumio volumio[13855]: info: CoreStateMachine::pushState Jan 27 05:52:46 volumio volumio[13855]: info: CorePlayQueue::getTrack 0 Jan 27 05:52:46 volumio volumio[13855]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 27 05:52:46 volumio volumio[13855]: info: CoreCommandRouter::volumioPushState Jan 27 05:52:46 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 05:52:46 volumio volumio[13855]: info: CoreStateMachine::setRandom null Jan 27 05:52:46 volumio volumio[13855]: info: CoreStateMachine::pushState Jan 27 05:52:46 volumio volumio[13855]: info: CorePlayQueue::getTrack 0 Jan 27 05:52:46 volumio volumio[13855]: info: CoreCommandRouter::volumioPushState Jan 27 05:52:46 volumio go-librespot[14025]: go-librespot daemon starting... Jan 27 05:52:46 volumio volumio[13855]: info: Setting Device type: Raspberry PI Jan 27 05:52:46 volumio go-librespot[14026]: time="2026-01-27T05:52:46+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 05:52:46 volumio go-librespot[14026]: time="2026-01-27T05:52:46+07:00" level=debug msg="app state loaded" Jan 27 05:52:46 volumio go-librespot[14026]: time="2026-01-27T05:52:46+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 05:52:46 volumio volumio[13855]: info: Completed loading Core Plugins Jan 27 05:52:46 volumio volumio[13855]: info: Preparing to generate the ALSA configuration file Jan 27 05:52:46 volumio volumio[13855]: info: VolumeController:: Volume=100 Mute =false Jan 27 05:52:46 volumio volumio[13855]: info: CoreStateMachine::pushState Jan 27 05:52:46 volumio volumio[13855]: info: CorePlayQueue::getTrack 0 Jan 27 05:52:46 volumio volumio[13855]: info: CoreCommandRouter::volumioPushState Jan 27 05:52:46 volumio volumio[13855]: info: Asound.conf file unchanged, so no further update is needed Jan 27 05:52:46 volumio volumio[13855]: info: Output device has changed, restarting MPD Jan 27 05:52:46 volumio sudo[14036]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Jan 27 05:52:46 volumio volumio[13855]: info: Output device has changed, restarting Shairport Sync Jan 27 05:52:46 volumio sudo[14036]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 05:52:46 volumio volumio[13855]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 05:52:46 volumio volumio[13855]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 05:52:47 volumio sudo[14038]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 27 05:52:47 volumio sudo[14038]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 05:52:47 volumio sudo[14038]: pam_unix(sudo:session): session closed for user root Jan 27 05:52:47 volumio sudo[14040]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 27 05:52:47 volumio sudo[14040]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 05:52:47 volumio sudo[14036]: pam_unix(sudo:session): session closed for user root Jan 27 05:52:47 volumio volumio[13855]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 27 05:52:47 volumio volumio[13855]: info: ___________ START PLUGINS ___________ Jan 27 05:52:47 volumio volumio[13855]: info: ControllerMpd::onStart: Initializing MPD Jan 27 05:52:47 volumio volumio[13855]: info: Creating MPD Configuration file Jan 27 05:52:47 volumio go-librespot[14026]: time="2026-01-27T05:52:47+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 27 05:52:47 volumio go-librespot[14026]: time="2026-01-27T05:52:47+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Jan 27 05:52:47 volumio go-librespot[14026]: time="2026-01-27T05:52:47+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Jan 27 05:52:47 volumio go-librespot[14026]: time="2026-01-27T05:52:47+07:00" level=info msg="zeroconf server listening on port 36899" Jan 27 05:52:47 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Jan 27 05:52:47 volumio volumio[13855]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 27 05:52:47 volumio volumio[13855]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 27 05:52:47 volumio volumio[13855]: info: [1769467967305] CoreMusicLibrary::Adding element Media Servers Jan 27 05:52:47 volumio volumio[13855]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 27 05:52:47 volumio sudo[14051]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 27 05:52:47 volumio sudo[14051]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 05:52:47 volumio volumio[13855]: info: UPNP Browser: Client initialized successfully Jan 27 05:52:47 volumio sudo[14049]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 27 05:52:47 volumio sudo[14049]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 05:52:47 volumio volumio[13855]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 05:52:47 volumio volumio[13855]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 05:52:47 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 27 05:52:47 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 27 05:52:47 volumio sudo[14049]: pam_unix(sudo:session): session closed for user root Jan 27 05:52:47 volumio systemd[1]: mpd.service: Consumed 7.432s CPU time. Jan 27 05:52:47 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 27 05:52:47 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 27 05:52:47 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 27 05:52:47 volumio go-librespot[14026]: time="2026-01-27T05:52:47+07:00" level=debug msg="obtained new client token: AACPBNLf4aWgGqehMQ9BR4O0eUgKhyopY8fs1yT6Pu8LCYC5xH4NpkPGohZ1SYVhQXXn19APx/GXW8NtGbHO3JOkdq4pQUtrqTl3+Vri1aQfeTP6tR3HMYcQk9w++jmzsnRpQdMSb32G0LBvD0QF927y6HmADhQ8hfuvQCbGGSXkhNeQr0lOaNBjpbHSoqJAfVcURkTFY4oL6FuPgxhgLy1GIVPjlBae+IZ1qWMSWmHkfHxMQ4r2SjKuXps=" Jan 27 05:52:47 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 27 05:52:47 volumio volumio[13855]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 27 05:52:47 volumio volumio[13855]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 05:52:47 volumio volumio[13855]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 05:52:47 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 27 05:52:47 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 27 05:52:47 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 27 05:52:47 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 27 05:52:47 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 27 05:52:47 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 27 05:52:47 volumio go-librespot[14026]: time="2026-01-27T05:52:47+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 05:52:47 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 27 05:52:47 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 27 05:52:47 volumio volumio[13855]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 27 05:52:47 volumio volumio[13855]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 27 05:52:47 volumio volumio[13855]: info: [1769467967688] CoreMusicLibrary::Adding element Last_100 Jan 27 05:52:47 volumio volumio[13855]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 27 05:52:47 volumio volumio[13855]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 27 05:52:47 volumio volumio[13855]: info: [1769467967728] CoreMusicLibrary::Adding element Webradio Jan 27 05:52:47 volumio volumio[13855]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 27 05:52:47 volumio volumio[13855]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 27 05:52:47 volumio volumio[13855]: info: Initializing BBC Radios Jan 27 05:52:47 volumio go-librespot[14026]: time="2026-01-27T05:52:47+07:00" level=debug msg="completed keyexchange" Jan 27 05:52:47 volumio go-librespot[14026]: time="2026-01-27T05:52:47+07:00" level=debug msg="completed challenge" Jan 27 05:52:47 volumio go-librespot[14026]: time="2026-01-27T05:52:47+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 27 05:52:47 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 05:52:47 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 05:52:47 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 05:52:47 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 05:52:47 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 05:52:47 volumio volumio[13855]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 27 05:52:47 volumio volumio[13855]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 05:52:48 volumio volumio[13855]: info: Creating Spotify config file Jan 27 05:52:48 volumio volumio[13855]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 05:52:48 volumio sudo[14065]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 27 05:52:48 volumio sudo[14065]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jan 27 05:52:48 volumio sudo[14065]: pam_unix(sudo:session): session closed for user root Jan 27 05:52:48 volumio volumio[13978]: Starting albumart workers Jan 27 05:52:49 volumio volumio[13855]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 27 05:52:49 volumio volumio[13855]: info: [1769467969086] CoreMusicLibrary::Adding element YouTube Music Jan 27 05:52:49 volumio volumio[13855]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 27 05:52:49 volumio volumio[13855]: Cannot find translation for source YouTube Music Jan 27 05:52:49 volumio volumio[13855]: info: Volumio Calling Home Jan 27 05:52:49 volumio sudo[14082]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Jan 27 05:52:49 volumio sudo[14082]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 05:52:49 volumio volumio[13980]: Starting albumart workers Jan 27 05:52:49 volumio sudo[14082]: pam_unix(sudo:session): session closed for user root Jan 27 05:52:49 volumio volumio[13982]: Starting albumart workers Jan 27 05:52:49 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 05:52:49 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 05:52:49 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 05:52:49 volumio volumio[13855]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Jan 27 05:52:49 volumio volumio[13855]: info: Discovery: Found device Volumio Jan 27 05:52:49 volumio volumio[13855]: info: CoreCommandRouter::volumioGetState Jan 27 05:52:49 volumio volumio[13855]: info: CorePlayQueue::getTrack 0 Jan 27 05:52:50 volumio volumio[13855]: info: MPD Permissions set Jan 27 05:52:50 volumio volumio[13855]: info: MPD Permissions set Jan 27 05:52:50 volumio volumio[13855]: info: Upmpdcli Daemon Started Jan 27 05:52:50 volumio volumio[13855]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Jan 27 05:52:50 volumio volumio[13855]: info: Discovery: Found device Volumio Jan 27 05:52:50 volumio volumio[13855]: info: CoreCommandRouter::volumioGetState Jan 27 05:52:50 volumio volumio[13855]: info: CorePlayQueue::getTrack 0 Jan 27 05:52:50 volumio volumio[13855]: info: Spotify config file written Jan 27 05:52:50 volumio sudo[14089]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jan 27 05:52:50 volumio sudo[14089]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 05:52:50 volumio volumio[13855]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Jan 27 05:52:50 volumio volumio[13855]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 05:52:50 volumio volumio[13855]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 05:52:50 volumio volumio[13855]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 05:52:50 volumio volumio[13855]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 05:52:50 volumio volumio[13855]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 05:52:50 volumio volumio[13855]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 05:52:50 volumio volumio[13855]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 05:52:50 volumio volumio[13855]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 05:52:50 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 05:52:50 volumio volumio[13855]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 05:52:50 volumio volumio[13855]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 05:52:50 volumio volumio[13855]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 05:52:50 volumio volumio[13855]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 05:52:50 volumio volumio[13855]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 05:52:50 volumio volumio[13855]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 05:52:50 volumio volumio[13855]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 05:52:50 volumio volumio[13855]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 05:52:50 volumio volumio[13855]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 05:52:50 volumio volumio[13855]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 05:52:50 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 05:52:50 volumio go-librespot[14096]: go-librespot daemon starting... Jan 27 05:52:50 volumio sudo[14089]: pam_unix(sudo:session): session closed for user root Jan 27 05:52:50 volumio volumio[13855]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 05:52:50 volumio go-librespot[14100]: time="2026-01-27T05:52:50+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 05:52:50 volumio volumio[13855]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 05:52:50 volumio go-librespot[14100]: time="2026-01-27T05:52:50+07:00" level=debug msg="app state loaded" Jan 27 05:52:50 volumio go-librespot[14100]: time="2026-01-27T05:52:50+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 05:52:50 volumio volumio[13855]: info: No need to fix Spotify hosts Jan 27 05:52:51 volumio go-librespot[14100]: time="2026-01-27T05:52:51+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 27 05:52:51 volumio go-librespot[14100]: time="2026-01-27T05:52:51+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 27 05:52:51 volumio go-librespot[14100]: time="2026-01-27T05:52:51+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 27 05:52:51 volumio go-librespot[14100]: time="2026-01-27T05:52:51+07:00" level=info msg="zeroconf server listening on port 37071" Jan 27 05:52:51 volumio volumio[13855]: info: Volumio called home Jan 27 05:52:51 volumio go-librespot[14100]: time="2026-01-27T05:52:51+07:00" level=debug msg="obtained new client token: AADpnySoiyzAUCoNsTWSRb95Ypn6uub0W4HS2J0hovja9CmllA3M6u7OoZ4/CYd3/kXFQNITzZ0rwkDdRTHnoj+dWam/NhMDPU87nGK4l96W7jUlWJnjA/3PqaWMHh5dzjmDHt2oEU9Cy6f+FdlgcsAY3rWbPc6tr6B4q6zkQ/0ZbQb6JGCA/fVw7ehSmALZWgtQicQzx2FilNFtzd5Su8fMrKCK1KKyxsPpgps8tdTbn8YcWVXT1nx+oBQ=" Jan 27 05:52:51 volumio volumio[13855]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 27 05:52:51 volumio volumio[13855]: SPOTIFY: BQCdzPJZ4VXVe8884Euq0rCWCmP3-X7z6KT1lVr2ovGZs3s4_utnbuYRyetUPBAmENC4StF6FzXL-fFuOHftSBQkMFstwDJnm_92r7TrD5tn1pyKFQ2aOLbzQrdYT2jKjKuK7-_83SkZyadpwJ-ze7iNeMI-_89oulJtneQYlxuHnGInQUVdiiZLriqcRpgD4WcrG_FCVYB5mGz3clGxpWXVq8IRWURUs1hMcq3lPMR0n79UQv8HNOgmLQUPHEHmQs3gHNJ9T4j2CL6iSCyiQxEsiwe_RMgC-Mm-3Hldh1SdCD4EtJnD294l Jan 27 05:52:51 volumio volumio[13855]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 27 05:52:51 volumio volumio[13855]: info: New Spotify access token = BQCdzPJZ4VXVe8884Euq0rCWCmP3-X7z6KT1lVr2ovGZs3s4_utnbuYRyetUPBAmENC4StF6FzXL-fFuOHftSBQkMFstwDJnm_92r7TrD5tn1pyKFQ2aOLbzQrdYT2jKjKuK7-_83SkZyadpwJ-ze7iNeMI-_89oulJtneQYlxuHnGInQUVdiiZLriqcRpgD4WcrG_FCVYB5mGz3clGxpWXVq8IRWURUs1hMcq3lPMR0n79UQv8HNOgmLQUPHEHmQs3gHNJ9T4j2CL6iSCyiQxEsiwe_RMgC-Mm-3Hldh1SdCD4EtJnD294l Jan 27 05:52:51 volumio volumio[13855]: info: Spotify credentials grant success - running version from March 24, 2019 Jan 27 05:52:51 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 05:52:51 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 05:52:51 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 05:52:51 volumio go-librespot[14100]: time="2026-01-27T05:52:51+07:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:4070, retrying with a different AP" error="dial tcp 104.199.241.202:4070: connect: connection refused" Jan 27 05:52:52 volumio go-librespot[14100]: time="2026-01-27T05:52:52+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Jan 27 05:52:52 volumio volumio[13855]: info: Starting Shairport Sync Jan 27 05:52:52 volumio volumio[13855]: info: Starting Shairport Sync Jan 27 05:52:52 volumio go-librespot[14100]: time="2026-01-27T05:52:52+07:00" level=debug msg="completed keyexchange" Jan 27 05:52:52 volumio go-librespot[14100]: time="2026-01-27T05:52:52+07:00" level=debug msg="completed challenge" Jan 27 05:52:52 volumio volumio[13855]: info: Starting Shairport Sync Jan 27 05:52:52 volumio sudo[14130]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 27 05:52:52 volumio sudo[14130]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 05:52:52 volumio sudo[14133]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 27 05:52:52 volumio sudo[14133]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 05:52:52 volumio sudo[14135]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 27 05:52:52 volumio sudo[14135]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 05:52:52 volumio go-librespot[14100]: time="2026-01-27T05:52:52+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 27 05:52:52 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 27 05:52:52 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Jan 27 05:52:52 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 27 05:52:52 volumio systemd[1]: shairport-sync.service: Consumed 2.573s CPU time. Jan 27 05:52:52 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 05:52:52 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 05:52:52 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 27 05:52:52 volumio sudo[14130]: pam_unix(sudo:session): session closed for user root Jan 27 05:52:52 volumio volumio[13855]: info: CoreCommandRouter::volumioGetState Jan 27 05:52:52 volumio volumio[13855]: info: CorePlayQueue::getTrack 0 Jan 27 05:52:52 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 27 05:52:52 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Jan 27 05:52:52 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 27 05:52:52 volumio volumio[13855]: info: Shairport-Sync Started Jan 27 05:52:52 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 27 05:52:52 volumio sudo[14135]: pam_unix(sudo:session): session closed for user root Jan 27 05:52:52 volumio sudo[14133]: pam_unix(sudo:session): session closed for user root Jan 27 05:52:52 volumio volumio[13855]: Error adding Membership: Error: addMembership EINVAL Jan 27 05:52:52 volumio volumio[13855]: info: Shairport-Sync Started Jan 27 05:52:52 volumio volumio[13855]: info: Shairport-Sync Started Jan 27 05:52:52 volumio volumio[13855]: SPOTIFY: User informations: {"country":"PK","display_name":"215mmgea6kss3jxeqsqdquvji","email":"linh.ngotran@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/215mmgea6kss3jxeqsqdquvji"},"followers":{"href":null,"total":1},"href":"https://api.spotify.com/v1/users/215mmgea6kss3jxeqsqdquvji","id":"215mmgea6kss3jxeqsqdquvji","images":[],"product":"premium","type":"user","uri":"spotify:user:215mmgea6kss3jxeqsqdquvji"} Jan 27 05:52:52 volumio volumio[13855]: info: Spotify Successfully logged in Jan 27 05:52:52 volumio volumio[13855]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 27 05:52:52 volumio volumio[13855]: info: [1769467972888] CoreMusicLibrary::Adding element Spotify Jan 27 05:52:52 volumio volumio[13855]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 27 05:52:52 volumio volumio[13855]: Cannot find translation for source YouTube Music Jan 27 05:52:52 volumio volumio[13855]: Cannot find translation for source Spotify Jan 27 05:52:53 volumio volumio[13855]: info: [yt-cast-receiver] DIAL server listening on port 8098 Jan 27 05:52:53 volumio volumio[13855]: info: CoreCommandRouter::volumioRetrievevolume Jan 27 05:52:53 volumio volumio[13855]: info: VolumeController:: Volume=100 Mute =false Jan 27 05:52:53 volumio volumio[13855]: info: CoreCommandRouter::volumioGetState Jan 27 05:52:53 volumio volumio[13855]: info: CorePlayQueue::getTrack 0 Jan 27 05:52:53 volumio volumio[13855]: info: CoreStateMachine::pushState Jan 27 05:52:53 volumio volumio[13855]: info: CorePlayQueue::getTrack 0 Jan 27 05:52:53 volumio volumio[13855]: info: CoreCommandRouter::volumioPushState Jan 27 05:52:53 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 05:52:53 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 05:52:53 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 05:52:54 volumio volumio[13855]: info: go-librespot daemon successfully initialized Jan 27 05:52:55 volumio mpd[14080]: 2026-01-27T05:52:55 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 27 05:52:55 volumio systemd[1]: Started mpd.service - Music Player Daemon. Jan 27 05:52:55 volumio sudo[14040]: pam_unix(sudo:session): session closed for user root Jan 27 05:52:55 volumio sudo[14051]: pam_unix(sudo:session): session closed for user root Jan 27 05:52:55 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 65. Jan 27 05:52:55 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 05:52:55 volumio volumio[13855]: error: MPD error: The expression evaluated to a falsy value: Jan 27 05:52:55 volumio volumio[13855]: assert.ok(self.idling) Jan 27 05:52:55 volumio volumio[13855]: error: The expression evaluated to a falsy value: Jan 27 05:52:55 volumio volumio[13855]: assert.ok(self.idling) Jan 27 05:52:55 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 05:52:55 volumio go-librespot[14175]: go-librespot daemon starting... Jan 27 05:52:55 volumio volumio[13855]: info: MPD running with PID14080 Jan 27 05:52:55 volumio volumio[13855]: ,establishing connection Jan 27 05:52:55 volumio volumio[13855]: error: updateQueue error: null Jan 27 05:52:55 volumio go-librespot[14176]: time="2026-01-27T05:52:55+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 05:52:55 volumio go-librespot[14176]: time="2026-01-27T05:52:55+07:00" level=debug msg="app state loaded" Jan 27 05:52:55 volumio go-librespot[14176]: time="2026-01-27T05:52:55+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 05:52:55 volumio volumio[13855]: info: Completed starting Core Plugins Jan 27 05:52:55 volumio volumio[13855]: info: ------------------------------------------- Jan 27 05:52:55 volumio volumio[13855]: info: ----- MyVolumio plugins startup ---- Jan 27 05:52:55 volumio volumio[13855]: info: ------------------------------------------- Jan 27 05:52:55 volumio volumio[13855]: info: [MyVolumio PluginManager] Fetching plans data.... Jan 27 05:52:55 volumio volumio[13855]: error: updateQueue error: null Jan 27 05:52:55 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 05:52:55 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 05:52:55 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 05:52:56 volumio go-librespot[14176]: time="2026-01-27T05:52:56+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 27 05:52:56 volumio go-librespot[14176]: time="2026-01-27T05:52:56+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 27 05:52:56 volumio go-librespot[14176]: time="2026-01-27T05:52:56+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 27 05:52:56 volumio go-librespot[14176]: time="2026-01-27T05:52:56+07:00" level=info msg="zeroconf server listening on port 42107" Jan 27 05:52:56 volumio go-librespot[14176]: time="2026-01-27T05:52:56+07:00" level=debug msg="obtained new client token: AACP6Dy6Uq2gQKZwI5ZuDM9rN1k7TnioUS+UE2Ll/r8wCypbVwmVqDddm73S42dlUBfp9aF5FIaBePrwF1w0ghrYZcscIIhmkABI59A2RtltAP64NPlqDMcx6iS42zYsHdcbtgV54kKMFoJHFXDPXleASyVFUQHt3GUge3KEdzvU1G93yXBAHnY8n6fZL24fn6gF7aMnRKHCq4G8s/Kr5mnohtuBqSNh1R83llHJNYlH+5QXMJGyZ86qd/g=" Jan 27 05:52:56 volumio go-librespot[14176]: time="2026-01-27T05:52:56+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 05:52:56 volumio go-librespot[14176]: time="2026-01-27T05:52:56+07:00" level=debug msg="completed keyexchange" Jan 27 05:52:56 volumio go-librespot[14176]: time="2026-01-27T05:52:56+07:00" level=debug msg="completed challenge" Jan 27 05:52:56 volumio go-librespot[14176]: time="2026-01-27T05:52:56+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 27 05:52:56 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 05:52:56 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 05:52:57 volumio volumio[13855]: info: Initializing connection to go-librespot Websocket Jan 27 05:52:57 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 05:52:57 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 05:52:57 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 05:52:57 volumio volumio[13855]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 27 05:52:59 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 05:52:59 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 05:52:59 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 05:52:59 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 66. Jan 27 05:52:59 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 05:53:00 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 05:53:00 volumio go-librespot[14185]: go-librespot daemon starting... Jan 27 05:53:00 volumio go-librespot[14186]: time="2026-01-27T05:53:00+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 05:53:00 volumio go-librespot[14186]: time="2026-01-27T05:53:00+07:00" level=debug msg="app state loaded" Jan 27 05:53:00 volumio go-librespot[14186]: time="2026-01-27T05:53:00+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 05:53:00 volumio volumio[13855]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Jan 27 05:53:00 volumio go-librespot[14186]: time="2026-01-27T05:53:00+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 27 05:53:00 volumio go-librespot[14186]: time="2026-01-27T05:53:00+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 27 05:53:00 volumio go-librespot[14186]: time="2026-01-27T05:53:00+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 27 05:53:00 volumio go-librespot[14186]: time="2026-01-27T05:53:00+07:00" level=info msg="zeroconf server listening on port 34079" Jan 27 05:53:00 volumio volumio[13855]: info: Initializing connection to go-librespot Websocket Jan 27 05:53:00 volumio go-librespot[14186]: time="2026-01-27T05:53:00+07:00" level=debug msg="new websocket client" Jan 27 05:53:00 volumio volumio[13855]: info: Connection to go-librespot Websocket established Jan 27 05:53:01 volumio go-librespot[14186]: time="2026-01-27T05:53:01+07:00" level=debug msg="obtained new client token: AAB1yWOMFtakZ3uMuvkOnWT+JLyDKlHUDouwxSWm4rpAPBW7kMsfsoz0EswnTfCG9tnDLP6ARziSgy12ZD53nAY+et41cdJf9d3mC6eIYGyDlDoHj3GY0VQbJwUBQgezhIVmF5oVbUC33rKPKz4QbyxmnJwN8w7qXU5QDq5veZpo/YP7Y2dTpnc7cnKYl3Oao0+pzFl3wabnx+edpeUojQy6Q899F7Abwe5Ga+8B3iJFUv8eZLGEk2INXVY=" Jan 27 05:53:01 volumio go-librespot[14186]: time="2026-01-27T05:53:01+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 05:53:01 volumio go-librespot[14186]: time="2026-01-27T05:53:01+07:00" level=debug msg="completed keyexchange" Jan 27 05:53:01 volumio go-librespot[14186]: time="2026-01-27T05:53:01+07:00" level=debug msg="completed challenge" Jan 27 05:53:01 volumio go-librespot[14186]: time="2026-01-27T05:53: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 27 05:53:01 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 05:53:01 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 05:53:01 volumio volumio[13855]: info: Connection to go-librespot Websocket closed Jan 27 05:53:01 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 05:53:01 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 05:53:01 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 05:53:03 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 05:53:03 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 05:53:03 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 05:53:04 volumio volumio[13855]: info: Getting Spotify volume Jan 27 05:53:04 volumio volumio[13855]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 27 05:53:04 volumio volumio[13855]: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 27 05:53:04 volumio volumio[13855]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Jan 27 05:53:04 volumio volumio[13855]: errno: -111, Jan 27 05:53:04 volumio volumio[13855]: code: 'ECONNREFUSED', Jan 27 05:53:04 volumio volumio[13855]: syscall: 'connect', Jan 27 05:53:04 volumio volumio[13855]: address: '127.0.0.1', Jan 27 05:53:04 volumio volumio[13855]: port: 9879, Jan 27 05:53:04 volumio volumio[13855]: response: undefined Jan 27 05:53:04 volumio volumio[13855]: } Jan 27 05:53:04 volumio volumio[13855]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 27 05:53:04 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 67. Jan 27 05:53:04 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 05:53:04 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 05:53:04 volumio go-librespot[14220]: go-librespot daemon starting... Jan 27 05:53:04 volumio go-librespot[14221]: time="2026-01-27T05:53:04+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 05:53:04 volumio go-librespot[14221]: time="2026-01-27T05:53:04+07:00" level=debug msg="app state loaded" Jan 27 05:53:04 volumio go-librespot[14221]: time="2026-01-27T05:53:04+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 05:53:05 volumio go-librespot[14221]: time="2026-01-27T05:53: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-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 27 05:53:05 volumio go-librespot[14221]: time="2026-01-27T05:53:05+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 27 05:53:05 volumio go-librespot[14221]: time="2026-01-27T05:53:05+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 27 05:53:05 volumio go-librespot[14221]: time="2026-01-27T05:53:05+07:00" level=info msg="zeroconf server listening on port 38097" Jan 27 05:53:05 volumio go-librespot[14221]: time="2026-01-27T05:53:05+07:00" level=debug msg="obtained new client token: AADuHd51liLBDaGry5zUIi4NxXg1SZZIGsiog88iaWigo3F03Y53ejci5iMWu7/tWzpbTs/ewmeToeyj1ujJj/MWVD2tR1Is0QtgF+fjEurQZBPVIYvQWEElTSaiNasqlu5UjNrCSH4Pl4kMFdeuaZ013GCKbbgIjmnR6niXJ9n+3XOR9bpelYOFdsPZiwbSY0v7o/XoaUZd1XGn4nIQyQYt3u5Ca2gbo4Fbm3hvziO/GaKuVEGUeG+Z/uI=" Jan 27 05:53:05 volumio go-librespot[14221]: time="2026-01-27T05:53:05+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 05:53:05 volumio sudo[14231]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-01-27 05:52' Jan 27 05:53:05 volumio sudo[14231]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 05:53:05 volumio go-librespot[14221]: time="2026-01-27T05:53:05+07:00" level=debug msg="completed keyexchange" Jan 27 05:53:05 volumio go-librespot[14221]: time="2026-01-27T05:53:05+07:00" level=debug msg="completed challenge" Jan 27 05:53:05 volumio go-librespot[14221]: time="2026-01-27T05:53:05+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 27 05:53:05 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 05:53:05 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 05:53:05 volumio sudo[14231]: pam_unix(sudo:session): session closed for user root Jan 27 05:53:05 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 05:53:05 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 05:53:05 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 05:53:05 volumio volumio-remote-updater[628]: [2026-01-27 05:53:05] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Jan 27 05:53:05 volumio volumio-remote-updater[628]: [2026-01-27 05:53:05] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Jan 27 05:53:05 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Jan 27 05:53:05 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Jan 27 05:53:05 volumio systemd[1]: volumio.service: Consumed 1min 2.721s CPU time. Jan 27 05:53:06 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 27 05:53:06 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Jan 27 05:53:06 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 8098. Jan 27 05:53:06 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 27 05:53:06 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Jan 27 05:53:06 volumio systemd[1]: volumio.service: Consumed 1min 2.721s CPU time. Jan 27 05:53:06 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Jan 27 05:53:06 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Jan 27 05:53:07 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 05:53:07 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 05:53:07 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 05:53:08 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 68. Jan 27 05:53:08 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 05:53:08 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 05:53:08 volumio go-librespot[14261]: go-librespot daemon starting... Jan 27 05:53:08 volumio go-librespot[14262]: time="2026-01-27T05:53:08+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 05:53:08 volumio go-librespot[14262]: time="2026-01-27T05:53:08+07:00" level=debug msg="app state loaded" Jan 27 05:53:08 volumio go-librespot[14262]: time="2026-01-27T05:53:08+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 05:53:09 volumio go-librespot[14262]: time="2026-01-27T05:53: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 27 05:53:09 volumio go-librespot[14262]: time="2026-01-27T05:53: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 27 05:53:09 volumio go-librespot[14262]: time="2026-01-27T05:53: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 27 05:53:09 volumio go-librespot[14262]: time="2026-01-27T05:53:09+07:00" level=info msg="zeroconf server listening on port 43489" Jan 27 05:53:09 volumio go-librespot[14262]: time="2026-01-27T05:53:09+07:00" level=debug msg="obtained new client token: AADc8Ye5klB5D/rgb2AtQqV1kh9jcd2OfHOA+v+uo7eI8SbtiZ9pfaYOHCEZP+u6IAIyPguK3Vg9YfUszz6+pa4ACWY5XJ79Mv6bcVmkNAum2Bg6ob/TOqJ+zB++GAcLR42IMFhVPcGXvcuSf4NXS518R16e2EfVd9QUxY9s/4AZO/wUxuTRkD19YYEPQ1aD61zV8Lug0VSCz/6zpVt7ztjTvInlIheJCJyvox2qfmMcwnUrSVoByjjbXS0=" Jan 27 05:53:09 volumio go-librespot[14262]: time="2026-01-27T05:53:09+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 05:53:09 volumio volumio[14246]: info: ------------------------------------------- Jan 27 05:53:09 volumio volumio[14246]: info: ----- Volumio3 ---- Jan 27 05:53:09 volumio volumio[14246]: info: ------------------------------------------- Jan 27 05:53:09 volumio volumio[14246]: info: ----- System startup ---- Jan 27 05:53:09 volumio volumio[14246]: info: ------------------------------------------- Jan 27 05:53:09 volumio go-librespot[14262]: time="2026-01-27T05:53:09+07:00" level=debug msg="completed keyexchange" Jan 27 05:53:09 volumio go-librespot[14262]: time="2026-01-27T05:53:09+07:00" level=debug msg="completed challenge" Jan 27 05:53:09 volumio go-librespot[14262]: time="2026-01-27T05:53:09+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 27 05:53:09 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 05:53:09 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 05:53:09 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 05:53:09 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 05:53:09 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 05:53:10 volumio volumio-remote-updater[628]: [2026-01-27 05:53:10] [connect] Successful connection Jan 27 05:53:11 volumio volumio[14246]: info: MYVOLUMIO Environment detected Jan 27 05:53:11 volumio volumio[14246]: info: Plugin folders cleanup Jan 27 05:53:11 volumio volumio[14246]: info: Scanning into folder /volumio/app/plugins/ Jan 27 05:53:11 volumio volumio[14246]: info: Scanning category audio_interface Jan 27 05:53:11 volumio volumio[14246]: info: Scanning category miscellanea Jan 27 05:53:11 volumio volumio[14246]: info: Scanning category music_service Jan 27 05:53:11 volumio volumio[14246]: info: Scanning category plugins.json Jan 27 05:53:11 volumio volumio[14246]: info: Scanning category system_controller Jan 27 05:53:11 volumio volumio[14246]: info: Scanning category user_interface Jan 27 05:53:11 volumio volumio[14246]: info: Scanning into folder /data/plugins/ Jan 27 05:53:11 volumio volumio[14246]: info: Scanning category music_service Jan 27 05:53:11 volumio volumio[14246]: info: Plugin folders cleanup completed Jan 27 05:53:11 volumio volumio[14246]: info: ------------------------------------------- Jan 27 05:53:11 volumio volumio[14246]: info: ----- Core plugins startup ---- Jan 27 05:53:11 volumio volumio[14246]: info: ------------------------------------------- Jan 27 05:53:11 volumio volumio[14246]: info: Loading plugins from folder /volumio/app/plugins/ Jan 27 05:53:11 volumio volumio[14246]: info: Adding plugin upnp to MyMusic Plugins Jan 27 05:53:11 volumio volumio[14246]: info: Adding plugin airplay_emulation to MyMusic Plugins Jan 27 05:53:11 volumio volumio[14246]: info: Adding plugin upnp_browser to MyMusic Plugins Jan 27 05:53:11 volumio volumio[14246]: info: Loading plugins from folder /data/plugins/ Jan 27 05:53:11 volumio volumio[14246]: info: Loading plugin "system"... Jan 27 05:53:11 volumio volumio[14246]: info: Loading plugin "appearance"... Jan 27 05:53:11 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 05:53:11 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 05:53:11 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 05:53:12 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 69. Jan 27 05:53:12 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 05:53:13 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 05:53:13 volumio go-librespot[14283]: go-librespot daemon starting... Jan 27 05:53:13 volumio go-librespot[14284]: time="2026-01-27T05:53:13+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 05:53:13 volumio go-librespot[14284]: time="2026-01-27T05:53:13+07:00" level=debug msg="app state loaded" Jan 27 05:53:13 volumio go-librespot[14284]: time="2026-01-27T05:53:13+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 05:53:13 volumio volumio[14246]: info: Loading plugin "network"... Jan 27 05:53:13 volumio volumio[14246]: info: Refreshing Cached IP Addresses Jan 27 05:53:13 volumio sudo[14291]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 27 05:53:13 volumio sudo[14291]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 05:53:13 volumio sudo[14291]: pam_unix(sudo:session): session closed for user root Jan 27 05:53:13 volumio sudo[14293]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 27 05:53:13 volumio sudo[14293]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 05:53:13 volumio sudo[14293]: pam_unix(sudo:session): session closed for user root Jan 27 05:53:13 volumio volumio[14246]: info: Loading plugin "services"... Jan 27 05:53:13 volumio volumio[14246]: info: Loading plugin "alsa_controller"... Jan 27 05:53:13 volumio sudo[14302]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Jan 27 05:53:13 volumio sudo[14302]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 05:53:13 volumio volumio[14246]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 27 05:53:13 volumio volumio[14246]: info: Loading plugin "wizard"... Jan 27 05:53:13 volumio volumio[14246]: info: Loading plugin "networkfs"... Jan 27 05:53:13 volumio volumio[14246]: info: Starting Udev Watcher for removable devices Jan 27 05:53:13 volumio volumio[14246]: info: Ignoring mount for partition: boot Jan 27 05:53:13 volumio volumio[14246]: info: Ignoring mount for partition: volumio Jan 27 05:53:13 volumio volumio[14246]: info: Ignoring mount for partition: volumio_data Jan 27 05:53:13 volumio volumio[14246]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 27 05:53:13 volumio volumio[14246]: info: Loading plugin "volumio_command_line_client"... Jan 27 05:53:13 volumio go-librespot[14284]: time="2026-01-27T05:53:13+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 27 05:53:13 volumio go-librespot[14284]: time="2026-01-27T05:53:13+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Jan 27 05:53:13 volumio go-librespot[14284]: time="2026-01-27T05:53:13+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Jan 27 05:53:13 volumio volumio[14246]: info: Loading plugin "upnp"... Jan 27 05:53:13 volumio volumio[14246]: info: [1769467993733] Starting Upmpd Daemon Jan 27 05:53:13 volumio volumio[14246]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 27 05:53:13 volumio volumio[14246]: info: Loading plugin "my_music"... Jan 27 05:53:13 volumio volumio[14246]: info: Loading plugin "mpd"... Jan 27 05:53:13 volumio go-librespot[14284]: time="2026-01-27T05:53:13+07:00" level=info msg="zeroconf server listening on port 36113" Jan 27 05:53:13 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 05:53:13 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 05:53:13 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 05:53:13 volumio go-librespot[14284]: time="2026-01-27T05:53:13+07:00" level=debug msg="obtained new client token: AAALGUY7evVjyAwT3THpexb2f2CtGU3twpxjE3NZArhPSblT+f1/31IleFs6cTkDEtn52a7gYUNhCmPjCCv0L3IyNyYefJFLprLIw11/zZuS2q1v4xf84yP8KeylhJHj876hYlFcKn98VcFk1qJtxeeXtrOwcu1HxYp+elwtQ34SuTvdXVktam/sPYdclSSZ+GALwQJrgay90nxwuH3LBDcgw0VnGuE+qN33/jFrJaY11FbY0rUy1A0kdTw=" Jan 27 05:53:14 volumio go-librespot[14284]: time="2026-01-27T05:53:14+07:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:4070, retrying with a different AP" error="dial tcp 104.199.241.202:4070: connect: connection refused" Jan 27 05:53:14 volumio go-librespot[14284]: time="2026-01-27T05:53:14+07:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:443, retrying with a different AP" error="dial tcp 104.199.241.202:443: connect: connection refused" Jan 27 05:53:14 volumio go-librespot[14284]: time="2026-01-27T05:53:14+07:00" level=debug msg="connected to ap-gae2.spotify.com:80" Jan 27 05:53:14 volumio go-librespot[14284]: time="2026-01-27T05:53:14+07:00" level=debug msg="completed keyexchange" Jan 27 05:53:14 volumio go-librespot[14284]: time="2026-01-27T05:53:14+07:00" level=debug msg="completed challenge" Jan 27 05:53:14 volumio volumio[14246]: info: Loading plugin "upnp_browser"... Jan 27 05:53:14 volumio go-librespot[14284]: time="2026-01-27T05:53:14+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 27 05:53:14 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 05:53:14 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 05:53:15 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 05:53:15 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 05:53:15 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 05:53:16 volumio sudo[14302]: pam_unix(sudo:session): session closed for user root Jan 27 05:53:17 volumio volumio[14246]: info: Starting UPNP Browser Jan 27 05:53:17 volumio volumio[14246]: info: Loading plugin "alarm-clock"... Jan 27 05:53:17 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 70. Jan 27 05:53:17 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 05:53:17 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 05:53:17 volumio go-librespot[14326]: go-librespot daemon starting... Jan 27 05:53:17 volumio go-librespot[14327]: time="2026-01-27T05:53:17+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 05:53:17 volumio go-librespot[14327]: time="2026-01-27T05:53:17+07:00" level=debug msg="app state loaded" Jan 27 05:53:17 volumio volumio[14246]: info: Loading plugin "airplay_emulation"... Jan 27 05:53:17 volumio go-librespot[14327]: time="2026-01-27T05:53:17+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 05:53:17 volumio volumio[14246]: info: Starting Shairport Sync Jan 27 05:53:17 volumio volumio[14246]: info: Loading plugin "last_100"... Jan 27 05:53:17 volumio volumio[14246]: info: Loading plugin "webradio"... Jan 27 05:53:17 volumio volumio[14246]: info: Loading plugin "i2s_dacs"... Jan 27 05:53:17 volumio volumio[14246]: info: Loading plugin "volumiodiscovery"... Jan 27 05:53:17 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 05:53:17 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 05:53:17 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 05:53:17 volumio volumio[14246]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 27 05:53:17 volumio volumio[14246]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 27 05:53:17 volumio volumio[14246]: *** WARNING *** For more information see Jan 27 05:53:17 volumio volumio[14246]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 27 05:53:17 volumio volumio[14246]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 27 05:53:17 volumio volumio[14246]: *** WARNING *** For more information see Jan 27 05:53:17 volumio node[14246]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 27 05:53:17 volumio node[14246]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 27 05:53:17 volumio node[14246]: *** WARNING *** For more information see Jan 27 05:53:17 volumio node[14246]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 27 05:53:17 volumio node[14246]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 27 05:53:17 volumio node[14246]: *** WARNING *** For more information see Jan 27 05:53:17 volumio volumio[14246]: info: Applying required configuration parameters for plugin volumiodiscovery Jan 27 05:53:18 volumio volumio[14246]: info: Discovery: Started advertising with name: Volumio Jan 27 05:53:18 volumio volumio[14246]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 27 05:53:18 volumio volumio[14246]: info: Loading plugin "spop"... Jan 27 05:53:18 volumio go-librespot[14327]: time="2026-01-27T05:53:18+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 27 05:53:18 volumio go-librespot[14327]: time="2026-01-27T05:53:18+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 27 05:53:18 volumio go-librespot[14327]: time="2026-01-27T05:53:18+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 27 05:53:18 volumio go-librespot[14327]: time="2026-01-27T05:53:18+07:00" level=info msg="zeroconf server listening on port 45461" Jan 27 05:53:18 volumio go-librespot[14327]: time="2026-01-27T05:53:18+07:00" level=debug msg="obtained new client token: AAAuDGbL0OhFmvo5LZC/gIWGmckVphQeu+odde7qQOs0mmmaEH+n6x5pHjjeXxp/3yQNuhsFqIbgzAlaCMp89NMhu1ZJYC7kdy2gFF4o0yLSluOz7UqTzjnw11pgv1LbVYPm05eey64bMLQuVH+DdJvAdzBlysjq6+xyRCDQV1qApHP/8UVwVU9CYHQ+95RFgncYcFVSs7N2RHx221iDdA1/NNYMrx55hg175qD9xFecxLrxy3yJhdiudsI=" Jan 27 05:53:18 volumio go-librespot[14327]: time="2026-01-27T05:53:18+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 05:53:18 volumio go-librespot[14327]: time="2026-01-27T05:53:18+07:00" level=debug msg="completed keyexchange" Jan 27 05:53:18 volumio go-librespot[14327]: time="2026-01-27T05:53:18+07:00" level=debug msg="completed challenge" Jan 27 05:53:18 volumio go-librespot[14327]: time="2026-01-27T05:53:18+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 27 05:53:18 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 05:53:18 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 05:53:19 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 05:53:19 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 05:53:19 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 05:53:20 volumio volumio[14246]: info: Loading plugin "ytcr"... Jan 27 05:53:21 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 05:53:21 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 05:53:21 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 05:53:21 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 71. Jan 27 05:53:21 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 05:53:22 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 05:53:22 volumio go-librespot[14338]: go-librespot daemon starting... Jan 27 05:53:22 volumio go-librespot[14339]: time="2026-01-27T05:53:22+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 05:53:22 volumio go-librespot[14339]: time="2026-01-27T05:53:22+07:00" level=debug msg="app state loaded" Jan 27 05:53:22 volumio go-librespot[14339]: time="2026-01-27T05:53:22+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 05:53:22 volumio go-librespot[14339]: time="2026-01-27T05:53:22+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 27 05:53:22 volumio go-librespot[14339]: time="2026-01-27T05:53:22+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 27 05:53:22 volumio go-librespot[14339]: time="2026-01-27T05:53:22+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 27 05:53:22 volumio volumio[14246]: info: Loading plugin "ytmusic"... Jan 27 05:53:22 volumio go-librespot[14339]: time="2026-01-27T05:53:22+07:00" level=info msg="zeroconf server listening on port 42793" Jan 27 05:53:22 volumio go-librespot[14339]: time="2026-01-27T05:53:22+07:00" level=debug msg="obtained new client token: AADK+HQThEX/+Qq5FMk21KURxsblLb9vYWt3P2+Ilxby1BHWFQmcXeJdFu29qdEgTXp/nq/ZMRVYGjKXyrQax4Axhrx4LBY3UPNRxZlgDxbeliLGB2G360lJdMXvRkR7gfTd7zN01vYJ+IQfYDk73nmBYA1umJGJc6lg1JKk5bkkcTqzj3XD8N2QSqP+/KuwJkVLoK5IsTSFY3hK17NGgNcAJGvUeA1bANqKEGpLEvJMXVPuV+KLGhoQn8Q=" Jan 27 05:53:23 volumio go-librespot[14339]: time="2026-01-27T05:53:23+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 05:53:23 volumio go-librespot[14339]: time="2026-01-27T05:53:23+07:00" level=debug msg="completed keyexchange" Jan 27 05:53:23 volumio go-librespot[14339]: time="2026-01-27T05:53:23+07:00" level=debug msg="completed challenge" Jan 27 05:53:23 volumio go-librespot[14339]: time="2026-01-27T05:53:23+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 27 05:53:23 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 05:53:23 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 05:53:23 volumio volumio-remote-updater[628]: [2026-01-27 05:53:23] [connect] Successful connection Jan 27 05:53:23 volumio volumio[14246]: info: Loading plugin "outputs"... Jan 27 05:53:23 volumio volumio[14246]: info: Loading plugin "albumart"... Jan 27 05:53:23 volumio volumio[14246]: info: Plugin example_plugin is not enabled Jan 27 05:53:23 volumio volumio[14246]: info: Loading plugin "inputs"... Jan 27 05:53:23 volumio volumio[14246]: info: Loading plugin "updater_comm"... Jan 27 05:53:23 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 05:53:23 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 05:53:23 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 05:53:24 volumio volumio[14246]: info: Plugin mpdemulation is not enabled Jan 27 05:53:24 volumio volumio[14246]: info: Loading plugin "rest_api"... Jan 27 05:53:24 volumio volumio[14246]: info: Loading plugin "websocket"... Jan 27 05:53:24 volumio volumio[14246]: info: Starting Socket.io Server version 1.7.4 Jan 27 05:53:24 volumio volumio[14246]: info: Loading plugin "RoonBridge"... Jan 27 05:53:24 volumio volumio[14246]: info: Applying required configuration parameters for plugin RoonBridge Jan 27 05:53:24 volumio volumio[14246]: info: Loading i18n strings for locale en Jan 27 05:53:24 volumio volumio[14246]: Updating browse sources language Jan 27 05:53:24 volumio volumio[14246]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 27 05:53:24 volumio volumio[14246]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 27 05:53:24 volumio volumio[14246]: info: CoreCommandRouter::initPlayerControls Jan 27 05:53:24 volumio volumio[14246]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 05:53:24 volumio volumio[14246]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 05:53:24 volumio volumio[14246]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 05:53:24 volumio volumio[14246]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 05:53:24 volumio volumio[14246]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 05:53:24 volumio volumio[14246]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 05:53:24 volumio volumio[14246]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 05:53:24 volumio volumio[14246]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 05:53:24 volumio volumio[14246]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 27 05:53:24 volumio volumio[14246]: Express server listening on port 3000 Jan 27 05:53:24 volumio volumio[14246]: [Metrics] WebUI: 16s 82.34ms Jan 27 05:53:24 volumio volumio[14360]: Forking 3 albumart workers Jan 27 05:53:24 volumio volumio[14246]: info: CoreStateMachine::resetVolumioState Jan 27 05:53:24 volumio volumio[14246]: info: CoreStateMachine::getcurrentVolume Jan 27 05:53:24 volumio volumio[14246]: info: CoreCommandRouter::volumioRetrievevolume Jan 27 05:53:25 volumio sudo[14394]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 27 05:53:25 volumio sudo[14394]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 05:53:25 volumio sudo[14394]: pam_unix(sudo:session): session closed for user root Jan 27 05:53:25 volumio sudo[14399]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 27 05:53:25 volumio sudo[14399]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 05:53:25 volumio sudo[14399]: pam_unix(sudo:session): session closed for user root Jan 27 05:53:25 volumio volumio[14246]: info: Volumio Network Manager: Network status updated: 1 Jan 27 05:53:25 volumio volumio[14246]: info: VolumeController:: Volume=100 Mute =false Jan 27 05:53:25 volumio volumio[14246]: info: CoreStateMachine::pushState Jan 27 05:53:25 volumio volumio[14246]: info: CorePlayQueue::getTrack 0 Jan 27 05:53:25 volumio volumio[14246]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 27 05:53:25 volumio volumio[14246]: info: CoreCommandRouter::volumioPushState Jan 27 05:53:25 volumio volumio[14246]: info: CoreStateMachine::updateTrackBlock Jan 27 05:53:25 volumio volumio[14246]: info: CorePlayQueue::getTrackBlock Jan 27 05:53:25 volumio volumio[14246]: info: CoreCommandRouter::volumioRetrievevolume Jan 27 05:53:25 volumio volumio-remote-updater[628]: [2026-01-27 05:53:25] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1769468003 101 Jan 27 05:53:25 volumio volumio[14246]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 1 Jan 27 05:53:25 volumio volumio[14246]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 05:53:25 volumio volumio[14246]: info: Reloading queue from file Jan 27 05:53:25 volumio volumio[14246]: info: CoreStateMachine::setRepeat null single undefined Jan 27 05:53:25 volumio volumio[14246]: info: CoreStateMachine::pushState Jan 27 05:53:25 volumio volumio[14246]: info: CorePlayQueue::getTrack 0 Jan 27 05:53:25 volumio volumio[14246]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 27 05:53:25 volumio volumio[14246]: info: CoreCommandRouter::volumioPushState Jan 27 05:53:25 volumio volumio[14246]: info: CoreStateMachine::setRandom null Jan 27 05:53:25 volumio volumio[14246]: info: CoreStateMachine::pushState Jan 27 05:53:25 volumio volumio[14246]: info: CorePlayQueue::getTrack 0 Jan 27 05:53:25 volumio volumio[14246]: info: CoreCommandRouter::volumioPushState Jan 27 05:53:25 volumio volumio[14246]: info: Setting Device type: Raspberry PI Jan 27 05:53:25 volumio volumio[14246]: info: Completed loading Core Plugins Jan 27 05:53:25 volumio volumio[14246]: info: Preparing to generate the ALSA configuration file Jan 27 05:53:25 volumio volumio[14246]: info: VolumeController:: Volume=100 Mute =false Jan 27 05:53:25 volumio volumio[14246]: info: CoreStateMachine::pushState Jan 27 05:53:25 volumio volumio[14246]: info: CorePlayQueue::getTrack 0 Jan 27 05:53:25 volumio volumio[14246]: info: CoreCommandRouter::volumioPushState Jan 27 05:53:25 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 05:53:25 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 05:53:25 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 05:53:25 volumio volumio[14246]: info: Asound.conf file unchanged, so no further update is needed Jan 27 05:53:25 volumio volumio[14246]: info: Output device has changed, restarting MPD Jan 27 05:53:26 volumio volumio[14246]: info: Output device has changed, restarting Shairport Sync Jan 27 05:53:26 volumio sudo[14421]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Jan 27 05:53:26 volumio volumio[14246]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 05:53:26 volumio volumio[14246]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 05:53:26 volumio sudo[14421]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 05:53:26 volumio sudo[14423]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 27 05:53:26 volumio sudo[14423]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 05:53:26 volumio sudo[14423]: pam_unix(sudo:session): session closed for user root Jan 27 05:53:26 volumio sudo[14425]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 27 05:53:26 volumio sudo[14425]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 05:53:26 volumio volumio[14246]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 27 05:53:26 volumio sudo[14421]: pam_unix(sudo:session): session closed for user root Jan 27 05:53:26 volumio volumio[14246]: info: ___________ START PLUGINS ___________ Jan 27 05:53:26 volumio volumio[14246]: info: ControllerMpd::onStart: Initializing MPD Jan 27 05:53:26 volumio volumio[14246]: info: Creating MPD Configuration file Jan 27 05:53:26 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 72. Jan 27 05:53:26 volumio volumio[14246]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 27 05:53:26 volumio volumio[14246]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 27 05:53:26 volumio volumio[14246]: info: [1769468006273] CoreMusicLibrary::Adding element Media Servers Jan 27 05:53:26 volumio volumio[14246]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 27 05:53:26 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 05:53:26 volumio volumio[14246]: info: UPNP Browser: Client initialized successfully Jan 27 05:53:26 volumio sudo[14434]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 27 05:53:26 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 05:53:26 volumio go-librespot[14437]: go-librespot daemon starting... Jan 27 05:53:26 volumio volumio[14246]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 05:53:26 volumio volumio[14246]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 05:53:26 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Jan 27 05:53:26 volumio sudo[14436]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 27 05:53:26 volumio sudo[14436]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 05:53:26 volumio sudo[14434]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 05:53:26 volumio sudo[14434]: pam_unix(sudo:session): session closed for user root Jan 27 05:53:26 volumio volumio[14246]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 27 05:53:26 volumio volumio[14246]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 05:53:26 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 27 05:53:26 volumio volumio[14246]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 05:53:26 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 27 05:53:26 volumio systemd[1]: mpd.service: Consumed 7.339s CPU time. Jan 27 05:53:26 volumio go-librespot[14438]: time="2026-01-27T05:53:26+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 05:53:26 volumio go-librespot[14438]: time="2026-01-27T05:53:26+07:00" level=debug msg="app state loaded" Jan 27 05:53:26 volumio go-librespot[14438]: time="2026-01-27T05:53:26+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 05:53:26 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 27 05:53:26 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 27 05:53:26 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 27 05:53:26 volumio volumio[14246]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 27 05:53:26 volumio volumio[14246]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 27 05:53:26 volumio volumio[14246]: info: [1769468006611] CoreMusicLibrary::Adding element Last_100 Jan 27 05:53:26 volumio volumio[14246]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 27 05:53:26 volumio volumio[14246]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 27 05:53:26 volumio volumio[14246]: info: [1769468006621] CoreMusicLibrary::Adding element Webradio Jan 27 05:53:26 volumio volumio[14246]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 27 05:53:26 volumio volumio[14246]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 27 05:53:26 volumio volumio[14246]: info: Initializing BBC Radios Jan 27 05:53:26 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 27 05:53:26 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 27 05:53:26 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 27 05:53:26 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 27 05:53:26 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 27 05:53:26 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 27 05:53:26 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 27 05:53:26 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 27 05:53:26 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 27 05:53:26 volumio volumio[14246]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 27 05:53:26 volumio volumio[14246]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 05:53:26 volumio volumio[14246]: info: Creating Spotify config file Jan 27 05:53:26 volumio volumio[14246]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 05:53:27 volumio go-librespot[14438]: time="2026-01-27T05:53: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 27 05:53:27 volumio go-librespot[14438]: time="2026-01-27T05:53:27+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 27 05:53:27 volumio go-librespot[14438]: time="2026-01-27T05:53:27+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 27 05:53:27 volumio sudo[14470]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 27 05:53:27 volumio sudo[14470]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jan 27 05:53:27 volumio sudo[14470]: pam_unix(sudo:session): session closed for user root Jan 27 05:53:27 volumio go-librespot[14438]: time="2026-01-27T05:53:27+07:00" level=info msg="zeroconf server listening on port 35733" Jan 27 05:53:27 volumio go-librespot[14438]: time="2026-01-27T05:53:27+07:00" level=debug msg="obtained new client token: AAAMoNmVXf6Gbu0Xl/Qa/WzUrfmLxhvULmLf7S0L3CStLjKIW3geO0Rqp25L4ZA+k10FUyfHVzYI/rzhABOW6+wS7eb2jhtP08r7vPmCct7C2OJVHDVZIxQazIAZBeoMxTedIxqVDy24XUus1cGZeI+BanE0D70BoAUuMzFeORNakFwOA55eu+Ej1C88JPcJh2EA618JEKgU9s0J2oPY4BCBdX6jA+DFCVDux3kM1L7olwcimEjbhPZlC8g=" Jan 27 05:53:27 volumio go-librespot[14438]: time="2026-01-27T05:53:27+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 05:53:27 volumio go-librespot[14438]: time="2026-01-27T05:53:27+07:00" level=debug msg="completed keyexchange" Jan 27 05:53:27 volumio go-librespot[14438]: time="2026-01-27T05:53:27+07:00" level=debug msg="completed challenge" Jan 27 05:53:27 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 05:53:27 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 05:53:27 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 05:53:27 volumio volumio[14246]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 27 05:53:27 volumio volumio[14246]: info: [1769468007997] CoreMusicLibrary::Adding element YouTube Music Jan 27 05:53:28 volumio go-librespot[14438]: time="2026-01-27T05:53:27+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 27 05:53:28 volumio volumio[14246]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 27 05:53:28 volumio volumio[14246]: Cannot find translation for source YouTube Music Jan 27 05:53:28 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 05:53:28 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 05:53:28 volumio volumio[14246]: info: Volumio Calling Home Jan 27 05:53:28 volumio sudo[14476]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Jan 27 05:53:28 volumio sudo[14476]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 05:53:28 volumio sudo[14476]: pam_unix(sudo:session): session closed for user root Jan 27 05:53:28 volumio volumio[14374]: Starting albumart workers Jan 27 05:53:28 volumio volumio[14246]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Jan 27 05:53:28 volumio volumio[14246]: info: Discovery: Found device Volumio Jan 27 05:53:28 volumio volumio[14376]: Starting albumart workers Jan 27 05:53:28 volumio volumio[14246]: info: CoreCommandRouter::volumioGetState Jan 27 05:53:28 volumio volumio[14246]: info: CorePlayQueue::getTrack 0 Jan 27 05:53:28 volumio volumio[14246]: info: MPD Permissions set Jan 27 05:53:28 volumio volumio[14246]: info: MPD Permissions set Jan 27 05:53:28 volumio volumio[14246]: info: Upmpdcli Daemon Started Jan 27 05:53:28 volumio volumio[14246]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Jan 27 05:53:28 volumio volumio[14246]: info: Discovery: Found device Volumio Jan 27 05:53:28 volumio volumio[14246]: info: CoreCommandRouter::volumioGetState Jan 27 05:53:28 volumio volumio[14246]: info: CorePlayQueue::getTrack 0 Jan 27 05:53:28 volumio volumio[14246]: info: Spotify config file written Jan 27 05:53:28 volumio volumio[14246]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Jan 27 05:53:28 volumio sudo[14482]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jan 27 05:53:28 volumio sudo[14482]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 05:53:28 volumio volumio[14246]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 05:53:28 volumio volumio[14246]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 05:53:28 volumio volumio[14246]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 05:53:28 volumio volumio[14246]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 05:53:28 volumio volumio[14246]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 05:53:28 volumio volumio[14246]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 05:53:28 volumio volumio[14246]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 05:53:28 volumio volumio[14246]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 05:53:29 volumio volumio[14246]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 05:53:29 volumio volumio[14246]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 05:53:29 volumio volumio[14246]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 05:53:29 volumio volumio[14246]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 05:53:29 volumio volumio[14246]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 05:53:29 volumio volumio[14246]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 05:53:29 volumio volumio[14246]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 05:53:29 volumio volumio[14246]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 05:53:29 volumio volumio[14246]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 05:53:29 volumio volumio[14246]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 05:53:29 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 05:53:29 volumio volumio[14246]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 05:53:29 volumio volumio[14246]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 05:53:29 volumio volumio[14246]: info: No need to fix Spotify hosts Jan 27 05:53:29 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 05:53:29 volumio go-librespot[14491]: go-librespot daemon starting... Jan 27 05:53:29 volumio sudo[14482]: pam_unix(sudo:session): session closed for user root Jan 27 05:53:29 volumio go-librespot[14495]: time="2026-01-27T05:53:29+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 05:53:29 volumio go-librespot[14495]: time="2026-01-27T05:53:29+07:00" level=debug msg="app state loaded" Jan 27 05:53:29 volumio go-librespot[14495]: time="2026-01-27T05:53:29+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 05:53:29 volumio volumio[14373]: Starting albumart workers Jan 27 05:53:29 volumio go-librespot[14495]: time="2026-01-27T05:53:29+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 27 05:53:29 volumio go-librespot[14495]: time="2026-01-27T05:53:29+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 27 05:53:29 volumio go-librespot[14495]: time="2026-01-27T05:53:29+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 27 05:53:29 volumio go-librespot[14495]: time="2026-01-27T05:53:29+07:00" level=info msg="zeroconf server listening on port 45733" Jan 27 05:53:29 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 05:53:29 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 05:53:29 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 05:53:30 volumio go-librespot[14495]: time="2026-01-27T05:53:30+07:00" level=debug msg="obtained new client token: AADjODmsFNwcN/7h3oaYRD6Or3rpcZoHrnhEkdfm7OMpixaEVnBQzMBhKIDJT+IIpXAEN3MaYZoHYHAfjExhhx8o1l+YDg2a6SwhPAGtTEOjATCUyJM/4kUV+ZjX90ECjIAxihOIzErt7yFWQpngDjOWUs5HyZUp1NtpFdtFeKQqhcI1FYp2tHTO3fctYvKlCco+sFczcdQDbPL3MM73DK7/TrbOFWAC4YJS5EXLglkl3UZoUOSKTZ6L" Jan 27 05:53:30 volumio go-librespot[14495]: time="2026-01-27T05:53:30+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 05:53:30 volumio go-librespot[14495]: time="2026-01-27T05:53:30+07:00" level=debug msg="completed keyexchange" Jan 27 05:53:30 volumio go-librespot[14495]: time="2026-01-27T05:53:30+07:00" level=debug msg="completed challenge" Jan 27 05:53:30 volumio go-librespot[14495]: time="2026-01-27T05:53:30+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 27 05:53:30 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 05:53:30 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 05:53:30 volumio volumio[14246]: info: Volumio called home Jan 27 05:53:30 volumio volumio[14246]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 27 05:53:30 volumio volumio[14246]: SPOTIFY: BQDGezd8s2Su855Hp3Yz7-XVqhUrO7QddTOFFuJJTB7Vezu_3hBEWNc9Kt63r5xD85bCS-YQS4EwmT1bkmufv3WvzdCTVC31fcx7zaD6qOHv6YsUQPUriW7RE4c9d2fw2PLw2ydrVUxm8G0lAXLwcizRpCb6-1uZf6vE0-8X8Vx66QIzlKx1hOIT6oCZYtaxcqh5TCFthIL489BK9GChPv8GAoHzihoTbNiKoL7NhAr1qPEipS0l6O12hwu7JAPRnqCvV3EohJPzJ3afwHjaapusgXxjW71fnS1P5Q7DJ5yRWzbt3DuhKXJM Jan 27 05:53:30 volumio volumio[14246]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 27 05:53:30 volumio volumio[14246]: info: New Spotify access token = BQDGezd8s2Su855Hp3Yz7-XVqhUrO7QddTOFFuJJTB7Vezu_3hBEWNc9Kt63r5xD85bCS-YQS4EwmT1bkmufv3WvzdCTVC31fcx7zaD6qOHv6YsUQPUriW7RE4c9d2fw2PLw2ydrVUxm8G0lAXLwcizRpCb6-1uZf6vE0-8X8Vx66QIzlKx1hOIT6oCZYtaxcqh5TCFthIL489BK9GChPv8GAoHzihoTbNiKoL7NhAr1qPEipS0l6O12hwu7JAPRnqCvV3EohJPzJ3afwHjaapusgXxjW71fnS1P5Q7DJ5yRWzbt3DuhKXJM Jan 27 05:53:30 volumio volumio[14246]: info: Spotify credentials grant success - running version from March 24, 2019 Jan 27 05:53:31 volumio volumio[14246]: info: Starting Shairport Sync Jan 27 05:53:31 volumio volumio[14246]: info: Starting Shairport Sync Jan 27 05:53:31 volumio volumio[14246]: info: Starting Shairport Sync Jan 27 05:53:31 volumio sudo[14510]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 27 05:53:31 volumio sudo[14510]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 05:53:31 volumio sudo[14513]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 27 05:53:31 volumio sudo[14513]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 05:53:31 volumio sudo[14515]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 27 05:53:31 volumio sudo[14515]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 05:53:31 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 27 05:53:31 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Jan 27 05:53:31 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 27 05:53:31 volumio systemd[1]: shairport-sync.service: Consumed 2.355s CPU time. Jan 27 05:53:31 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 27 05:53:31 volumio sudo[14510]: pam_unix(sudo:session): session closed for user root Jan 27 05:53:31 volumio sudo[14513]: pam_unix(sudo:session): session closed for user root Jan 27 05:53:31 volumio sudo[14515]: pam_unix(sudo:session): session closed for user root Jan 27 05:53:31 volumio volumio[14246]: info: Shairport-Sync Started Jan 27 05:53:31 volumio volumio[14246]: Error adding Membership: Error: addMembership EINVAL Jan 27 05:53:31 volumio volumio[14246]: info: Shairport-Sync Started Jan 27 05:53:31 volumio volumio[14246]: info: Shairport-Sync Started Jan 27 05:53:31 volumio volumio[14246]: info: CoreCommandRouter::volumioGetState Jan 27 05:53:31 volumio volumio[14246]: info: CorePlayQueue::getTrack 0 Jan 27 05:53:31 volumio volumio[14246]: SPOTIFY: User informations: {"country":"PK","display_name":"215mmgea6kss3jxeqsqdquvji","email":"linh.ngotran@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/215mmgea6kss3jxeqsqdquvji"},"followers":{"href":null,"total":1},"href":"https://api.spotify.com/v1/users/215mmgea6kss3jxeqsqdquvji","id":"215mmgea6kss3jxeqsqdquvji","images":[],"product":"premium","type":"user","uri":"spotify:user:215mmgea6kss3jxeqsqdquvji"} Jan 27 05:53:31 volumio volumio[14246]: info: Spotify Successfully logged in Jan 27 05:53:31 volumio volumio[14246]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 27 05:53:31 volumio volumio[14246]: info: [1769468011889] CoreMusicLibrary::Adding element Spotify Jan 27 05:53:31 volumio volumio[14246]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 27 05:53:31 volumio volumio[14246]: Cannot find translation for source YouTube Music Jan 27 05:53:31 volumio volumio[14246]: Cannot find translation for source Spotify Jan 27 05:53:31 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 05:53:31 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 05:53:31 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 05:53:32 volumio volumio[14246]: info: [yt-cast-receiver] DIAL server listening on port 8098 Jan 27 05:53:32 volumio volumio[14246]: info: CoreCommandRouter::volumioRetrievevolume Jan 27 05:53:33 volumio volumio[14246]: info: VolumeController:: Volume=100 Mute =false Jan 27 05:53:33 volumio volumio[14246]: info: CoreCommandRouter::volumioGetState Jan 27 05:53:33 volumio volumio[14246]: info: CorePlayQueue::getTrack 0 Jan 27 05:53:33 volumio volumio[14246]: info: CoreStateMachine::pushState Jan 27 05:53:33 volumio volumio[14246]: info: CorePlayQueue::getTrack 0 Jan 27 05:53:33 volumio volumio[14246]: info: CoreCommandRouter::volumioPushState Jan 27 05:53:33 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 73. Jan 27 05:53:33 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 05:53:33 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 05:53:33 volumio go-librespot[14547]: go-librespot daemon starting... Jan 27 05:53:33 volumio go-librespot[14552]: time="2026-01-27T05:53:33+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 05:53:33 volumio go-librespot[14552]: time="2026-01-27T05:53:33+07:00" level=debug msg="app state loaded" Jan 27 05:53:33 volumio go-librespot[14552]: time="2026-01-27T05:53:33+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 05:53:33 volumio volumio[14246]: info: go-librespot daemon successfully initialized Jan 27 05:53:33 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 05:53:33 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 05:53:33 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 05:53:34 volumio go-librespot[14552]: time="2026-01-27T05:53:34+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 27 05:53:34 volumio go-librespot[14552]: time="2026-01-27T05:53:34+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Jan 27 05:53:34 volumio go-librespot[14552]: time="2026-01-27T05:53:34+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Jan 27 05:53:34 volumio go-librespot[14552]: time="2026-01-27T05:53:34+07:00" level=info msg="zeroconf server listening on port 42185" Jan 27 05:53:34 volumio go-librespot[14552]: time="2026-01-27T05:53:34+07:00" level=debug msg="obtained new client token: AAC6JcM9mkInSr4NsQnp5VHhCfq3S2uddDjK5GzKC/iPBTsvgZKNy1LykD/JCHOH+I54I0Y/Sjlh27C+Dnk2nZ2m+WQ1Aayc0sv6t95sStT/haQWFQMDA4PjvVICQJqXBPSLJwiGtXYNPDhQh5bs/UWyCwINrnHPYZ2Ig3OaYj/+kqxaztQRw0mnMbCC57MBwO5y+BNfoy+477v5WJrPo+ueNspLaUEaHmuCXXI/W5TnZYSKwMeIN2Rhx4w=" Jan 27 05:53:34 volumio go-librespot[14552]: time="2026-01-27T05:53:34+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 05:53:34 volumio mpd[14474]: 2026-01-27T05:53:34 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 27 05:53:34 volumio systemd[1]: Started mpd.service - Music Player Daemon. Jan 27 05:53:34 volumio sudo[14425]: pam_unix(sudo:session): session closed for user root Jan 27 05:53:34 volumio sudo[14436]: pam_unix(sudo:session): session closed for user root Jan 27 05:53:34 volumio go-librespot[14552]: time="2026-01-27T05:53:34+07:00" level=debug msg="completed keyexchange" Jan 27 05:53:34 volumio go-librespot[14552]: time="2026-01-27T05:53:34+07:00" level=debug msg="completed challenge" Jan 27 05:53:34 volumio go-librespot[14552]: time="2026-01-27T05:53:34+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 27 05:53:34 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 05:53:34 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 05:53:34 volumio volumio[14246]: error: MPD error: The expression evaluated to a falsy value: Jan 27 05:53:34 volumio volumio[14246]: assert.ok(self.idling) Jan 27 05:53:34 volumio volumio[14246]: error: The expression evaluated to a falsy value: Jan 27 05:53:34 volumio volumio[14246]: assert.ok(self.idling) Jan 27 05:53:34 volumio volumio[14246]: error: updateQueue error: null Jan 27 05:53:35 volumio volumio[14246]: info: MPD running with PID14474 Jan 27 05:53:35 volumio volumio[14246]: ,establishing connection Jan 27 05:53:35 volumio volumio[14246]: info: Completed starting Core Plugins Jan 27 05:53:35 volumio volumio[14246]: info: ------------------------------------------- Jan 27 05:53:35 volumio volumio[14246]: info: ----- MyVolumio plugins startup ---- Jan 27 05:53:35 volumio volumio[14246]: info: ------------------------------------------- Jan 27 05:53:35 volumio volumio[14246]: info: [MyVolumio PluginManager] Fetching plans data.... Jan 27 05:53:35 volumio volumio[14246]: error: updateQueue error: null Jan 27 05:53:35 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 05:53:35 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 05:53:35 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 05:53:36 volumio volumio[14246]: info: Initializing connection to go-librespot Websocket Jan 27 05:53:36 volumio volumio[14246]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 27 05:53:37 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 05:53:37 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 05:53:37 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 05:53:37 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 74. Jan 27 05:53:37 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 05:53:38 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 05:53:38 volumio go-librespot[14575]: go-librespot daemon starting... Jan 27 05:53:38 volumio go-librespot[14576]: time="2026-01-27T05:53:38+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 05:53:38 volumio go-librespot[14576]: time="2026-01-27T05:53:38+07:00" level=debug msg="app state loaded" Jan 27 05:53:38 volumio go-librespot[14576]: time="2026-01-27T05:53:38+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 05:53:38 volumio go-librespot[14576]: time="2026-01-27T05:53:38+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 27 05:53:38 volumio go-librespot[14576]: time="2026-01-27T05:53:38+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 27 05:53:38 volumio go-librespot[14576]: time="2026-01-27T05:53:38+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 27 05:53:38 volumio go-librespot[14576]: time="2026-01-27T05:53:38+07:00" level=info msg="zeroconf server listening on port 39111" Jan 27 05:53:38 volumio go-librespot[14576]: time="2026-01-27T05:53:38+07:00" level=debug msg="obtained new client token: AABjvrdo5OWgZd4629xVHLRRln48d9KcsoVuweuJ4Q5kfkaDS0SFLTeTT6RLOeHUC+aEwRoFDL/AS53xKYxwfdIXWnH87RC1XMeDS7WZ33caozip7smjikkEPpxSUb8m+znjR1q1X3iID+LIoaaPwfFaMH+yMuWWT1bDtZ0GcSs8Ti6PlxC0/47HgxiVaOpvCSorAQnRujw3n9aAbwiY/spIlufZPp0DRf/pYboL7CiOdsxlFD4rFkJ7RRU=" Jan 27 05:53:39 volumio go-librespot[14576]: time="2026-01-27T05:53:39+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 05:53:39 volumio go-librespot[14576]: time="2026-01-27T05:53:39+07:00" level=debug msg="completed keyexchange" Jan 27 05:53:39 volumio go-librespot[14576]: time="2026-01-27T05:53:39+07:00" level=debug msg="completed challenge" Jan 27 05:53:39 volumio go-librespot[14576]: time="2026-01-27T05:53:39+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 27 05:53:39 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 05:53:39 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 05:53:39 volumio volumio[14246]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Jan 27 05:53:39 volumio volumio[14246]: info: Initializing connection to go-librespot Websocket Jan 27 05:53:39 volumio volumio[14246]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 27 05:53:39 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 05:53:39 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 05:53:39 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 05:53:41 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 05:53:41 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 05:53:41 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 05:53:42 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 75. Jan 27 05:53:42 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 05:53:42 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 05:53:42 volumio go-librespot[14583]: go-librespot daemon starting... Jan 27 05:53:42 volumio go-librespot[14584]: time="2026-01-27T05:53:42+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 05:53:42 volumio go-librespot[14584]: time="2026-01-27T05:53:42+07:00" level=debug msg="app state loaded" Jan 27 05:53:42 volumio go-librespot[14584]: time="2026-01-27T05:53:42+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 05:53:42 volumio volumio[14246]: info: Initializing connection to go-librespot Websocket Jan 27 05:53:42 volumio go-librespot[14584]: time="2026-01-27T05:53:42+07:00" level=debug msg="new websocket client" Jan 27 05:53:42 volumio volumio[14246]: info: Connection to go-librespot Websocket established Jan 27 05:53:43 volumio go-librespot[14584]: time="2026-01-27T05:53:43+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 27 05:53:43 volumio go-librespot[14584]: time="2026-01-27T05:53:43+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 27 05:53:43 volumio go-librespot[14584]: time="2026-01-27T05:53:43+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 27 05:53:43 volumio go-librespot[14584]: time="2026-01-27T05:53:43+07:00" level=info msg="zeroconf server listening on port 36465" Jan 27 05:53:43 volumio go-librespot[14584]: time="2026-01-27T05:53:43+07:00" level=debug msg="obtained new client token: AAA0Jq15OuM3fkHjXZsgfGJhI92E/vFZDo8TRhCQAZA7G0/yrXgDfghHqvMLAiTgke4hf5MbLxcOGj5mw+Tb85HXDjz0vSWc6EW6WesjmyeW+EXiDp/kGQ9xRl3GOZ+6PPQG86Pqr+Wa9ThgygIFjv1eZw8qZe2GSZz5TKFodjoNpAkqEut8TkKCbZ29JeV1noqWGFYWXwBtVYI85dY6+GiZFc7gQ/htIEAdRaGmcA0oyaHvAZjoYlX3tvE=" Jan 27 05:53:43 volumio go-librespot[14584]: time="2026-01-27T05:53:43+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 05:53:43 volumio go-librespot[14584]: time="2026-01-27T05:53:43+07:00" level=debug msg="completed keyexchange" Jan 27 05:53:43 volumio go-librespot[14584]: time="2026-01-27T05:53:43+07:00" level=debug msg="completed challenge" Jan 27 05:53:43 volumio go-librespot[14584]: time="2026-01-27T05:53:43+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 27 05:53:43 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 05:53:43 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 05:53:43 volumio volumio[14246]: info: Connection to go-librespot Websocket closed Jan 27 05:53:43 volumio volumio[14246]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Jan 27 05:53:43 volumio volumio[14246]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Jan 27 05:53:43 volumio volumio[14246]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Jan 27 05:53:43 volumio volumio[14246]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Jan 27 05:53:43 volumio volumio[14246]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Jan 27 05:53:43 volumio volumio[14246]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Jan 27 05:53:43 volumio volumio[14246]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Jan 27 05:53:43 volumio volumio[14246]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Jan 27 05:53:43 volumio volumio[14246]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Jan 27 05:53:43 volumio volumio[14246]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Jan 27 05:53:43 volumio volumio[14246]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Jan 27 05:53:43 volumio volumio[14246]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Jan 27 05:53:43 volumio volumio[14246]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Jan 27 05:53:43 volumio volumio[14246]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Jan 27 05:53:43 volumio volumio[14246]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Jan 27 05:53:43 volumio volumio[14246]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Jan 27 05:53:43 volumio volumio[14246]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Jan 27 05:53:43 volumio volumio[14246]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Jan 27 05:53:43 volumio volumio[14246]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Jan 27 05:53:43 volumio volumio[14246]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Jan 27 05:53:43 volumio volumio[14246]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Jan 27 05:53:43 volumio volumio[14246]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Jan 27 05:53:43 volumio volumio[14246]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Jan 27 05:53:43 volumio volumio[14246]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Jan 27 05:53:43 volumio volumio[14246]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Jan 27 05:53:43 volumio volumio[14246]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Jan 27 05:53:43 volumio volumio[14246]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Jan 27 05:53:43 volumio volumio[14246]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Jan 27 05:53:43 volumio volumio[14246]: info: Adding plugin bluetooth to MyMusic Plugins Jan 27 05:53:43 volumio volumio[14246]: info: Adding plugin multiroom to MyMusic Plugins Jan 27 05:53:43 volumio volumio[14246]: info: Adding plugin metavolumio to MyMusic Plugins Jan 27 05:53:43 volumio volumio[14246]: info: Adding plugin cd_controller to MyMusic Plugins Jan 27 05:53:43 volumio volumio[14246]: info: Adding plugin qobuzconnect to MyMusic Plugins Jan 27 05:53:43 volumio volumio[14246]: info: Adding plugin smart_inputs to MyMusic Plugins Jan 27 05:53:43 volumio volumio[14246]: info: Adding plugin tidalconnect to MyMusic Plugins Jan 27 05:53:43 volumio volumio[14246]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Jan 27 05:53:43 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 05:53:43 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 05:53:43 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 05:53:45 volumio volumio[14246]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Jan 27 05:53:45 volumio volumio[14246]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Jan 27 05:53:45 volumio volumio[14246]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 05:53:45 volumio volumio[14246]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 05:53:45 volumio volumio[14246]: info: Starting MyVolumio Remote Streaming Endpoints Jan 27 05:53:45 volumio volumio[14246]: info: MyVolumio login type: Token Jan 27 05:53:45 volumio volumio[14246]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Jan 27 05:53:45 volumio volumio[14246]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Jan 27 05:53:45 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 05:53:45 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 05:53:45 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 05:53:46 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 76. Jan 27 05:53:46 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 05:53:47 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 05:53:47 volumio go-librespot[14606]: go-librespot daemon starting... Jan 27 05:53:47 volumio go-librespot[14607]: time="2026-01-27T05:53:47+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 05:53:47 volumio go-librespot[14607]: time="2026-01-27T05:53:47+07:00" level=debug msg="app state loaded" Jan 27 05:53:47 volumio go-librespot[14607]: time="2026-01-27T05:53:47+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 05:53:47 volumio volumio[14246]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Jan 27 05:53:47 volumio volumio[14246]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Jan 27 05:53:47 volumio volumio[14246]: info: Streaming services startup Jan 27 05:53:47 volumio volumio[14246]: info: Starting Streaming Daemon Jan 27 05:53:47 volumio volumio[14246]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Jan 27 05:53:47 volumio sudo[14615]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jan 27 05:53:47 volumio sudo[14615]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 05:53:47 volumio go-librespot[14607]: time="2026-01-27T05:53:47+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 27 05:53:47 volumio go-librespot[14607]: time="2026-01-27T05:53:47+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 27 05:53:47 volumio go-librespot[14607]: time="2026-01-27T05:53:47+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 27 05:53:47 volumio sudo[14615]: pam_unix(sudo:session): session closed for user root Jan 27 05:53:47 volumio go-librespot[14607]: time="2026-01-27T05:53:47+07:00" level=info msg="zeroconf server listening on port 41183" Jan 27 05:53:47 volumio volumio[14246]: info: Getting Spotify volume Jan 27 05:53:47 volumio volumio[14246]: info: Initializing connection to go-librespot Websocket Jan 27 05:53:47 volumio volumio[14246]: error: Cannot start Volumio Streaming Daemon Jan 27 05:53:47 volumio volumio[14246]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Jan 27 05:53:47 volumio volumio[14246]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Jan 27 05:53:47 volumio go-librespot[14607]: time="2026-01-27T05:53:47+07:00" level=debug msg="new websocket client" Jan 27 05:53:47 volumio volumio[14246]: info: Connection to go-librespot Websocket established Jan 27 05:53:47 volumio volumio[14246]: 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 27 05:53:47 volumio go-librespot[14607]: time="2026-01-27T05:53:47+07:00" level=debug msg="obtained new client token: AAC6m4ESQAvLnBLRG6IegyscFD+OhYf2oafdTSGAHzQ4A3dCFMdAMEygFMQ08dbQj9x7Q7M/DO1v03FFrEzcAKRJXuq/GERlsxwBqL3Tp19ePlkUHlHnwVXRpXU86gr9h/Dq4n/0R+SXS/L21k46xthrMAVVgq64TU0ryThVoigI/BiuqB9y4/Mc9QfrcEaQbPNu6JenaOrmdboXc/GJh9zS4gy9KbgDIpYySIGeQzvk21u44snzC4Jmsbk=" Jan 27 05:53:47 volumio go-librespot[14607]: time="2026-01-27T05:53:47+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 05:53:47 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 05:53:47 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 05:53:47 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 05:53:48 volumio go-librespot[14607]: time="2026-01-27T05:53:48+07:00" level=debug msg="completed keyexchange" Jan 27 05:53:48 volumio go-librespot[14607]: time="2026-01-27T05:53:48+07:00" level=debug msg="completed challenge" Jan 27 05:53:48 volumio volumio[14246]: info: CoreCommandRouter::volumioGetState Jan 27 05:53:48 volumio volumio[14246]: info: CorePlayQueue::getTrack 0 Jan 27 05:53:48 volumio volumio[14246]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jan 27 05:53:48 volumio volumio[14246]: SPOTIFY: SPOTIFY VOLUME undefined Jan 27 05:53:48 volumio volumio[14246]: SPOTIFY: VOLUMIO VOLUME 100 Jan 27 05:53:48 volumio go-librespot[14607]: time="2026-01-27T05:53:48+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 27 05:53:48 volumio volumio[14246]: info: Aligning Spotify Volume to Volumio Volume Jan 27 05:53:48 volumio volumio[14246]: info: CoreCommandRouter::volumioGetState Jan 27 05:53:48 volumio volumio[14246]: info: CorePlayQueue::getTrack 0 Jan 27 05:53:48 volumio volumio[14246]: info: Setting Spotify Volume from Volumio: 100 Jan 27 05:53:48 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 05:53:48 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 05:53:48 volumio volumio[14246]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 27 05:53:48 volumio volumio[14246]: Error: socket hang up Jan 27 05:53:48 volumio volumio[14246]: at connResetException (node:internal/errors:720:14) Jan 27 05:53:48 volumio volumio[14246]: at Socket.socketOnEnd (node:_http_client:519:23) Jan 27 05:53:48 volumio volumio[14246]: at Socket.emit (node:events:526:35) Jan 27 05:53:48 volumio volumio[14246]: at endReadableNT (node:internal/streams/readable:1376:12) Jan 27 05:53:48 volumio volumio[14246]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Jan 27 05:53:48 volumio volumio[14246]: code: 'ECONNRESET', Jan 27 05:53:48 volumio volumio[14246]: response: undefined Jan 27 05:53:48 volumio volumio[14246]: } Jan 27 05:53:48 volumio volumio[14246]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 27 05:53:49 volumio sudo[14635]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-01-27 05:52' Jan 27 05:53:49 volumio sudo[14635]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 05:53:49 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 05:53:49 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 05:53:49 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 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"