Jan 28 23:32:00 volumio volumio[5308]: info: VolumeController:: Volume=100 Mute =false Jan 28 23:32:00 volumio volumio[5308]: info: CoreCommandRouter::volumioGetState Jan 28 23:32:00 volumio volumio[5308]: info: CorePlayQueue::getTrack 0 Jan 28 23:32:00 volumio volumio[5308]: info: CoreStateMachine::pushState Jan 28 23:32:00 volumio volumio[5308]: info: CorePlayQueue::getTrack 0 Jan 28 23:32:00 volumio volumio[5308]: info: CoreCommandRouter::volumioPushState Jan 28 23:32:01 volumio volumio[5308]: info: go-librespot daemon successfully initialized Jan 28 23:32:01 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Jan 28 23:32:01 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 23:32:01 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 23:32:01 volumio go-librespot[5629]: go-librespot daemon starting... Jan 28 23:32:01 volumio go-librespot[5630]: time="2026-01-28T23:32:01+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 23:32:01 volumio go-librespot[5630]: time="2026-01-28T23:32:01+07:00" level=debug msg="app state loaded" Jan 28 23:32:01 volumio go-librespot[5630]: time="2026-01-28T23:32:01+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 23:32:01 volumio mpd[5541]: 2026-01-28T23:32:01 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 28 23:32:01 volumio systemd[1]: Started mpd.service - Music Player Daemon. Jan 28 23:32:01 volumio sudo[5493]: pam_unix(sudo:session): session closed for user root Jan 28 23:32:01 volumio sudo[5510]: pam_unix(sudo:session): session closed for user root Jan 28 23:32:01 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 23:32:01 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 23:32:01 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 23:32:01 volumio volumio[5308]: error: MPD error: The expression evaluated to a falsy value: Jan 28 23:32:01 volumio volumio[5308]: assert.ok(self.idling) Jan 28 23:32:01 volumio volumio[5308]: error: The expression evaluated to a falsy value: Jan 28 23:32:01 volumio volumio[5308]: assert.ok(self.idling) Jan 28 23:32:01 volumio go-librespot[5630]: time="2026-01-28T23:32:01+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 23:32:01 volumio go-librespot[5630]: time="2026-01-28T23:32:01+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 28 23:32:01 volumio go-librespot[5630]: time="2026-01-28T23:32:01+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 28 23:32:01 volumio volumio[5308]: info: MPD running with PID5541 Jan 28 23:32:01 volumio volumio[5308]: ,establishing connection Jan 28 23:32:01 volumio volumio[5308]: error: updateQueue error: null Jan 28 23:32:01 volumio go-librespot[5630]: time="2026-01-28T23:32:01+07:00" level=info msg="zeroconf server listening on port 41455" Jan 28 23:32:02 volumio volumio[5308]: info: Completed starting Core Plugins Jan 28 23:32:02 volumio volumio[5308]: info: ------------------------------------------- Jan 28 23:32:02 volumio volumio[5308]: info: ----- MyVolumio plugins startup ---- Jan 28 23:32:02 volumio volumio[5308]: info: ------------------------------------------- Jan 28 23:32:02 volumio volumio[5308]: info: [MyVolumio PluginManager] Fetching plans data.... Jan 28 23:32:02 volumio volumio[5308]: error: updateQueue error: null Jan 28 23:32:02 volumio go-librespot[5630]: time="2026-01-28T23:32:02+07:00" level=debug msg="obtained new client token: AACrU5kubEWvU2iiXqLdWfsDc2iuN1F5IAYJF2GveiSU6vKAczgBNwkSqwOVAErPXVNp7x5bWj6Mx9q5gS1HJbVbedQCasvu8AogAWW5BUX3CGnBbi9oTxunjn7+sL2jZQ4ODT+/ZV4fOPAQ9Fpi9uEL5TnCYZRlOl9FvL3Js18ZVW6AbX2558jiv5JyoLoRf/CmF5/7nnN+/o1VM7VDtXB3gs/WEWIKo/XuPRSpLnukywI27EdBsXXP" Jan 28 23:32:02 volumio go-librespot[5630]: time="2026-01-28T23:32:02+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 23:32:02 volumio go-librespot[5630]: time="2026-01-28T23:32:02+07:00" level=debug msg="completed keyexchange" Jan 28 23:32:02 volumio go-librespot[5630]: time="2026-01-28T23:32:02+07:00" level=debug msg="completed challenge" Jan 28 23:32:02 volumio go-librespot[5630]: time="2026-01-28T23:32:02+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 23:32:02 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 23:32:02 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 23:32:03 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 23:32:03 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 23:32:03 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 23:32:04 volumio volumio[5308]: info: Initializing connection to go-librespot Websocket Jan 28 23:32:04 volumio volumio[5308]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 28 23:32:05 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Jan 28 23:32:05 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 23:32:05 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 23:32:05 volumio go-librespot[5642]: go-librespot daemon starting... Jan 28 23:32:05 volumio go-librespot[5643]: time="2026-01-28T23:32:05+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 23:32:05 volumio go-librespot[5643]: time="2026-01-28T23:32:05+07:00" level=debug msg="app state loaded" Jan 28 23:32:05 volumio go-librespot[5643]: time="2026-01-28T23:32:05+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 23:32:05 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 23:32:05 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 23:32:05 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 23:32:06 volumio go-librespot[5643]: time="2026-01-28T23:32:06+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 28 23:32:06 volumio go-librespot[5643]: time="2026-01-28T23:32:06+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Jan 28 23:32:06 volumio go-librespot[5643]: time="2026-01-28T23:32:06+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Jan 28 23:32:06 volumio go-librespot[5643]: time="2026-01-28T23:32:06+07:00" level=info msg="zeroconf server listening on port 46565" Jan 28 23:32:06 volumio go-librespot[5643]: time="2026-01-28T23:32:06+07:00" level=debug msg="obtained new client token: AAAvMOH9/VnQSRnpJRyukZAJTZWEcm0sDNCyHQB3e2bHET1gbdL5POXRsDuc1wC5EKc/T0PmsFnvUpUiOKgMUhxHeyKZwjJGtg53phDRN/Ra8SwPPVvbpiF4duXc336SUc3Vhj34A7nuMZK03Fx/7D+xs6hcXT5H0Zn/Ir6WhTxWc0cPeYhVTBso7RD8fUXknqkv6PDFNv2iqBQeQfjNRfiQ4ZXkVp1USQhpU2UjfeO0J4iEHvpqXz+Qru4=" Jan 28 23:32:06 volumio go-librespot[5643]: time="2026-01-28T23:32:06+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 23:32:06 volumio volumio[5308]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Jan 28 23:32:06 volumio go-librespot[5643]: time="2026-01-28T23:32:06+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Jan 28 23:32:06 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 23:32:06 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 23:32:07 volumio volumio[5308]: info: Initializing connection to go-librespot Websocket Jan 28 23:32:07 volumio volumio[5308]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 28 23:32:07 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 23:32:07 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 23:32:07 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 23:32:09 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 23:32:09 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 23:32:09 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 23:32:09 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 11. Jan 28 23:32:09 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 23:32:10 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 23:32:10 volumio go-librespot[5651]: go-librespot daemon starting... Jan 28 23:32:10 volumio go-librespot[5652]: time="2026-01-28T23:32:10+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 23:32:10 volumio go-librespot[5652]: time="2026-01-28T23:32:10+07:00" level=debug msg="app state loaded" Jan 28 23:32:10 volumio go-librespot[5652]: time="2026-01-28T23:32:10+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 23:32:10 volumio volumio[5308]: info: Initializing connection to go-librespot Websocket Jan 28 23:32:10 volumio go-librespot[5652]: time="2026-01-28T23:32:10+07:00" level=debug msg="new websocket client" Jan 28 23:32:10 volumio volumio[5308]: info: Connection to go-librespot Websocket established Jan 28 23:32:10 volumio go-librespot[5652]: time="2026-01-28T23:32:10+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 28 23:32:10 volumio go-librespot[5652]: time="2026-01-28T23:32:10+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Jan 28 23:32:10 volumio go-librespot[5652]: time="2026-01-28T23:32:10+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Jan 28 23:32:10 volumio go-librespot[5652]: time="2026-01-28T23:32:10+07:00" level=info msg="zeroconf server listening on port 34385" Jan 28 23:32:10 volumio go-librespot[5652]: time="2026-01-28T23:32:10+07:00" level=debug msg="obtained new client token: AAAnQE854nxC9Xa0f8UUVCqoyEKi9lryQcl42GMBuKLdDSa0GlLF5gRC5Y4xxNF4pAsSmcrXDszX+Dn/POaLtYqJQx5aSAzy4QgvoGJ4Jnx5Ur9tTzHMPXgSbPdHqdkiTTmop01EvwkSuOPZsk9SxxIRw9Hc75bOEGr1mFTT2l4XpIrZzp+Ycn1l0hdlTMihT8OCJJ/4VXTnv+8ekTcxNpeDdcAx3NCo7O1irWUDttFTFMXcKoqvNCCB96A=" Jan 28 23:32:10 volumio go-librespot[5652]: time="2026-01-28T23:32:10+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 23:32:10 volumio go-librespot[5652]: time="2026-01-28T23:32:10+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Jan 28 23:32:11 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 23:32:11 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 23:32:11 volumio volumio[5308]: info: Connection to go-librespot Websocket closed Jan 28 23:32:11 volumio volumio[5308]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Jan 28 23:32:11 volumio volumio[5308]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Jan 28 23:32:11 volumio volumio[5308]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Jan 28 23:32:11 volumio volumio[5308]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Jan 28 23:32:11 volumio volumio[5308]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Jan 28 23:32:11 volumio volumio[5308]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Jan 28 23:32:11 volumio volumio[5308]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Jan 28 23:32:11 volumio volumio[5308]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Jan 28 23:32:11 volumio volumio[5308]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Jan 28 23:32:11 volumio volumio[5308]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Jan 28 23:32:11 volumio volumio[5308]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Jan 28 23:32:11 volumio volumio[5308]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Jan 28 23:32:11 volumio volumio[5308]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Jan 28 23:32:11 volumio volumio[5308]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Jan 28 23:32:11 volumio volumio[5308]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Jan 28 23:32:11 volumio volumio[5308]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Jan 28 23:32:11 volumio volumio[5308]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Jan 28 23:32:11 volumio volumio[5308]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Jan 28 23:32:11 volumio volumio[5308]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Jan 28 23:32:11 volumio volumio[5308]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Jan 28 23:32:11 volumio volumio[5308]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Jan 28 23:32:11 volumio volumio[5308]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Jan 28 23:32:11 volumio volumio[5308]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Jan 28 23:32:11 volumio volumio[5308]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Jan 28 23:32:11 volumio volumio[5308]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Jan 28 23:32:11 volumio volumio[5308]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Jan 28 23:32:11 volumio volumio[5308]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Jan 28 23:32:11 volumio volumio[5308]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Jan 28 23:32:11 volumio volumio[5308]: info: Adding plugin bluetooth to MyMusic Plugins Jan 28 23:32:11 volumio volumio[5308]: info: Adding plugin multiroom to MyMusic Plugins Jan 28 23:32:11 volumio volumio[5308]: info: Adding plugin metavolumio to MyMusic Plugins Jan 28 23:32:11 volumio volumio[5308]: info: Adding plugin cd_controller to MyMusic Plugins Jan 28 23:32:11 volumio volumio[5308]: info: Adding plugin qobuzconnect to MyMusic Plugins Jan 28 23:32:11 volumio volumio[5308]: info: Adding plugin smart_inputs to MyMusic Plugins Jan 28 23:32:11 volumio volumio[5308]: info: Adding plugin tidalconnect to MyMusic Plugins Jan 28 23:32:11 volumio volumio[5308]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Jan 28 23:32:11 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 23:32:11 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 23:32:11 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 23:32:12 volumio volumio[5308]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Jan 28 23:32:12 volumio volumio[5308]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Jan 28 23:32:12 volumio volumio[5308]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 23:32:12 volumio volumio[5308]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 23:32:12 volumio volumio[5308]: info: Starting MyVolumio Remote Streaming Endpoints Jan 28 23:32:12 volumio volumio[5308]: info: MyVolumio login type: Token Jan 28 23:32:13 volumio volumio[5308]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Jan 28 23:32:13 volumio volumio[5308]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Jan 28 23:32:13 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 23:32:13 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 23:32:13 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 23:32:14 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 12. Jan 28 23:32:14 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 23:32:14 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 23:32:14 volumio go-librespot[5673]: go-librespot daemon starting... Jan 28 23:32:14 volumio go-librespot[5674]: time="2026-01-28T23:32:14+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 23:32:14 volumio go-librespot[5674]: time="2026-01-28T23:32:14+07:00" level=debug msg="app state loaded" Jan 28 23:32:14 volumio go-librespot[5674]: time="2026-01-28T23:32:14+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 23:32:14 volumio volumio[5308]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Jan 28 23:32:14 volumio volumio[5308]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Jan 28 23:32:14 volumio volumio[5308]: info: Streaming services startup Jan 28 23:32:14 volumio volumio[5308]: info: Starting Streaming Daemon Jan 28 23:32:14 volumio sudo[5683]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jan 28 23:32:14 volumio sudo[5683]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 23:32:14 volumio volumio[5308]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Jan 28 23:32:14 volumio sudo[5683]: pam_unix(sudo:session): session closed for user root Jan 28 23:32:14 volumio go-librespot[5674]: time="2026-01-28T23:32:14+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 28 23:32:14 volumio go-librespot[5674]: time="2026-01-28T23:32:14+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Jan 28 23:32:14 volumio go-librespot[5674]: time="2026-01-28T23:32:14+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Jan 28 23:32:14 volumio volumio[5308]: info: Getting Spotify volume Jan 28 23:32:14 volumio volumio[5308]: info: Initializing connection to go-librespot Websocket Jan 28 23:32:14 volumio go-librespot[5674]: time="2026-01-28T23:32:14+07:00" level=info msg="zeroconf server listening on port 45821" Jan 28 23:32:14 volumio volumio[5308]: error: Cannot start Volumio Streaming Daemon Jan 28 23:32:14 volumio volumio[5308]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Jan 28 23:32:14 volumio volumio[5308]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Jan 28 23:32:14 volumio go-librespot[5674]: time="2026-01-28T23:32:14+07:00" level=debug msg="new websocket client" Jan 28 23:32:14 volumio volumio[5308]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Jan 28 23:32:14 volumio volumio[5308]: info: Connection to go-librespot Websocket established Jan 28 23:32:15 volumio go-librespot[5674]: time="2026-01-28T23:32:15+07:00" level=debug msg="obtained new client token: AAAI7ACEvyeQjtgLRx08dPfv3y+Awpf4Ox+5b6c2InmNNXwPn+hhaes8mwMopnrv5Z+M3zXyTi0vY3cDpV/UOWQMrP4Y4WbE/hpij/ndhcLecd4bDi9S1lUIFmYUwqLrgF2CjX/hh7Av//EPh+TtvSd6B6mAGQOYCju3uK5E2ackKmVGjbpBbHsmNJVFH708WuBqIzBmrH4xF+z7LRf5zanglORAfDTHXfEi8m7fZ9iVQczzDU7lX856" Jan 28 23:32:15 volumio volumio[5308]: info: CoreCommandRouter::volumioGetState Jan 28 23:32:15 volumio volumio[5308]: info: CorePlayQueue::getTrack 0 Jan 28 23:32:15 volumio volumio[5308]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jan 28 23:32:15 volumio volumio[5308]: SPOTIFY: SPOTIFY VOLUME undefined Jan 28 23:32:15 volumio volumio[5308]: SPOTIFY: VOLUMIO VOLUME 100 Jan 28 23:32:15 volumio volumio[5308]: info: Aligning Spotify Volume to Volumio Volume Jan 28 23:32:15 volumio volumio[5308]: info: CoreCommandRouter::volumioGetState Jan 28 23:32:15 volumio volumio[5308]: info: CorePlayQueue::getTrack 0 Jan 28 23:32:15 volumio volumio[5308]: info: Setting Spotify Volume from Volumio: 100 Jan 28 23:32:15 volumio go-librespot[5674]: time="2026-01-28T23:32:15+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 23:32:15 volumio go-librespot[5674]: time="2026-01-28T23:32:15+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Jan 28 23:32:15 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 23:32:15 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 23:32:15 volumio volumio[5308]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 28 23:32:15 volumio volumio[5308]: Error: socket hang up Jan 28 23:32:15 volumio volumio[5308]: at connResetException (node:internal/errors:720:14) Jan 28 23:32:15 volumio volumio[5308]: at Socket.socketOnEnd (node:_http_client:519:23) Jan 28 23:32:15 volumio volumio[5308]: at Socket.emit (node:events:526:35) Jan 28 23:32:15 volumio volumio[5308]: at endReadableNT (node:internal/streams/readable:1376:12) Jan 28 23:32:15 volumio volumio[5308]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Jan 28 23:32:15 volumio volumio[5308]: code: 'ECONNRESET', Jan 28 23:32:15 volumio volumio[5308]: response: undefined Jan 28 23:32:15 volumio volumio[5308]: } Jan 28 23:32:15 volumio volumio[5308]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 28 23:32:15 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 23:32:15 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 23:32:15 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 23:32:16 volumio sudo[5703]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-01-28 23:31' Jan 28 23:32:16 volumio sudo[5703]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 23:32:17 volumio sudo[5703]: pam_unix(sudo:session): session closed for user root Jan 28 23:32:17 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 23:32:17 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 23:32:17 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 23:32:18 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 13. Jan 28 23:32:18 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 23:32:18 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 23:32:18 volumio go-librespot[5711]: go-librespot daemon starting... Jan 28 23:32:18 volumio go-librespot[5713]: time="2026-01-28T23:32:18+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 23:32:18 volumio go-librespot[5713]: time="2026-01-28T23:32:18+07:00" level=debug msg="app state loaded" Jan 28 23:32:18 volumio go-librespot[5713]: time="2026-01-28T23:32:18+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 23:32:18 volumio volumio-remote-updater[628]: [2026-01-28 23:32:18] [error] handle_read_frame error: asio.system:104 (Connection reset by peer) Jan 28 23:32:18 volumio volumio-remote-updater[628]: [2026-01-28 23:32:18] [disconnect] Disconnect close local:[1006,Connection reset by peer] remote:[1006] Jan 28 23:32:18 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Jan 28 23:32:18 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Jan 28 23:32:18 volumio systemd[1]: volumio.service: Consumed 1min 3.003s CPU time. Jan 28 23:32:18 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 28 23:32:18 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Jan 28 23:32:18 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 10847. Jan 28 23:32:18 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 28 23:32:18 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Jan 28 23:32:18 volumio systemd[1]: volumio.service: Consumed 1min 3.003s CPU time. Jan 28 23:32:18 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Jan 28 23:32:18 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Jan 28 23:32:19 volumio go-librespot[5713]: time="2026-01-28T23:32:19+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 28 23:32:19 volumio go-librespot[5713]: time="2026-01-28T23:32:19+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Jan 28 23:32:19 volumio go-librespot[5713]: time="2026-01-28T23:32:19+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Jan 28 23:32:19 volumio go-librespot[5713]: time="2026-01-28T23:32:19+07:00" level=info msg="zeroconf server listening on port 41145" Jan 28 23:32:19 volumio go-librespot[5713]: time="2026-01-28T23:32:19+07:00" level=debug msg="obtained new client token: AADnBtJsAbi7ISV45JCYvFuz+AXlei7H4OD7nRHz0ONPGzcpHbcOXVocofrF7wP2WbF6yIC6zyrqw29SsUJoUYUTU7Ee0bVkMQWkJgcgLwluro3yOm7bXir4dwXpCJK2Fc3K+gOqyB+5JQvZ5P+Vvb3H4SBkQjLrVYcTHhJXjJB5QyuYQIde8FTrKhZpn2CC3qnpf/oy0oGfSb9G8Pi3H6kd1fv3B/WKhFDtbHfp4/UKcmWUO7VDBOAZTQM=" Jan 28 23:32:19 volumio go-librespot[5713]: time="2026-01-28T23:32:19+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 23:32:19 volumio go-librespot[5713]: time="2026-01-28T23:32:19+07:00" level=debug msg="completed keyexchange" Jan 28 23:32:19 volumio go-librespot[5713]: time="2026-01-28T23:32:19+07:00" level=debug msg="completed challenge" Jan 28 23:32:19 volumio go-librespot[5713]: time="2026-01-28T23:32:19+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 23:32:19 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 23:32:19 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 23:32:19 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 23:32:19 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 23:32:19 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 23:32:21 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 23:32:21 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 23:32:21 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 23:32:22 volumio volumio[5727]: info: ------------------------------------------- Jan 28 23:32:22 volumio volumio[5727]: info: ----- Volumio3 ---- Jan 28 23:32:22 volumio volumio[5727]: info: ------------------------------------------- Jan 28 23:32:22 volumio volumio[5727]: info: ----- System startup ---- Jan 28 23:32:22 volumio volumio[5727]: info: ------------------------------------------- Jan 28 23:32:22 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 14. Jan 28 23:32:22 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 23:32:22 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 23:32:22 volumio go-librespot[5749]: go-librespot daemon starting... Jan 28 23:32:22 volumio go-librespot[5750]: time="2026-01-28T23:32:22+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 23:32:22 volumio go-librespot[5750]: time="2026-01-28T23:32:22+07:00" level=debug msg="app state loaded" Jan 28 23:32:22 volumio go-librespot[5750]: time="2026-01-28T23:32:22+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 23:32:23 volumio go-librespot[5750]: time="2026-01-28T23:32:23+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 23:32:23 volumio go-librespot[5750]: time="2026-01-28T23:32:23+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 28 23:32:23 volumio go-librespot[5750]: time="2026-01-28T23:32:23+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 28 23:32:23 volumio go-librespot[5750]: time="2026-01-28T23:32:23+07:00" level=info msg="zeroconf server listening on port 46171" Jan 28 23:32:23 volumio volumio-remote-updater[628]: [2026-01-28 23:32:23] [connect] Successful connection Jan 28 23:32:23 volumio go-librespot[5750]: time="2026-01-28T23:32:23+07:00" level=debug msg="obtained new client token: AADk50jHhMPd47w1Dk+aqQL/uFA46OFQXR9qM3QXyJoT85GPNYyccvCBYzfJkdootp6Qji6Vt+vjYqfCJhBDe24Hjp4blZnq/kX4kd9XyYoWJTCrPIP7fJ7rXY2MJlPGA1FocOEauazAsxuygvgpiO3L2/ExT4o+17ofqJqgvNUqYWMBSdIrqNeOKP4Qjg/09c5dRFa7mGq6yT7b7bwZuStKHSQyHZ4bSkqPLNzWFvCmkQ/5tpKA46lXKi8=" Jan 28 23:32:23 volumio go-librespot[5750]: time="2026-01-28T23:32:23+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 23:32:23 volumio volumio[5727]: info: MYVOLUMIO Environment detected Jan 28 23:32:23 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 23:32:23 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 23:32:23 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 23:32:23 volumio go-librespot[5750]: time="2026-01-28T23:32:23+07:00" level=debug msg="completed keyexchange" Jan 28 23:32:23 volumio go-librespot[5750]: time="2026-01-28T23:32:23+07:00" level=debug msg="completed challenge" Jan 28 23:32:24 volumio volumio[5727]: info: Plugin folders cleanup Jan 28 23:32:24 volumio volumio[5727]: info: Scanning into folder /volumio/app/plugins/ Jan 28 23:32:24 volumio volumio[5727]: info: Scanning category audio_interface Jan 28 23:32:24 volumio volumio[5727]: info: Scanning category miscellanea Jan 28 23:32:24 volumio volumio[5727]: info: Scanning category music_service Jan 28 23:32:24 volumio volumio[5727]: info: Scanning category plugins.json Jan 28 23:32:24 volumio volumio[5727]: info: Scanning category system_controller Jan 28 23:32:24 volumio volumio[5727]: info: Scanning category user_interface Jan 28 23:32:24 volumio volumio[5727]: info: Scanning into folder /data/plugins/ Jan 28 23:32:24 volumio volumio[5727]: info: Scanning category music_service Jan 28 23:32:24 volumio volumio[5727]: info: Plugin folders cleanup completed Jan 28 23:32:24 volumio volumio[5727]: info: ------------------------------------------- Jan 28 23:32:24 volumio volumio[5727]: info: ----- Core plugins startup ---- Jan 28 23:32:24 volumio volumio[5727]: info: ------------------------------------------- Jan 28 23:32:24 volumio volumio[5727]: info: Loading plugins from folder /volumio/app/plugins/ Jan 28 23:32:24 volumio volumio[5727]: info: Adding plugin upnp to MyMusic Plugins Jan 28 23:32:24 volumio go-librespot[5750]: time="2026-01-28T23:32:24+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 23:32:24 volumio volumio[5727]: info: Adding plugin airplay_emulation to MyMusic Plugins Jan 28 23:32:24 volumio volumio[5727]: info: Adding plugin upnp_browser to MyMusic Plugins Jan 28 23:32:24 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 23:32:24 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 23:32:24 volumio volumio[5727]: info: Loading plugins from folder /data/plugins/ Jan 28 23:32:24 volumio volumio[5727]: info: Loading plugin "system"... Jan 28 23:32:24 volumio volumio[5727]: info: Loading plugin "appearance"... Jan 28 23:32:25 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 23:32:25 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 23:32:25 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 23:32:26 volumio volumio[5727]: info: Loading plugin "network"... Jan 28 23:32:26 volumio volumio[5727]: info: Refreshing Cached IP Addresses Jan 28 23:32:26 volumio sudo[5764]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 28 23:32:26 volumio sudo[5764]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 23:32:26 volumio sudo[5766]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 28 23:32:26 volumio volumio[5727]: info: Loading plugin "services"... Jan 28 23:32:26 volumio sudo[5764]: pam_unix(sudo:session): session closed for user root Jan 28 23:32:26 volumio sudo[5766]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 23:32:26 volumio volumio[5727]: info: Loading plugin "alsa_controller"... Jan 28 23:32:26 volumio sudo[5766]: pam_unix(sudo:session): session closed for user root Jan 28 23:32:26 volumio sudo[5773]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Jan 28 23:32:26 volumio sudo[5773]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 23:32:26 volumio volumio[5727]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 28 23:32:26 volumio volumio[5727]: info: Loading plugin "wizard"... Jan 28 23:32:26 volumio volumio[5727]: info: Loading plugin "networkfs"... Jan 28 23:32:26 volumio volumio[5727]: info: Starting Udev Watcher for removable devices Jan 28 23:32:26 volumio volumio[5727]: info: Ignoring mount for partition: boot Jan 28 23:32:26 volumio volumio[5727]: info: Ignoring mount for partition: volumio Jan 28 23:32:26 volumio volumio[5727]: info: Ignoring mount for partition: volumio_data Jan 28 23:32:26 volumio volumio[5727]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 28 23:32:26 volumio volumio[5727]: info: Loading plugin "volumio_command_line_client"... Jan 28 23:32:26 volumio volumio[5727]: info: Loading plugin "upnp"... Jan 28 23:32:26 volumio volumio[5727]: info: [1769617946443] Starting Upmpd Daemon Jan 28 23:32:26 volumio volumio[5727]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 28 23:32:26 volumio volumio[5727]: info: Loading plugin "my_music"... Jan 28 23:32:26 volumio volumio[5727]: info: Loading plugin "mpd"... Jan 28 23:32:27 volumio volumio[5727]: info: Loading plugin "upnp_browser"... Jan 28 23:32:27 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 15. Jan 28 23:32:27 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 23:32:27 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 23:32:27 volumio go-librespot[5797]: go-librespot daemon starting... Jan 28 23:32:27 volumio go-librespot[5798]: time="2026-01-28T23:32:27+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 23:32:27 volumio go-librespot[5798]: time="2026-01-28T23:32:27+07:00" level=debug msg="app state loaded" Jan 28 23:32:27 volumio go-librespot[5798]: time="2026-01-28T23:32:27+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 23:32:27 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 23:32:27 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 23:32:27 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 23:32:27 volumio go-librespot[5798]: time="2026-01-28T23:32:27+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 28 23:32:27 volumio go-librespot[5798]: time="2026-01-28T23:32:27+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Jan 28 23:32:27 volumio go-librespot[5798]: time="2026-01-28T23:32:27+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Jan 28 23:32:27 volumio go-librespot[5798]: time="2026-01-28T23:32:27+07:00" level=info msg="zeroconf server listening on port 41925" Jan 28 23:32:28 volumio go-librespot[5798]: time="2026-01-28T23:32:28+07:00" level=debug msg="obtained new client token: AABelCISTNiN82/4zDwdlpzVio+B1cUEsP50XhD/dJjf4yBYt15VMtLXYlodYDH2GmqNIQBvnwxcSoItB+4ahmNtO9ZxJWi+7m2oO0AfFHeeOH601nHq+t6+KrLd+JYZxsrN3wbDfsPPzqfSaHQ3DQw0Qhl51S6k4F/yssLR5gz329v9CGxOXxn3u9nW+TizzNiR6Nu4s79fGkqus2K+Vq70KKKF9i1m7ILkbIqUwJP/4LN+e3ExteEb" Jan 28 23:32:28 volumio go-librespot[5798]: time="2026-01-28T23:32:28+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 23:32:28 volumio go-librespot[5798]: time="2026-01-28T23:32:28+07:00" level=debug msg="completed keyexchange" Jan 28 23:32:28 volumio go-librespot[5798]: time="2026-01-28T23:32:28+07:00" level=debug msg="completed challenge" Jan 28 23:32:28 volumio go-librespot[5798]: time="2026-01-28T23:32:28+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 23:32:28 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 23:32:28 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 23:32:28 volumio sudo[5773]: pam_unix(sudo:session): session closed for user root Jan 28 23:32:29 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 23:32:29 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 23:32:29 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 23:32:30 volumio volumio[5727]: info: Starting UPNP Browser Jan 28 23:32:30 volumio volumio[5727]: info: Loading plugin "alarm-clock"... Jan 28 23:32:30 volumio volumio[5727]: info: Loading plugin "airplay_emulation"... Jan 28 23:32:30 volumio volumio[5727]: info: Starting Shairport Sync Jan 28 23:32:30 volumio volumio[5727]: info: Loading plugin "last_100"... Jan 28 23:32:30 volumio volumio[5727]: info: Loading plugin "webradio"... Jan 28 23:32:30 volumio volumio[5727]: info: Loading plugin "i2s_dacs"... Jan 28 23:32:30 volumio volumio[5727]: info: Loading plugin "volumiodiscovery"... Jan 28 23:32:30 volumio volumio[5727]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 28 23:32:30 volumio volumio[5727]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 23:32:30 volumio node[5727]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 28 23:32:30 volumio volumio[5727]: *** WARNING *** For more information see Jan 28 23:32:30 volumio volumio[5727]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 28 23:32:30 volumio volumio[5727]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 23:32:30 volumio volumio[5727]: *** WARNING *** For more information see Jan 28 23:32:30 volumio node[5727]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 23:32:30 volumio node[5727]: *** WARNING *** For more information see Jan 28 23:32:30 volumio node[5727]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 28 23:32:30 volumio node[5727]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 23:32:30 volumio node[5727]: *** WARNING *** For more information see Jan 28 23:32:30 volumio volumio[5727]: info: Applying required configuration parameters for plugin volumiodiscovery Jan 28 23:32:30 volumio volumio[5727]: info: Discovery: Started advertising with name: Volumio Jan 28 23:32:30 volumio volumio[5727]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 28 23:32:30 volumio volumio[5727]: info: Loading plugin "spop"... Jan 28 23:32:31 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 16. Jan 28 23:32:31 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 23:32:31 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 23:32:31 volumio go-librespot[5808]: go-librespot daemon starting... Jan 28 23:32:31 volumio go-librespot[5809]: time="2026-01-28T23:32:31+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 23:32:31 volumio go-librespot[5809]: time="2026-01-28T23:32:31+07:00" level=debug msg="app state loaded" Jan 28 23:32:31 volumio go-librespot[5809]: time="2026-01-28T23:32:31+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 23:32:31 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 23:32:31 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 23:32:31 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 23:32:32 volumio go-librespot[5809]: time="2026-01-28T23:32:32+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 28 23:32:32 volumio go-librespot[5809]: time="2026-01-28T23:32:32+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Jan 28 23:32:32 volumio go-librespot[5809]: time="2026-01-28T23:32:32+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Jan 28 23:32:32 volumio go-librespot[5809]: time="2026-01-28T23:32:32+07:00" level=info msg="zeroconf server listening on port 36159" Jan 28 23:32:32 volumio go-librespot[5809]: time="2026-01-28T23:32:32+07:00" level=debug msg="obtained new client token: AAAQoS0FEFlPl0/GtCVAjfgP1WI4SQO8KEgwwYlNRQHaDhOGgtlpQYu7XUYlp3tNSUl1sQWLD31YxcFJdCE2mrP3cvWuiquHy0pkUj4bsw7xruc9prRAgb6ohkHjbcjTPJ8Y2UWS6Bwx8MMAugiMmeUVXy3ULzKsbkwadZeQ+XQbdo1s+7o43n6O8SHySwNeBVZgXSLDT07bYSCJvbL+BwXVPUckUrSZEOx5cVanetV4eP3QdoFhHqiuRnU=" Jan 28 23:32:32 volumio go-librespot[5809]: time="2026-01-28T23:32:32+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 23:32:32 volumio go-librespot[5809]: time="2026-01-28T23:32:32+07:00" level=debug msg="completed keyexchange" Jan 28 23:32:32 volumio go-librespot[5809]: time="2026-01-28T23:32:32+07:00" level=debug msg="completed challenge" Jan 28 23:32:32 volumio go-librespot[5809]: time="2026-01-28T23:32:32+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 23:32:32 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 23:32:32 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 23:32:32 volumio volumio[5727]: info: Loading plugin "ytcr"... Jan 28 23:32:33 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 23:32:33 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 23:32:33 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 23:32:35 volumio volumio[5727]: info: Loading plugin "ytmusic"... Jan 28 23:32:35 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 17. Jan 28 23:32:35 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 23:32:35 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 23:32:35 volumio go-librespot[5817]: go-librespot daemon starting... Jan 28 23:32:35 volumio go-librespot[5818]: time="2026-01-28T23:32:35+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 23:32:35 volumio go-librespot[5818]: time="2026-01-28T23:32:35+07:00" level=debug msg="app state loaded" Jan 28 23:32:35 volumio go-librespot[5818]: time="2026-01-28T23:32:35+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 23:32:35 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 23:32:35 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 23:32:35 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 23:32:36 volumio volumio-remote-updater[628]: [2026-01-28 23:32:36] [connect] Successful connection Jan 28 23:32:36 volumio volumio[5727]: info: Loading plugin "outputs"... Jan 28 23:32:36 volumio go-librespot[5818]: time="2026-01-28T23:32:36+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 23:32:36 volumio go-librespot[5818]: time="2026-01-28T23:32:36+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 28 23:32:36 volumio go-librespot[5818]: time="2026-01-28T23:32:36+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 28 23:32:36 volumio volumio[5727]: info: Loading plugin "albumart"... Jan 28 23:32:36 volumio go-librespot[5818]: time="2026-01-28T23:32:36+07:00" level=info msg="zeroconf server listening on port 38121" Jan 28 23:32:36 volumio volumio[5727]: info: Plugin example_plugin is not enabled Jan 28 23:32:36 volumio volumio[5727]: info: Loading plugin "inputs"... Jan 28 23:32:36 volumio volumio[5727]: info: Loading plugin "updater_comm"... Jan 28 23:32:36 volumio volumio[5727]: info: Plugin mpdemulation is not enabled Jan 28 23:32:36 volumio volumio[5727]: info: Loading plugin "rest_api"... Jan 28 23:32:36 volumio volumio[5727]: info: Loading plugin "websocket"... Jan 28 23:32:36 volumio go-librespot[5818]: time="2026-01-28T23:32:36+07:00" level=debug msg="obtained new client token: AAB6nAQH79fwcHH/U68c8GeHdX3mscxc4o1uBVajarEVZcid4ZtReoIVJ/ju2g93iQSXEgWQeqJ5E604BXhzwow3LxWt54HnaO1C5icsR5n5QMY+edsuXUi7fbs9pourQM1BNHzxNmSeHomUf38aOW7BZ9wEYauzMvAftHYc1uLqNMR05IPepoJJI1/OQNCm4VttIKZZqRfTWIXJXJrOikD/iT0oTeNkrzwXQqEUA3DoG2EaIjK2hB8vR7w=" Jan 28 23:32:36 volumio volumio[5727]: info: Starting Socket.io Server version 1.7.4 Jan 28 23:32:36 volumio volumio[5727]: info: Loading plugin "RoonBridge"... Jan 28 23:32:36 volumio go-librespot[5818]: time="2026-01-28T23:32:36+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 23:32:36 volumio go-librespot[5818]: time="2026-01-28T23:32:36+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Jan 28 23:32:36 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 23:32:36 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 23:32:37 volumio volumio[5727]: info: Applying required configuration parameters for plugin RoonBridge Jan 28 23:32:37 volumio volumio[5727]: info: Loading i18n strings for locale en Jan 28 23:32:37 volumio volumio[5727]: Updating browse sources language Jan 28 23:32:37 volumio volumio[5727]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 23:32:37 volumio volumio[5727]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 28 23:32:37 volumio volumio[5727]: info: CoreCommandRouter::initPlayerControls Jan 28 23:32:37 volumio volumio[5727]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 23:32:37 volumio volumio[5727]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 23:32:37 volumio volumio[5727]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 23:32:37 volumio volumio[5727]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 23:32:37 volumio volumio[5727]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 23:32:37 volumio volumio[5727]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 23:32:37 volumio volumio[5727]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 23:32:37 volumio volumio[5727]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 23:32:37 volumio volumio[5727]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 28 23:32:37 volumio volumio[5839]: Forking 3 albumart workers Jan 28 23:32:37 volumio volumio[5727]: Express server listening on port 3000 Jan 28 23:32:37 volumio volumio[5727]: [Metrics] WebUI: 16s 145.45ms Jan 28 23:32:37 volumio volumio[5727]: info: CoreStateMachine::resetVolumioState Jan 28 23:32:37 volumio volumio[5727]: info: CoreStateMachine::getcurrentVolume Jan 28 23:32:37 volumio volumio[5727]: info: CoreCommandRouter::volumioRetrievevolume Jan 28 23:32:37 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 23:32:37 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 23:32:37 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 23:32:37 volumio sudo[5883]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 28 23:32:37 volumio sudo[5881]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 28 23:32:37 volumio sudo[5883]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 23:32:37 volumio sudo[5881]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 23:32:37 volumio sudo[5881]: pam_unix(sudo:session): session closed for user root Jan 28 23:32:37 volumio sudo[5883]: pam_unix(sudo:session): session closed for user root Jan 28 23:32:37 volumio volumio[5727]: info: Volumio Network Manager: Network status updated: 1 Jan 28 23:32:38 volumio volumio-remote-updater[628]: [2026-01-28 23:32:38] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1769617956 101 Jan 28 23:32:38 volumio volumio[5727]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 1 Jan 28 23:32:38 volumio volumio[5727]: info: VolumeController:: Volume=100 Mute =false Jan 28 23:32:38 volumio volumio[5727]: info: CoreStateMachine::pushState Jan 28 23:32:38 volumio volumio[5727]: info: CorePlayQueue::getTrack 0 Jan 28 23:32:38 volumio volumio[5727]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 28 23:32:38 volumio volumio[5727]: info: CoreCommandRouter::volumioPushState Jan 28 23:32:38 volumio volumio[5727]: info: CoreStateMachine::updateTrackBlock Jan 28 23:32:38 volumio volumio[5727]: info: CorePlayQueue::getTrackBlock Jan 28 23:32:38 volumio volumio[5727]: info: CoreCommandRouter::volumioRetrievevolume Jan 28 23:32:38 volumio volumio[5727]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 23:32:38 volumio volumio[5727]: info: Reloading queue from file Jan 28 23:32:38 volumio volumio[5727]: info: CoreStateMachine::setRepeat null single undefined Jan 28 23:32:38 volumio volumio[5727]: info: CoreStateMachine::pushState Jan 28 23:32:38 volumio volumio[5727]: info: CorePlayQueue::getTrack 0 Jan 28 23:32:38 volumio volumio[5727]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 28 23:32:38 volumio volumio[5727]: info: CoreCommandRouter::volumioPushState Jan 28 23:32:38 volumio volumio[5727]: info: CoreStateMachine::setRandom null Jan 28 23:32:38 volumio volumio[5727]: info: CoreStateMachine::pushState Jan 28 23:32:38 volumio volumio[5727]: info: CorePlayQueue::getTrack 0 Jan 28 23:32:38 volumio volumio[5727]: info: CoreCommandRouter::volumioPushState Jan 28 23:32:38 volumio volumio[5727]: info: Setting Device type: Raspberry PI Jan 28 23:32:38 volumio volumio[5727]: info: Completed loading Core Plugins Jan 28 23:32:38 volumio volumio[5727]: info: Preparing to generate the ALSA configuration file Jan 28 23:32:38 volumio volumio[5727]: info: VolumeController:: Volume=100 Mute =false Jan 28 23:32:38 volumio volumio[5727]: info: CoreStateMachine::pushState Jan 28 23:32:38 volumio volumio[5727]: info: CorePlayQueue::getTrack 0 Jan 28 23:32:38 volumio volumio[5727]: info: CoreCommandRouter::volumioPushState Jan 28 23:32:38 volumio volumio[5727]: info: Asound.conf file unchanged, so no further update is needed Jan 28 23:32:38 volumio volumio[5727]: info: Output device has changed, restarting MPD Jan 28 23:32:38 volumio sudo[5901]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Jan 28 23:32:38 volumio volumio[5727]: info: Output device has changed, restarting Shairport Sync Jan 28 23:32:38 volumio volumio[5727]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 23:32:38 volumio volumio[5727]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 23:32:38 volumio sudo[5901]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 23:32:38 volumio sudo[5903]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 28 23:32:38 volumio sudo[5903]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 23:32:38 volumio sudo[5903]: pam_unix(sudo:session): session closed for user root Jan 28 23:32:38 volumio sudo[5905]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 28 23:32:38 volumio sudo[5905]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 23:32:38 volumio volumio[5727]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 28 23:32:38 volumio volumio[5727]: info: ___________ START PLUGINS ___________ Jan 28 23:32:38 volumio sudo[5901]: pam_unix(sudo:session): session closed for user root Jan 28 23:32:38 volumio volumio[5727]: info: ControllerMpd::onStart: Initializing MPD Jan 28 23:32:38 volumio volumio[5727]: info: Creating MPD Configuration file Jan 28 23:32:39 volumio volumio[5727]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 28 23:32:39 volumio volumio[5727]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 23:32:39 volumio volumio[5727]: info: [1769617959009] CoreMusicLibrary::Adding element Media Servers Jan 28 23:32:39 volumio volumio[5727]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 23:32:39 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Jan 28 23:32:39 volumio sudo[5918]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 28 23:32:39 volumio sudo[5918]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 23:32:39 volumio volumio[5727]: info: UPNP Browser: Client initialized successfully Jan 28 23:32:39 volumio sudo[5918]: pam_unix(sudo:session): session closed for user root Jan 28 23:32:39 volumio sudo[5917]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 28 23:32:39 volumio sudo[5917]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 23:32:39 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 28 23:32:39 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 28 23:32:39 volumio systemd[1]: mpd.service: Consumed 7.519s CPU time. Jan 28 23:32:39 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 28 23:32:39 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 28 23:32:39 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 28 23:32:39 volumio volumio[5727]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 23:32:39 volumio volumio[5727]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 23:32:39 volumio volumio[5727]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 28 23:32:39 volumio volumio[5727]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 23:32:39 volumio volumio[5727]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 23:32:39 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 28 23:32:39 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 28 23:32:39 volumio volumio[5727]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 28 23:32:39 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 28 23:32:39 volumio volumio[5727]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 23:32:39 volumio volumio[5727]: info: [1769617959404] CoreMusicLibrary::Adding element Last_100 Jan 28 23:32:39 volumio volumio[5727]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 23:32:39 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 28 23:32:39 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 28 23:32:39 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 28 23:32:39 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 28 23:32:39 volumio volumio[5727]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 23:32:39 volumio volumio[5727]: info: [1769617959430] CoreMusicLibrary::Adding element Webradio Jan 28 23:32:39 volumio volumio[5727]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 23:32:39 volumio volumio[5727]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 28 23:32:39 volumio volumio[5727]: info: Initializing BBC Radios Jan 28 23:32:39 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 28 23:32:39 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 28 23:32:39 volumio volumio[5727]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 28 23:32:39 volumio volumio[5727]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 23:32:39 volumio volumio[5727]: info: Creating Spotify config file Jan 28 23:32:39 volumio volumio[5727]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 23:32:39 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 23:32:39 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 23:32:39 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 23:32:39 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 18. Jan 28 23:32:39 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 23:32:40 volumio sudo[5935]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 28 23:32:40 volumio sudo[5935]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jan 28 23:32:40 volumio sudo[5935]: pam_unix(sudo:session): session closed for user root Jan 28 23:32:40 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 23:32:40 volumio go-librespot[5946]: go-librespot daemon starting... Jan 28 23:32:40 volumio go-librespot[5948]: time="2026-01-28T23:32:40+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 23:32:40 volumio volumio[5850]: Starting albumart workers Jan 28 23:32:41 volumio go-librespot[5948]: time="2026-01-28T23:32:41+07:00" level=info msg="zeroconf server listening on port 33459" Jan 28 23:32:41 volumio volumio[5727]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 23:32:41 volumio volumio[5727]: info: [1769617961093] CoreMusicLibrary::Adding element YouTube Music Jan 28 23:32:41 volumio volumio[5727]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 23:32:41 volumio volumio[5727]: Cannot find translation for source YouTube Music Jan 28 23:32:41 volumio volumio[5727]: info: Volumio Calling Home Jan 28 23:32:41 volumio sudo[5957]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Jan 28 23:32:41 volumio sudo[5957]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 23:32:41 volumio volumio[5854]: Starting albumart workers Jan 28 23:32:41 volumio sudo[5957]: pam_unix(sudo:session): session closed for user root Jan 28 23:32:41 volumio volumio[5853]: Starting albumart workers Jan 28 23:32:41 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 23:32:41 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 23:32:41 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 23:32:42 volumio volumio[5727]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Jan 28 23:32:42 volumio volumio[5727]: info: Discovery: Found device Volumio Jan 28 23:32:42 volumio volumio[5727]: info: CoreCommandRouter::volumioGetState Jan 28 23:32:42 volumio volumio[5727]: info: CorePlayQueue::getTrack 0 Jan 28 23:32:42 volumio volumio[5727]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Jan 28 23:32:42 volumio volumio[5727]: info: Discovery: Found device Volumio Jan 28 23:32:42 volumio volumio[5727]: info: CoreCommandRouter::volumioGetState Jan 28 23:32:42 volumio volumio[5727]: info: CorePlayQueue::getTrack 0 Jan 28 23:32:42 volumio volumio[5727]: info: MPD Permissions set Jan 28 23:32:42 volumio volumio[5727]: info: MPD Permissions set Jan 28 23:32:42 volumio volumio[5727]: info: Upmpdcli Daemon Started Jan 28 23:32:42 volumio volumio[5727]: info: Spotify config file written Jan 28 23:32:42 volumio sudo[5963]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jan 28 23:32:42 volumio sudo[5963]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 23:32:42 volumio volumio[5727]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Jan 28 23:32:42 volumio volumio[5727]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 23:32:42 volumio volumio[5727]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 23:32:42 volumio volumio[5727]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 23:32:42 volumio volumio[5727]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 23:32:42 volumio volumio[5727]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 23:32:42 volumio volumio[5727]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 23:32:42 volumio volumio[5727]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 23:32:42 volumio volumio[5727]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 23:32:42 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Jan 28 23:32:42 volumio systemd[1]: go-librespot-daemon.service: Killing process 5953 (go-librespot) with signal SIGKILL. Jan 28 23:32:42 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Jan 28 23:32:42 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 23:32:42 volumio volumio[5727]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 23:32:42 volumio volumio[5727]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 23:32:42 volumio volumio[5727]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 23:32:42 volumio volumio[5727]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 23:32:42 volumio volumio[5727]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 23:32:42 volumio volumio[5727]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 23:32:42 volumio volumio[5727]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 23:32:42 volumio volumio[5727]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 23:32:42 volumio volumio[5727]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 23:32:42 volumio volumio[5727]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 23:32:42 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 23:32:42 volumio go-librespot[5970]: go-librespot daemon starting... Jan 28 23:32:42 volumio sudo[5963]: pam_unix(sudo:session): session closed for user root Jan 28 23:32:42 volumio volumio[5727]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 23:32:42 volumio volumio[5727]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 23:32:42 volumio volumio[5727]: info: No need to fix Spotify hosts Jan 28 23:32:42 volumio go-librespot[5973]: time="2026-01-28T23:32:42+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 23:32:42 volumio go-librespot[5973]: time="2026-01-28T23:32:42+07:00" level=debug msg="app state loaded" Jan 28 23:32:42 volumio go-librespot[5973]: time="2026-01-28T23:32:42+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 23:32:43 volumio go-librespot[5973]: time="2026-01-28T23:32: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 28 23:32:43 volumio go-librespot[5973]: time="2026-01-28T23:32: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 28 23:32:43 volumio go-librespot[5973]: time="2026-01-28T23:32: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 28 23:32:43 volumio go-librespot[5973]: time="2026-01-28T23:32:43+07:00" level=info msg="zeroconf server listening on port 37705" Jan 28 23:32:43 volumio go-librespot[5973]: time="2026-01-28T23:32:43+07:00" level=debug msg="obtained new client token: AAAZvb4gvbYSOv7TixK4oeFvbWUzcUjkg1LJEoSKLF/SeGLG0vbOt7BLB4WHjGyk/kbLHSedDWIvpWwZsuX0MkNGcp607njgVo5liB7P/Agn3pVLPnyZZMx2d+P3ANsMyNjbfI5P14VehPf70RylBg5OLqPkd6Kw6SUjiVKUbuE2qxekqRbYIqfAT/2iiz3AURUBbJjaRJWpp9crPW3SHqB3TPYgIDdjoK6h1eNV4PRxggGI+cu3f4MWFW0=" Jan 28 23:32:43 volumio go-librespot[5973]: time="2026-01-28T23:32:43+07:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:4070, retrying with a different AP" error="dial tcp 104.199.241.202:4070: connect: connection refused" Jan 28 23:32:43 volumio volumio[5727]: info: Volumio called home Jan 28 23:32:43 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 23:32:43 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 23:32:43 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 23:32:43 volumio volumio[5727]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 28 23:32:43 volumio volumio[5727]: SPOTIFY: BQCyyO3LRRIJgXHO8kglrcMjI4nYcI7ciYgSAXAtweZS8oOQdK2JlR-HSJy9wkvuCs_tbigqZNZUu2LNxbFG9O0GyqzJY5H3zQRAY8lLB4cWeW7beyAzUvP5CKlJPFUC8nyjDQ9fLW708UnbI-KSmav1Amp0NW2s6iHNBgtlwLJy9L5btjH-43OdcBDMVmF-0g78_RlD5CZ2O3PWOnkj5BrVmrkt0z5iLQB2NCJgjWDZjncUjDlKPsTzHAExNoTkGRISbABJJQzM193ME4CHs1Au7uuCfr6MeSJLUoDuUgzNt1hhHYfCfQcE Jan 28 23:32:43 volumio volumio[5727]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 28 23:32:43 volumio volumio[5727]: info: New Spotify access token = BQCyyO3LRRIJgXHO8kglrcMjI4nYcI7ciYgSAXAtweZS8oOQdK2JlR-HSJy9wkvuCs_tbigqZNZUu2LNxbFG9O0GyqzJY5H3zQRAY8lLB4cWeW7beyAzUvP5CKlJPFUC8nyjDQ9fLW708UnbI-KSmav1Amp0NW2s6iHNBgtlwLJy9L5btjH-43OdcBDMVmF-0g78_RlD5CZ2O3PWOnkj5BrVmrkt0z5iLQB2NCJgjWDZjncUjDlKPsTzHAExNoTkGRISbABJJQzM193ME4CHs1Au7uuCfr6MeSJLUoDuUgzNt1hhHYfCfQcE Jan 28 23:32:43 volumio volumio[5727]: info: Spotify credentials grant success - running version from March 24, 2019 Jan 28 23:32:43 volumio go-librespot[5973]: time="2026-01-28T23:32:43+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Jan 28 23:32:44 volumio volumio[5727]: info: Starting Shairport Sync Jan 28 23:32:44 volumio volumio[5727]: info: Starting Shairport Sync Jan 28 23:32:44 volumio go-librespot[5973]: time="2026-01-28T23:32:44+07:00" level=debug msg="completed keyexchange" Jan 28 23:32:44 volumio go-librespot[5973]: time="2026-01-28T23:32:44+07:00" level=debug msg="completed challenge" Jan 28 23:32:44 volumio sudo[6004]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 28 23:32:44 volumio sudo[6004]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 23:32:44 volumio volumio[5727]: info: Starting Shairport Sync Jan 28 23:32:44 volumio sudo[6006]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 28 23:32:44 volumio sudo[6006]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 23:32:44 volumio go-librespot[5973]: time="2026-01-28T23:32:44+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 23:32:44 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 23:32:44 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 23:32:44 volumio sudo[6009]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 28 23:32:44 volumio sudo[6009]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 23:32:44 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 28 23:32:44 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Jan 28 23:32:44 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 28 23:32:44 volumio systemd[1]: shairport-sync.service: Consumed 2.324s CPU time. Jan 28 23:32:44 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 28 23:32:44 volumio sudo[6004]: pam_unix(sudo:session): session closed for user root Jan 28 23:32:44 volumio sudo[6006]: pam_unix(sudo:session): session closed for user root Jan 28 23:32:44 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 28 23:32:44 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Jan 28 23:32:44 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 28 23:32:44 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 28 23:32:44 volumio sudo[6009]: pam_unix(sudo:session): session closed for user root Jan 28 23:32:44 volumio volumio[5727]: info: Shairport-Sync Started Jan 28 23:32:44 volumio volumio[5727]: Error adding Membership: Error: addMembership EINVAL Jan 28 23:32:44 volumio volumio[5727]: info: Shairport-Sync Started Jan 28 23:32:44 volumio volumio[5727]: info: Shairport-Sync Started Jan 28 23:32:44 volumio volumio[5727]: info: CoreCommandRouter::volumioGetState Jan 28 23:32:44 volumio volumio[5727]: info: CorePlayQueue::getTrack 0 Jan 28 23:32:45 volumio volumio[5727]: SPOTIFY: User informations: {"country":"PK","display_name":"215mmgea6kss3jxeqsqdquvji","email":"linh.ngotran@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/215mmgea6kss3jxeqsqdquvji"},"followers":{"href":null,"total":1},"href":"https://api.spotify.com/v1/users/215mmgea6kss3jxeqsqdquvji","id":"215mmgea6kss3jxeqsqdquvji","images":[],"product":"premium","type":"user","uri":"spotify:user:215mmgea6kss3jxeqsqdquvji"} Jan 28 23:32:45 volumio volumio[5727]: info: Spotify Successfully logged in Jan 28 23:32:45 volumio volumio[5727]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 23:32:45 volumio volumio[5727]: info: [1769617965106] CoreMusicLibrary::Adding element Spotify Jan 28 23:32:45 volumio volumio[5727]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 23:32:45 volumio volumio[5727]: Cannot find translation for source YouTube Music Jan 28 23:32:45 volumio volumio[5727]: Cannot find translation for source Spotify Jan 28 23:32:45 volumio volumio[5727]: info: [yt-cast-receiver] DIAL server listening on port 8098 Jan 28 23:32:45 volumio volumio[5727]: info: CoreCommandRouter::volumioRetrievevolume Jan 28 23:32:45 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 23:32:45 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 23:32:45 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 23:32:46 volumio volumio[5727]: info: VolumeController:: Volume=100 Mute =false Jan 28 23:32:46 volumio volumio[5727]: info: CoreCommandRouter::volumioGetState Jan 28 23:32:46 volumio volumio[5727]: info: CorePlayQueue::getTrack 0 Jan 28 23:32:46 volumio volumio[5727]: info: CoreStateMachine::pushState Jan 28 23:32:46 volumio volumio[5727]: info: CorePlayQueue::getTrack 0 Jan 28 23:32:46 volumio volumio[5727]: info: CoreCommandRouter::volumioPushState Jan 28 23:32:46 volumio volumio[5727]: info: go-librespot daemon successfully initialized Jan 28 23:32:47 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Jan 28 23:32:47 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 23:32:47 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 23:32:47 volumio go-librespot[6045]: go-librespot daemon starting... Jan 28 23:32:47 volumio go-librespot[6046]: time="2026-01-28T23:32:47+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 23:32:47 volumio go-librespot[6046]: time="2026-01-28T23:32:47+07:00" level=debug msg="app state loaded" Jan 28 23:32:47 volumio go-librespot[6046]: time="2026-01-28T23:32:47+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 23:32:47 volumio mpd[5954]: 2026-01-28T23:32:47 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 28 23:32:47 volumio systemd[1]: Started mpd.service - Music Player Daemon. Jan 28 23:32:47 volumio sudo[5917]: pam_unix(sudo:session): session closed for user root Jan 28 23:32:47 volumio sudo[5905]: pam_unix(sudo:session): session closed for user root Jan 28 23:32:47 volumio volumio[5727]: error: MPD error: The expression evaluated to a falsy value: Jan 28 23:32:47 volumio volumio[5727]: assert.ok(self.idling) Jan 28 23:32:47 volumio volumio[5727]: error: The expression evaluated to a falsy value: Jan 28 23:32:47 volumio volumio[5727]: assert.ok(self.idling) Jan 28 23:32:47 volumio volumio[5727]: error: updateQueue error: null Jan 28 23:32:47 volumio volumio[5727]: info: Completed starting Core Plugins Jan 28 23:32:47 volumio volumio[5727]: info: ------------------------------------------- Jan 28 23:32:47 volumio volumio[5727]: info: ----- MyVolumio plugins startup ---- Jan 28 23:32:47 volumio volumio[5727]: info: ------------------------------------------- Jan 28 23:32:47 volumio volumio[5727]: info: [MyVolumio PluginManager] Fetching plans data.... Jan 28 23:32:47 volumio go-librespot[6046]: time="2026-01-28T23:32: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 28 23:32:47 volumio go-librespot[6046]: time="2026-01-28T23:32: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 28 23:32:47 volumio go-librespot[6046]: time="2026-01-28T23:32: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 28 23:32:47 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 23:32:47 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 23:32:47 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 23:32:47 volumio volumio[5727]: info: MPD running with PID5954 Jan 28 23:32:47 volumio volumio[5727]: ,establishing connection Jan 28 23:32:47 volumio go-librespot[6046]: time="2026-01-28T23:32:47+07:00" level=info msg="zeroconf server listening on port 38141" Jan 28 23:32:47 volumio volumio[5727]: error: updateQueue error: null Jan 28 23:32:48 volumio go-librespot[6046]: time="2026-01-28T23:32:48+07:00" level=debug msg="obtained new client token: AABgh3ABYA26Zx63Yh4x5aqh52lbpkIxtGSpCRUGr0FS79f/f1C4vtDZ46urCWTpbiYnZhQ0/VY95DaMBl37aHBf+I3y9mB9BVPXAXpZxIvzh0iZw/MHZUM0Kd4lpCLmu5nVJIpPGWkwkjdsuL+kEzB4zNsIXzDxH5F8XrxMAupRknvsBLzAjv/cUPp1sRNRS/qhyzo7bGbQ24vWKc3kHIoNZDKHznlD+zacxzOzzZeUkZw/xjwt3uMW" Jan 28 23:32:48 volumio go-librespot[6046]: time="2026-01-28T23:32:48+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 23:32:48 volumio go-librespot[6046]: time="2026-01-28T23:32:48+07:00" level=debug msg="completed keyexchange" Jan 28 23:32:48 volumio go-librespot[6046]: time="2026-01-28T23:32:48+07:00" level=debug msg="completed challenge" Jan 28 23:32:48 volumio go-librespot[6046]: time="2026-01-28T23:32: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 28 23:32:48 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 23:32:48 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 23:32:49 volumio volumio[5727]: info: Initializing connection to go-librespot Websocket Jan 28 23:32:49 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 23:32:49 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 23:32:49 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 23:32:49 volumio volumio[5727]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 28 23:32:51 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Jan 28 23:32:51 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 23:32:51 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 23:32:51 volumio go-librespot[6059]: go-librespot daemon starting... Jan 28 23:32:51 volumio go-librespot[6060]: time="2026-01-28T23:32:51+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 23:32:51 volumio go-librespot[6060]: time="2026-01-28T23:32:51+07:00" level=debug msg="app state loaded" Jan 28 23:32:51 volumio go-librespot[6060]: time="2026-01-28T23:32:51+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 23:32:51 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 23:32:51 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 23:32:51 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 23:32:52 volumio go-librespot[6060]: time="2026-01-28T23:32:52+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 23:32:52 volumio go-librespot[6060]: time="2026-01-28T23:32:52+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 28 23:32:52 volumio go-librespot[6060]: time="2026-01-28T23:32:52+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 28 23:32:52 volumio go-librespot[6060]: time="2026-01-28T23:32:52+07:00" level=info msg="zeroconf server listening on port 37815" Jan 28 23:32:52 volumio go-librespot[6060]: time="2026-01-28T23:32:52+07:00" level=debug msg="obtained new client token: AAAQRA4T0vWJVJabXJFaSNDZPKFIn+/FFmPHU9nuXngB2B9OoFid8me5fyEwa5r4gQkZmof34xJjMrMImYclKegNDj16kiqimQtyUZI6BHrNdLtfau7ftO0iZaoMycPJ3nBVsQ/XBKW+ZTjjGT1cW92RyrtxFXG2E1oqozw3yOFdV1KbIJHxpzKTbG4VUnzVY18oiBc1TUTZqZiCMXi0zUmR9z3kBSpc/grvynyWa3FToyB9eqVxSO4M/Zk=" Jan 28 23:32:52 volumio go-librespot[6060]: time="2026-01-28T23:32:52+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 23:32:52 volumio volumio[5727]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Jan 28 23:32:52 volumio go-librespot[6060]: time="2026-01-28T23:32:52+07:00" level=debug msg="completed keyexchange" Jan 28 23:32:52 volumio go-librespot[6060]: time="2026-01-28T23:32:52+07:00" level=debug msg="completed challenge" Jan 28 23:32:52 volumio go-librespot[6060]: time="2026-01-28T23:32: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 28 23:32:52 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 23:32:52 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 23:32:52 volumio volumio[5727]: info: Initializing connection to go-librespot Websocket Jan 28 23:32:53 volumio volumio[5727]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 28 23:32:53 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 23:32:53 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 23:32:53 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 23:32:55 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 23:32:55 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 23:32:55 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 23:32:55 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Jan 28 23:32:55 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 23:32:56 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 23:32:56 volumio go-librespot[6068]: go-librespot daemon starting... Jan 28 23:32:56 volumio go-librespot[6069]: time="2026-01-28T23:32:56+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 23:32:56 volumio go-librespot[6069]: time="2026-01-28T23:32:56+07:00" level=debug msg="app state loaded" Jan 28 23:32:56 volumio go-librespot[6069]: time="2026-01-28T23:32:56+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 23:32:56 volumio volumio[5727]: info: Initializing connection to go-librespot Websocket Jan 28 23:32:56 volumio go-librespot[6069]: time="2026-01-28T23:32:56+07:00" level=debug msg="new websocket client" Jan 28 23:32:56 volumio volumio[5727]: info: Connection to go-librespot Websocket established Jan 28 23:32:56 volumio go-librespot[6069]: time="2026-01-28T23:32: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-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 23:32:56 volumio go-librespot[6069]: time="2026-01-28T23:32:56+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 28 23:32:56 volumio go-librespot[6069]: time="2026-01-28T23:32:56+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 28 23:32:56 volumio go-librespot[6069]: time="2026-01-28T23:32:56+07:00" level=info msg="zeroconf server listening on port 42643" Jan 28 23:32:56 volumio go-librespot[6069]: time="2026-01-28T23:32:56+07:00" level=debug msg="obtained new client token: AAAkR+bjRAXOHAgf+qcGj4D4RRckzr39J/GFqG96YZm/40cApZv8uVqcIaXc11H8AUNLkVcj6oinnkBVC0hDrijJzidjSgthQv2tOHutPyolYECoBTf1NhiLbHoV+/EAdDtSBlxrMflpm5lK5G/xflNJXhj0dFbhaC3IgPfVOFTXUfM/QG4ubtvlCArWVVnqzjqyA2o0f3/nf/VDDiXjBRZ/CfafJ4UEC8wFajXJB1VUoMQ/09mFcCnpn7o=" Jan 28 23:32:56 volumio go-librespot[6069]: time="2026-01-28T23:32:56+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 23:32:57 volumio volumio[5727]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Jan 28 23:32:57 volumio volumio[5727]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Jan 28 23:32:57 volumio volumio[5727]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Jan 28 23:32:57 volumio volumio[5727]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Jan 28 23:32:57 volumio volumio[5727]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Jan 28 23:32:57 volumio volumio[5727]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Jan 28 23:32:57 volumio volumio[5727]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Jan 28 23:32:57 volumio volumio[5727]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Jan 28 23:32:57 volumio volumio[5727]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Jan 28 23:32:57 volumio volumio[5727]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Jan 28 23:32:57 volumio volumio[5727]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Jan 28 23:32:57 volumio volumio[5727]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Jan 28 23:32:57 volumio volumio[5727]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Jan 28 23:32:57 volumio volumio[5727]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Jan 28 23:32:57 volumio volumio[5727]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Jan 28 23:32:57 volumio volumio[5727]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Jan 28 23:32:57 volumio volumio[5727]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Jan 28 23:32:57 volumio volumio[5727]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Jan 28 23:32:57 volumio volumio[5727]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Jan 28 23:32:57 volumio volumio[5727]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Jan 28 23:32:57 volumio volumio[5727]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Jan 28 23:32:57 volumio volumio[5727]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Jan 28 23:32:57 volumio volumio[5727]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Jan 28 23:32:57 volumio volumio[5727]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Jan 28 23:32:57 volumio volumio[5727]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Jan 28 23:32:57 volumio volumio[5727]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Jan 28 23:32:57 volumio volumio[5727]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Jan 28 23:32:57 volumio volumio[5727]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Jan 28 23:32:57 volumio volumio[5727]: info: Adding plugin bluetooth to MyMusic Plugins Jan 28 23:32:57 volumio volumio[5727]: info: Adding plugin multiroom to MyMusic Plugins Jan 28 23:32:57 volumio volumio[5727]: info: Adding plugin metavolumio to MyMusic Plugins Jan 28 23:32:57 volumio volumio[5727]: info: Adding plugin cd_controller to MyMusic Plugins Jan 28 23:32:57 volumio go-librespot[6069]: time="2026-01-28T23:32:57+07:00" level=debug msg="completed keyexchange" Jan 28 23:32:57 volumio go-librespot[6069]: time="2026-01-28T23:32:57+07:00" level=debug msg="completed challenge" Jan 28 23:32:57 volumio volumio[5727]: info: Adding plugin qobuzconnect to MyMusic Plugins Jan 28 23:32:57 volumio volumio[5727]: info: Adding plugin smart_inputs to MyMusic Plugins Jan 28 23:32:57 volumio volumio[5727]: info: Adding plugin tidalconnect to MyMusic Plugins Jan 28 23:32:57 volumio volumio[5727]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Jan 28 23:32:57 volumio go-librespot[6069]: time="2026-01-28T23:32:57+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 23:32:57 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 23:32:57 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 23:32:57 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 23:32:57 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 23:32:57 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 23:32:58 volumio volumio[5727]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Jan 28 23:32:58 volumio volumio[5727]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Jan 28 23:32:58 volumio volumio[5727]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 23:32:58 volumio volumio[5727]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 23:32:58 volumio volumio[5727]: info: Starting MyVolumio Remote Streaming Endpoints Jan 28 23:32:58 volumio volumio[5727]: info: MyVolumio login type: Token Jan 28 23:32:58 volumio volumio[5727]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Jan 28 23:32:58 volumio volumio[5727]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Jan 28 23:32:59 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 23:32:59 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 23:32:59 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 23:33:00 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Jan 28 23:33:00 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 23:33:00 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 23:33:00 volumio go-librespot[6090]: go-librespot daemon starting... Jan 28 23:33:00 volumio go-librespot[6091]: time="2026-01-28T23:33:00+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 23:33:00 volumio go-librespot[6091]: time="2026-01-28T23:33:00+07:00" level=debug msg="app state loaded" Jan 28 23:33:00 volumio go-librespot[6091]: time="2026-01-28T23:33:00+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 23:33:00 volumio volumio[5727]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Jan 28 23:33:00 volumio volumio[5727]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Jan 28 23:33:00 volumio volumio[5727]: info: Streaming services startup Jan 28 23:33:00 volumio volumio[5727]: info: Starting Streaming Daemon Jan 28 23:33:00 volumio sudo[6098]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jan 28 23:33:00 volumio sudo[6098]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 23:33:00 volumio volumio[5727]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Jan 28 23:33:00 volumio sudo[6098]: pam_unix(sudo:session): session closed for user root Jan 28 23:33:00 volumio volumio[5727]: info: Getting Spotify volume Jan 28 23:33:00 volumio volumio[5727]: info: Connection to go-librespot Websocket closed Jan 28 23:33:00 volumio volumio[5727]: error: Cannot start Volumio Streaming Daemon Jan 28 23:33:00 volumio volumio[5727]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Jan 28 23:33:00 volumio volumio[5727]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Jan 28 23:33:00 volumio volumio[5727]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Jan 28 23:33:00 volumio go-librespot[6091]: time="2026-01-28T23:33:00+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 23:33:00 volumio go-librespot[6091]: time="2026-01-28T23:33:00+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 28 23:33:00 volumio go-librespot[6091]: time="2026-01-28T23:33:00+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 28 23:33:00 volumio go-librespot[6091]: time="2026-01-28T23:33:00+07:00" level=info msg="zeroconf server listening on port 34781" Jan 28 23:33:01 volumio volumio[5727]: info: CoreCommandRouter::volumioGetState Jan 28 23:33:01 volumio volumio[5727]: info: CorePlayQueue::getTrack 0 Jan 28 23:33:01 volumio volumio[5727]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jan 28 23:33:01 volumio volumio[5727]: SPOTIFY: SPOTIFY VOLUME undefined Jan 28 23:33:01 volumio volumio[5727]: SPOTIFY: VOLUMIO VOLUME 100 Jan 28 23:33:01 volumio volumio[5727]: info: Aligning Spotify Volume to Volumio Volume Jan 28 23:33:01 volumio volumio[5727]: info: CoreCommandRouter::volumioGetState Jan 28 23:33:01 volumio volumio[5727]: info: CorePlayQueue::getTrack 0 Jan 28 23:33:01 volumio volumio[5727]: info: Setting Spotify Volume from Volumio: 100 Jan 28 23:33:01 volumio go-librespot[6091]: time="2026-01-28T23:33:01+07:00" level=debug msg="obtained new client token: AAAMr0TljR10NMAWrD7FEFtUS95vyCQWNqy0TFOOtdT/o5sEyqcHbB61BF8m8nq158H6ww0N9erN8BwwvxE57whI5m+Hqv/fb5wbQh0MYCKiDdCyAfvAASJbycXjfYMMCTTplrIUQRhDqwtJod9aZoX/y/N/0tqe7ZNkZG4yx2nbCLowxkkhfi/9OM23p8Edx67xB7xGqeygFf31czgFBCvh37pdK9H8U+4etx325KOfqFjmbAqOMm2/" Jan 28 23:33:01 volumio go-librespot[6091]: time="2026-01-28T23:33:01+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 23:33:01 volumio go-librespot[6091]: time="2026-01-28T23:33:01+07:00" level=debug msg="completed keyexchange" Jan 28 23:33:01 volumio go-librespot[6091]: time="2026-01-28T23:33:01+07:00" level=debug msg="completed challenge" Jan 28 23:33:01 volumio go-librespot[6091]: time="2026-01-28T23:33:01+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 23:33:01 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 23:33:01 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 23:33:01 volumio volumio[5727]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 28 23:33:01 volumio volumio[5727]: Error: socket hang up Jan 28 23:33:01 volumio volumio[5727]: at connResetException (node:internal/errors:720:14) Jan 28 23:33:01 volumio volumio[5727]: at Socket.socketOnEnd (node:_http_client:519:23) Jan 28 23:33:01 volumio volumio[5727]: at Socket.emit (node:events:526:35) Jan 28 23:33:01 volumio volumio[5727]: at endReadableNT (node:internal/streams/readable:1376:12) Jan 28 23:33:01 volumio volumio[5727]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Jan 28 23:33:01 volumio volumio[5727]: code: 'ECONNRESET', Jan 28 23:33:01 volumio volumio[5727]: response: undefined Jan 28 23:33:01 volumio volumio[5727]: } Jan 28 23:33:01 volumio volumio[5727]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 28 23:33:01 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 23:33:01 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 23:33:01 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 23:33:02 volumio sudo[6119]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-01-28 23:32' Jan 28 23:33:02 volumio sudo[6119]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 23:33:03 volumio sudo[6119]: pam_unix(sudo:session): session closed for user root Jan 28 23:33:03 volumio volumio-remote-updater[628]: [2026-01-28 23:33:03] [error] handle_read_frame error: asio.system:104 (Connection reset by peer) Jan 28 23:33:03 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Jan 28 23:33:03 volumio volumio-remote-updater[628]: [2026-01-28 23:33:03] [disconnect] Disconnect close local:[1006,Connection reset by peer] remote:[1006] Jan 28 23:33:03 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Jan 28 23:33:03 volumio systemd[1]: volumio.service: Consumed 1min 3.453s CPU time. Jan 28 23:33:03 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 28 23:33:03 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Jan 28 23:33:03 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 10848. Jan 28 23:33:03 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 28 23:33:03 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Jan 28 23:33:03 volumio systemd[1]: volumio.service: Consumed 1min 3.453s CPU time. Jan 28 23:33:03 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Jan 28 23:33:03 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Jan 28 23:33:03 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 23:33:03 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 23:33:03 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 23:33:04 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Jan 28 23:33:04 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 23:33:04 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 23:33:04 volumio go-librespot[6146]: go-librespot daemon starting... Jan 28 23:33:04 volumio go-librespot[6147]: time="2026-01-28T23:33:04+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 23:33:04 volumio go-librespot[6147]: time="2026-01-28T23:33:04+07:00" level=debug msg="app state loaded" Jan 28 23:33:04 volumio go-librespot[6147]: time="2026-01-28T23:33:04+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 23:33:05 volumio go-librespot[6147]: time="2026-01-28T23:33: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 28 23:33:05 volumio go-librespot[6147]: time="2026-01-28T23:33: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 28 23:33:05 volumio go-librespot[6147]: time="2026-01-28T23:33: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 28 23:33:05 volumio go-librespot[6147]: time="2026-01-28T23:33:05+07:00" level=info msg="zeroconf server listening on port 36665" Jan 28 23:33:05 volumio go-librespot[6147]: time="2026-01-28T23:33:05+07:00" level=debug msg="obtained new client token: AAAZdqIqexIah7xIueazUv3Y/1KnpmWc+oU4TrKgEteXSMI6urenORrSliqHe1Rswb9TSrsF/jpxsl9vLgaXrcg0y8928uKi0ck6CyFkpRy0e5zB7yzBC7OzFCR1o7bXguu6ybT1q0r9m/q9/kv2VWTDyyg2GUVCEka1eib5AAW5635blZOIBhLDNmO0/KKb6YVM28oY93IThXo5qZT2mZQ7QOXinqb0xS4BGbmmHKAHYhl7Y4qMsT7424o=" Jan 28 23:33:05 volumio go-librespot[6147]: time="2026-01-28T23:33:05+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 23:33:05 volumio go-librespot[6147]: time="2026-01-28T23:33:05+07:00" level=debug msg="completed keyexchange" Jan 28 23:33:05 volumio go-librespot[6147]: time="2026-01-28T23:33:05+07:00" level=debug msg="completed challenge" Jan 28 23:33:05 volumio go-librespot[6147]: time="2026-01-28T23:33: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 28 23:33:05 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 23:33:05 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 23:33:05 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 23:33:05 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 23:33:05 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 23:33:07 volumio volumio[6131]: info: ------------------------------------------- Jan 28 23:33:07 volumio volumio[6131]: info: ----- Volumio3 ---- Jan 28 23:33:07 volumio volumio[6131]: info: ------------------------------------------- Jan 28 23:33:07 volumio volumio[6131]: info: ----- System startup ---- Jan 28 23:33:07 volumio volumio[6131]: info: ------------------------------------------- Jan 28 23:33:07 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 23:33:07 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 23:33:07 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 23:33:08 volumio volumio-remote-updater[628]: [2026-01-28 23:33:08] [connect] Successful connection Jan 28 23:33:08 volumio volumio[6131]: info: MYVOLUMIO Environment detected Jan 28 23:33:08 volumio volumio[6131]: info: Plugin folders cleanup Jan 28 23:33:08 volumio volumio[6131]: info: Scanning into folder /volumio/app/plugins/ Jan 28 23:33:08 volumio volumio[6131]: info: Scanning category audio_interface Jan 28 23:33:08 volumio volumio[6131]: info: Scanning category miscellanea Jan 28 23:33:08 volumio volumio[6131]: info: Scanning category music_service Jan 28 23:33:08 volumio volumio[6131]: info: Scanning category plugins.json Jan 28 23:33:08 volumio volumio[6131]: info: Scanning category system_controller Jan 28 23:33:08 volumio volumio[6131]: info: Scanning category user_interface Jan 28 23:33:08 volumio volumio[6131]: info: Scanning into folder /data/plugins/ Jan 28 23:33:08 volumio volumio[6131]: info: Scanning category music_service Jan 28 23:33:08 volumio volumio[6131]: info: Plugin folders cleanup completed Jan 28 23:33:08 volumio volumio[6131]: info: ------------------------------------------- Jan 28 23:33:08 volumio volumio[6131]: info: ----- Core plugins startup ---- Jan 28 23:33:08 volumio volumio[6131]: info: ------------------------------------------- Jan 28 23:33:08 volumio volumio[6131]: info: Loading plugins from folder /volumio/app/plugins/ Jan 28 23:33:08 volumio volumio[6131]: info: Adding plugin upnp to MyMusic Plugins Jan 28 23:33:08 volumio volumio[6131]: info: Adding plugin airplay_emulation to MyMusic Plugins Jan 28 23:33:08 volumio volumio[6131]: info: Adding plugin upnp_browser to MyMusic Plugins Jan 28 23:33:08 volumio volumio[6131]: info: Loading plugins from folder /data/plugins/ Jan 28 23:33:08 volumio volumio[6131]: info: Loading plugin "system"... Jan 28 23:33:08 volumio volumio[6131]: info: Loading plugin "appearance"... Jan 28 23:33:08 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Jan 28 23:33:08 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 23:33:09 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 23:33:09 volumio go-librespot[6167]: go-librespot daemon starting... Jan 28 23:33:09 volumio go-librespot[6168]: time="2026-01-28T23:33:09+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 23:33:09 volumio go-librespot[6168]: time="2026-01-28T23:33:09+07:00" level=debug msg="app state loaded" Jan 28 23:33:09 volumio go-librespot[6168]: time="2026-01-28T23:33:09+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 23:33:09 volumio go-librespot[6168]: time="2026-01-28T23:33:09+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 23:33:09 volumio go-librespot[6168]: time="2026-01-28T23:33:09+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 28 23:33:09 volumio go-librespot[6168]: time="2026-01-28T23:33:09+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 28 23:33:09 volumio go-librespot[6168]: time="2026-01-28T23:33:09+07:00" level=info msg="zeroconf server listening on port 34489" Jan 28 23:33:09 volumio go-librespot[6168]: time="2026-01-28T23:33:09+07:00" level=debug msg="obtained new client token: AACgvyqvSmKwPJjRCtB2fMzhIMdcgSkTYcQR3Rz6HQKQwDxxZ69Sni3GPyHy9lybEJIb6lif9eARWsN006E3r4My7I0mSyErcMk5/1MFeABcfpJLNXrXA5D7GwZVyJBYQyMwH5LdLBgL1jGeUtJkrwsvLW/+J9q/nW9iVoOOjXbSf5Bitkqk+7OHu4cIfNaqfj6crMNSkGaVcU2I/vK5l9KIhwhqaSHH7ftNyIyF8H57Xia8Q9jmHoWMfao=" Jan 28 23:33:09 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 23:33:09 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 23:33:09 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 23:33:09 volumio go-librespot[6168]: time="2026-01-28T23:33:09+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 23:33:10 volumio go-librespot[6168]: time="2026-01-28T23:33:10+07:00" level=debug msg="completed keyexchange" Jan 28 23:33:10 volumio go-librespot[6168]: time="2026-01-28T23:33:10+07:00" level=debug msg="completed challenge" Jan 28 23:33:10 volumio go-librespot[6168]: time="2026-01-28T23:33:10+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 23:33:10 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 23:33:10 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 23:33:10 volumio volumio[6131]: info: Loading plugin "network"... Jan 28 23:33:10 volumio volumio[6131]: info: Refreshing Cached IP Addresses Jan 28 23:33:10 volumio sudo[6176]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 28 23:33:10 volumio sudo[6176]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 23:33:10 volumio sudo[6178]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 28 23:33:10 volumio sudo[6178]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 23:33:10 volumio volumio[6131]: info: Loading plugin "services"... Jan 28 23:33:10 volumio sudo[6176]: pam_unix(sudo:session): session closed for user root Jan 28 23:33:10 volumio sudo[6178]: pam_unix(sudo:session): session closed for user root Jan 28 23:33:10 volumio volumio[6131]: info: Loading plugin "alsa_controller"... Jan 28 23:33:10 volumio sudo[6185]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Jan 28 23:33:10 volumio sudo[6185]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 23:33:10 volumio volumio[6131]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 28 23:33:11 volumio volumio[6131]: info: Loading plugin "wizard"... Jan 28 23:33:11 volumio volumio[6131]: info: Loading plugin "networkfs"... Jan 28 23:33:11 volumio volumio[6131]: info: Starting Udev Watcher for removable devices Jan 28 23:33:11 volumio volumio[6131]: info: Ignoring mount for partition: boot Jan 28 23:33:11 volumio volumio[6131]: info: Ignoring mount for partition: volumio Jan 28 23:33:11 volumio volumio[6131]: info: Ignoring mount for partition: volumio_data Jan 28 23:33:11 volumio volumio[6131]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 28 23:33:11 volumio volumio[6131]: info: Loading plugin "volumio_command_line_client"... Jan 28 23:33:11 volumio volumio[6131]: info: Loading plugin "upnp"... Jan 28 23:33:11 volumio volumio[6131]: info: [1769617991147] Starting Upmpd Daemon Jan 28 23:33:11 volumio volumio[6131]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 28 23:33:11 volumio volumio[6131]: info: Loading plugin "my_music"... Jan 28 23:33:11 volumio volumio[6131]: info: Loading plugin "mpd"... Jan 28 23:33:11 volumio volumio[6131]: info: Loading plugin "upnp_browser"... Jan 28 23:33:11 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 23:33:11 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 23:33:11 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 23:33:13 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Jan 28 23:33:13 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 23:33:13 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 23:33:13 volumio go-librespot[6212]: go-librespot daemon starting... Jan 28 23:33:13 volumio go-librespot[6213]: time="2026-01-28T23:33:13+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 23:33:13 volumio go-librespot[6213]: time="2026-01-28T23:33:13+07:00" level=debug msg="app state loaded" Jan 28 23:33:13 volumio go-librespot[6213]: time="2026-01-28T23:33:13+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 23:33:13 volumio sudo[6185]: pam_unix(sudo:session): session closed for user root Jan 28 23:33:13 volumio go-librespot[6213]: time="2026-01-28T23:33: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-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 23:33:13 volumio go-librespot[6213]: time="2026-01-28T23:33:13+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 28 23:33:13 volumio go-librespot[6213]: time="2026-01-28T23:33:13+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 28 23:33:13 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 23:33:13 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 23:33:13 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 23:33:13 volumio go-librespot[6213]: time="2026-01-28T23:33:13+07:00" level=info msg="zeroconf server listening on port 40481" Jan 28 23:33:14 volumio go-librespot[6213]: time="2026-01-28T23:33:14+07:00" level=debug msg="obtained new client token: AAB3KdqSyrPpkCEdvvsU3iNPZ+Nwa79ubO8NpdxkxBHxYAzw3k/F8rnFznqpnXye4yupYuJVbxOhyumW45BioBkqscKT24xIEyRdc7hHlZcoQP+piGVgkUBfn4AwX0CDMOoAFV87qkDcPoJNULsyzA9ZcDQfPrB3utwVJkfRIR2nCEaFnka6jUEwdnrQgUq15Y6PoKT4pMcQFBcsfx3sUVaI6K/5uh/tPLb4mUqc3KPyFM0suU7o59Hw" Jan 28 23:33:14 volumio go-librespot[6213]: time="2026-01-28T23:33:14+07:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:4070, retrying with a different AP" error="dial tcp 104.199.241.202:4070: connect: connection refused" Jan 28 23:33:14 volumio go-librespot[6213]: time="2026-01-28T23:33:14+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Jan 28 23:33:14 volumio go-librespot[6213]: time="2026-01-28T23:33:14+07:00" level=debug msg="completed keyexchange" Jan 28 23:33:14 volumio go-librespot[6213]: time="2026-01-28T23:33:14+07:00" level=debug msg="completed challenge" Jan 28 23:33:14 volumio go-librespot[6213]: time="2026-01-28T23:33:14+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 23:33:14 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 23:33:14 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 23:33:14 volumio volumio[6131]: info: Starting UPNP Browser Jan 28 23:33:14 volumio volumio[6131]: info: Loading plugin "alarm-clock"... Jan 28 23:33:15 volumio volumio[6131]: info: Loading plugin "airplay_emulation"... Jan 28 23:33:15 volumio volumio[6131]: info: Starting Shairport Sync Jan 28 23:33:15 volumio volumio[6131]: info: Loading plugin "last_100"... Jan 28 23:33:15 volumio volumio[6131]: info: Loading plugin "webradio"... Jan 28 23:33:15 volumio volumio[6131]: info: Loading plugin "i2s_dacs"... Jan 28 23:33:15 volumio volumio[6131]: info: Loading plugin "volumiodiscovery"... Jan 28 23:33:15 volumio volumio[6131]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 28 23:33:15 volumio volumio[6131]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 23:33:15 volumio node[6131]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 28 23:33:15 volumio volumio[6131]: *** WARNING *** For more information see Jan 28 23:33:15 volumio volumio[6131]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 28 23:33:15 volumio volumio[6131]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 23:33:15 volumio volumio[6131]: *** WARNING *** For more information see Jan 28 23:33:15 volumio node[6131]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 23:33:15 volumio node[6131]: *** WARNING *** For more information see Jan 28 23:33:15 volumio node[6131]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 28 23:33:15 volumio node[6131]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 23:33:15 volumio node[6131]: *** WARNING *** For more information see Jan 28 23:33:15 volumio volumio[6131]: info: Applying required configuration parameters for plugin volumiodiscovery Jan 28 23:33:15 volumio volumio[6131]: info: Discovery: Started advertising with name: Volumio Jan 28 23:33:15 volumio volumio[6131]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 28 23:33:15 volumio volumio[6131]: info: Loading plugin "spop"... Jan 28 23:33:15 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 23:33:15 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 23:33:15 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 23:33:17 volumio volumio[6131]: info: Loading plugin "ytcr"... Jan 28 23:33:17 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Jan 28 23:33:17 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 23:33:17 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 23:33:17 volumio go-librespot[6222]: go-librespot daemon starting... Jan 28 23:33:17 volumio go-librespot[6223]: time="2026-01-28T23:33:17+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 23:33:17 volumio go-librespot[6223]: time="2026-01-28T23:33:17+07:00" level=debug msg="app state loaded" Jan 28 23:33:17 volumio go-librespot[6223]: time="2026-01-28T23:33:17+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 23:33:17 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 23:33:17 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 23:33:17 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 23:33:18 volumio go-librespot[6223]: time="2026-01-28T23:33:18+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 23:33:18 volumio go-librespot[6223]: time="2026-01-28T23:33:18+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 28 23:33:18 volumio go-librespot[6223]: time="2026-01-28T23:33:18+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 28 23:33:18 volumio go-librespot[6223]: time="2026-01-28T23:33:18+07:00" level=info msg="zeroconf server listening on port 42047" Jan 28 23:33:18 volumio go-librespot[6223]: time="2026-01-28T23:33:18+07:00" level=debug msg="obtained new client token: AACP9rLeibzdUFiTlZEfnDT1TZnMGvUYqwbmAkJpTLxRBZhWZB8d/1L8ws+sKRply5mKdrNvYctLiJHAeCICG5vuYvGb9bIz7PfammxSHNMlbHgMpq3citCiyF4JaUFloc6l9oACOyHGJX6n869Q2oTqCjGxUNUZgifYPstE4m4upl3ZrTFkSIyj48dgrQDNftgsXRQpaIpmahIlXfwGUOeR23fwVLVNZP7n+NPAOR87hW0FvfqbDsIBWs4=" Jan 28 23:33:18 volumio go-librespot[6223]: time="2026-01-28T23:33:18+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 23:33:18 volumio go-librespot[6223]: time="2026-01-28T23:33:18+07:00" level=debug msg="completed keyexchange" Jan 28 23:33:18 volumio go-librespot[6223]: time="2026-01-28T23:33:18+07:00" level=debug msg="completed challenge" Jan 28 23:33:18 volumio go-librespot[6223]: time="2026-01-28T23:33: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 28 23:33:18 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 23:33:18 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 23:33:19 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 23:33:19 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 23:33:19 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 23:33:19 volumio volumio[6131]: info: Loading plugin "ytmusic"... Jan 28 23:33:20 volumio volumio-remote-updater[628]: [2026-01-28 23:33:20] [connect] Successful connection Jan 28 23:33:21 volumio volumio[6131]: info: Loading plugin "outputs"... Jan 28 23:33:21 volumio volumio[6131]: info: Loading plugin "albumart"... Jan 28 23:33:21 volumio volumio[6131]: info: Plugin example_plugin is not enabled Jan 28 23:33:21 volumio volumio[6131]: info: Loading plugin "inputs"... Jan 28 23:33:21 volumio volumio[6131]: info: Loading plugin "updater_comm"... Jan 28 23:33:21 volumio volumio[6131]: info: Plugin mpdemulation is not enabled Jan 28 23:33:21 volumio volumio[6131]: info: Loading plugin "rest_api"... Jan 28 23:33:21 volumio volumio[6131]: info: Loading plugin "websocket"... Jan 28 23:33:21 volumio volumio[6131]: info: Starting Socket.io Server version 1.7.4 Jan 28 23:33:21 volumio volumio[6131]: info: Loading plugin "RoonBridge"... Jan 28 23:33:21 volumio volumio[6131]: info: Applying required configuration parameters for plugin RoonBridge Jan 28 23:33:21 volumio volumio[6131]: info: Loading i18n strings for locale en Jan 28 23:33:21 volumio volumio[6131]: Updating browse sources language Jan 28 23:33:21 volumio volumio[6131]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 23:33:21 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 23:33:21 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 23:33:21 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 23:33:21 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Jan 28 23:33:21 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 23:33:22 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 23:33:22 volumio go-librespot[6254]: go-librespot daemon starting... Jan 28 23:33:22 volumio go-librespot[6255]: time="2026-01-28T23:33:22+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 23:33:22 volumio go-librespot[6255]: time="2026-01-28T23:33:22+07:00" level=debug msg="app state loaded" Jan 28 23:33:22 volumio go-librespot[6255]: time="2026-01-28T23:33:22+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 23:33:22 volumio volumio[6131]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 28 23:33:22 volumio volumio[6131]: info: CoreCommandRouter::initPlayerControls Jan 28 23:33:22 volumio volumio[6131]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 23:33:22 volumio volumio[6131]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 23:33:22 volumio volumio[6131]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 23:33:22 volumio volumio[6131]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 23:33:22 volumio volumio[6131]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 23:33:22 volumio volumio[6131]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 23:33:22 volumio volumio[6131]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 23:33:22 volumio volumio[6131]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 23:33:22 volumio volumio[6131]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 28 23:33:22 volumio volumio[6131]: Express server listening on port 3000 Jan 28 23:33:22 volumio volumio[6131]: [Metrics] WebUI: 15s 994.74ms Jan 28 23:33:22 volumio volumio[6244]: Forking 3 albumart workers Jan 28 23:33:22 volumio volumio[6131]: info: CoreStateMachine::resetVolumioState Jan 28 23:33:22 volumio volumio[6131]: info: CoreStateMachine::getcurrentVolume Jan 28 23:33:22 volumio volumio[6131]: info: CoreCommandRouter::volumioRetrievevolume Jan 28 23:33:22 volumio sudo[6269]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 28 23:33:22 volumio sudo[6269]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 23:33:22 volumio sudo[6286]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 28 23:33:22 volumio sudo[6269]: pam_unix(sudo:session): session closed for user root Jan 28 23:33:22 volumio sudo[6286]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 23:33:22 volumio sudo[6286]: pam_unix(sudo:session): session closed for user root Jan 28 23:33:22 volumio volumio[6131]: info: Volumio Network Manager: Network status updated: 1 Jan 28 23:33:22 volumio go-librespot[6255]: time="2026-01-28T23:33: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 28 23:33:22 volumio go-librespot[6255]: time="2026-01-28T23:33: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 28 23:33:22 volumio go-librespot[6255]: time="2026-01-28T23:33: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 28 23:33:22 volumio go-librespot[6255]: time="2026-01-28T23:33:22+07:00" level=info msg="zeroconf server listening on port 45839" Jan 28 23:33:22 volumio volumio[6131]: info: VolumeController:: Volume=100 Mute =false Jan 28 23:33:22 volumio volumio[6131]: info: CoreStateMachine::pushState Jan 28 23:33:22 volumio volumio[6131]: info: CorePlayQueue::getTrack 0 Jan 28 23:33:22 volumio volumio[6131]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 28 23:33:22 volumio volumio[6131]: info: CoreCommandRouter::volumioPushState Jan 28 23:33:22 volumio volumio[6131]: info: CoreStateMachine::updateTrackBlock Jan 28 23:33:22 volumio volumio[6131]: info: CorePlayQueue::getTrackBlock Jan 28 23:33:22 volumio volumio[6131]: info: CoreCommandRouter::volumioRetrievevolume Jan 28 23:33:22 volumio volumio-remote-updater[628]: [2026-01-28 23:33:22] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1769618000 101 Jan 28 23:33:23 volumio volumio[6131]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 1 Jan 28 23:33:23 volumio go-librespot[6255]: time="2026-01-28T23:33:23+07:00" level=debug msg="obtained new client token: AADBmbK9q90GYxUZT7Uq0n2qpa6B2M5B73FYucVlIkz9Fe9vrw/nyZg0xw95Hsy3dMHeIOrL7iR1cPVqQdqS2JAojuzmF4piourQthKVnxOZPH0ExpDoU/ltPjKABSg6bRllYjqJ3//fAGU+P5ucOw69lGWsubQh9LCjK3VHd74HGCT8GEdO6fjLkuDCjWXsMpAiXsMocC/2svJWtekzbijoRzbMxgGj0p0NF669MO2vfBWMVUx/Vs8CHjY=" Jan 28 23:33:23 volumio volumio[6131]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 23:33:23 volumio volumio[6131]: info: Reloading queue from file Jan 28 23:33:23 volumio volumio[6131]: info: CoreStateMachine::setRepeat null single undefined Jan 28 23:33:23 volumio volumio[6131]: info: CoreStateMachine::pushState Jan 28 23:33:23 volumio volumio[6131]: info: CorePlayQueue::getTrack 0 Jan 28 23:33:23 volumio volumio[6131]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 28 23:33:23 volumio volumio[6131]: info: CoreCommandRouter::volumioPushState Jan 28 23:33:23 volumio go-librespot[6255]: time="2026-01-28T23:33:23+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 23:33:23 volumio volumio[6131]: info: CoreStateMachine::setRandom null Jan 28 23:33:23 volumio volumio[6131]: info: CoreStateMachine::pushState Jan 28 23:33:23 volumio volumio[6131]: info: CorePlayQueue::getTrack 0 Jan 28 23:33:23 volumio volumio[6131]: info: CoreCommandRouter::volumioPushState Jan 28 23:33:23 volumio volumio[6131]: info: Setting Device type: Raspberry PI Jan 28 23:33:23 volumio volumio[6131]: info: Completed loading Core Plugins Jan 28 23:33:23 volumio volumio[6131]: info: Preparing to generate the ALSA configuration file Jan 28 23:33:23 volumio go-librespot[6255]: time="2026-01-28T23:33:23+07:00" level=debug msg="completed keyexchange" Jan 28 23:33:23 volumio go-librespot[6255]: time="2026-01-28T23:33:23+07:00" level=debug msg="completed challenge" Jan 28 23:33:23 volumio volumio[6131]: info: VolumeController:: Volume=100 Mute =false Jan 28 23:33:23 volumio volumio[6131]: info: CoreStateMachine::pushState Jan 28 23:33:23 volumio volumio[6131]: info: CorePlayQueue::getTrack 0 Jan 28 23:33:23 volumio volumio[6131]: info: CoreCommandRouter::volumioPushState Jan 28 23:33:23 volumio go-librespot[6255]: time="2026-01-28T23:33:23+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 23:33:23 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 23:33:23 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 23:33:23 volumio volumio[6131]: info: Asound.conf file unchanged, so no further update is needed Jan 28 23:33:23 volumio volumio[6131]: info: Output device has changed, restarting MPD Jan 28 23:33:23 volumio volumio[6131]: info: Output device has changed, restarting Shairport Sync Jan 28 23:33:23 volumio volumio[6131]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 23:33:23 volumio volumio[6131]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 23:33:23 volumio sudo[6313]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Jan 28 23:33:23 volumio sudo[6313]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 23:33:23 volumio sudo[6315]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 28 23:33:23 volumio sudo[6315]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 23:33:23 volumio sudo[6317]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 28 23:33:23 volumio sudo[6315]: pam_unix(sudo:session): session closed for user root Jan 28 23:33:23 volumio volumio[6131]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 28 23:33:23 volumio sudo[6317]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 23:33:23 volumio volumio[6131]: info: ___________ START PLUGINS ___________ Jan 28 23:33:23 volumio volumio[6131]: info: ControllerMpd::onStart: Initializing MPD Jan 28 23:33:23 volumio volumio[6131]: info: Creating MPD Configuration file Jan 28 23:33:23 volumio sudo[6313]: pam_unix(sudo:session): session closed for user root Jan 28 23:33:23 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Jan 28 23:33:23 volumio volumio[6131]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 28 23:33:23 volumio volumio[6131]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 23:33:23 volumio volumio[6131]: info: [1769618003751] CoreMusicLibrary::Adding element Media Servers Jan 28 23:33:23 volumio volumio[6131]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 23:33:23 volumio volumio[6131]: info: UPNP Browser: Client initialized successfully Jan 28 23:33:23 volumio sudo[6326]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 28 23:33:23 volumio sudo[6328]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 28 23:33:23 volumio sudo[6326]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 23:33:23 volumio sudo[6328]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 23:33:23 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 28 23:33:23 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 28 23:33:23 volumio systemd[1]: mpd.service: Consumed 7.542s CPU time. Jan 28 23:33:23 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 28 23:33:23 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 28 23:33:23 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 28 23:33:23 volumio sudo[6326]: pam_unix(sudo:session): session closed for user root Jan 28 23:33:23 volumio volumio[6131]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 23:33:23 volumio volumio[6131]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 23:33:23 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 23:33:23 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 23:33:23 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 23:33:23 volumio volumio[6131]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 28 23:33:23 volumio volumio[6131]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 23:33:23 volumio volumio[6131]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 23:33:23 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 28 23:33:23 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 28 23:33:24 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 28 23:33:24 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 28 23:33:24 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 28 23:33:24 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 28 23:33:24 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 28 23:33:24 volumio volumio[6131]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 28 23:33:24 volumio volumio[6131]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 23:33:24 volumio volumio[6131]: info: [1769618004099] CoreMusicLibrary::Adding element Last_100 Jan 28 23:33:24 volumio volumio[6131]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 23:33:24 volumio volumio[6131]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 23:33:24 volumio volumio[6131]: info: [1769618004109] CoreMusicLibrary::Adding element Webradio Jan 28 23:33:24 volumio volumio[6131]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 23:33:24 volumio volumio[6131]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 28 23:33:24 volumio volumio[6131]: info: Initializing BBC Radios Jan 28 23:33:24 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 28 23:33:24 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 28 23:33:24 volumio volumio[6131]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 28 23:33:24 volumio volumio[6131]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 23:33:24 volumio volumio[6131]: info: Creating Spotify config file Jan 28 23:33:24 volumio volumio[6131]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 23:33:24 volumio sudo[6345]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 28 23:33:24 volumio sudo[6345]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jan 28 23:33:24 volumio sudo[6345]: pam_unix(sudo:session): session closed for user root Jan 28 23:33:25 volumio volumio[6266]: Starting albumart workers Jan 28 23:33:25 volumio volumio[6131]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 23:33:25 volumio volumio[6131]: info: [1769618005697] CoreMusicLibrary::Adding element YouTube Music Jan 28 23:33:25 volumio volumio[6131]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 23:33:25 volumio volumio[6131]: Cannot find translation for source YouTube Music Jan 28 23:33:25 volumio volumio[6131]: info: Volumio Calling Home Jan 28 23:33:25 volumio volumio[6267]: Starting albumart workers Jan 28 23:33:25 volumio sudo[6359]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Jan 28 23:33:25 volumio sudo[6359]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 23:33:25 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 23:33:25 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 23:33:25 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 23:33:25 volumio sudo[6359]: pam_unix(sudo:session): session closed for user root Jan 28 23:33:26 volumio volumio[6264]: Starting albumart workers Jan 28 23:33:26 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Jan 28 23:33:26 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 23:33:26 volumio volumio[6131]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Jan 28 23:33:26 volumio volumio[6131]: info: Discovery: Found device Volumio Jan 28 23:33:26 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 23:33:26 volumio go-librespot[6364]: go-librespot daemon starting... Jan 28 23:33:26 volumio volumio[6131]: info: CoreCommandRouter::volumioGetState Jan 28 23:33:26 volumio volumio[6131]: info: CorePlayQueue::getTrack 0 Jan 28 23:33:26 volumio volumio[6131]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Jan 28 23:33:26 volumio volumio[6131]: info: Discovery: Found device Volumio Jan 28 23:33:26 volumio volumio[6131]: info: CoreCommandRouter::volumioGetState Jan 28 23:33:26 volumio volumio[6131]: info: CorePlayQueue::getTrack 0 Jan 28 23:33:26 volumio go-librespot[6365]: time="2026-01-28T23:33:26+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 23:33:26 volumio go-librespot[6365]: time="2026-01-28T23:33:26+07:00" level=debug msg="app state loaded" Jan 28 23:33:26 volumio go-librespot[6365]: time="2026-01-28T23:33:26+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 23:33:26 volumio volumio[6131]: info: MPD Permissions set Jan 28 23:33:26 volumio volumio[6131]: info: MPD Permissions set Jan 28 23:33:26 volumio volumio[6131]: info: Upmpdcli Daemon Started Jan 28 23:33:26 volumio volumio[6131]: info: Spotify config file written Jan 28 23:33:27 volumio sudo[6372]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jan 28 23:33:27 volumio sudo[6372]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 23:33:27 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Jan 28 23:33:27 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Jan 28 23:33:27 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 23:33:27 volumio volumio[6131]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Jan 28 23:33:27 volumio volumio[6131]: info: Volumio called home Jan 28 23:33:27 volumio volumio[6131]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 23:33:27 volumio volumio[6131]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 23:33:27 volumio volumio[6131]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 23:33:27 volumio volumio[6131]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 23:33:27 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 23:33:27 volumio volumio[6131]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 23:33:27 volumio volumio[6131]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 23:33:27 volumio volumio[6131]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 23:33:27 volumio volumio[6131]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 23:33:27 volumio go-librespot[6376]: go-librespot daemon starting... Jan 28 23:33:27 volumio sudo[6372]: pam_unix(sudo:session): session closed for user root Jan 28 23:33:27 volumio volumio[6131]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 23:33:27 volumio volumio[6131]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 23:33:27 volumio volumio[6131]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 23:33:27 volumio volumio[6131]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 23:33:27 volumio volumio[6131]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 23:33:27 volumio volumio[6131]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 23:33:27 volumio volumio[6131]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 23:33:27 volumio go-librespot[6377]: time="2026-01-28T23:33:27+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 23:33:27 volumio go-librespot[6377]: time="2026-01-28T23:33:27+07:00" level=debug msg="app state loaded" Jan 28 23:33:27 volumio go-librespot[6377]: time="2026-01-28T23:33:27+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 23:33:27 volumio volumio[6131]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 23:33:27 volumio volumio[6131]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 23:33:27 volumio volumio[6131]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 23:33:27 volumio volumio[6131]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 23:33:27 volumio volumio[6131]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 23:33:27 volumio volumio[6131]: info: No need to fix Spotify hosts Jan 28 23:33:27 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 23:33:27 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 23:33:27 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 23:33:28 volumio go-librespot[6377]: time="2026-01-28T23:33:28+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 23:33:28 volumio go-librespot[6377]: time="2026-01-28T23:33:28+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 28 23:33:28 volumio go-librespot[6377]: time="2026-01-28T23:33:28+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 28 23:33:28 volumio go-librespot[6377]: time="2026-01-28T23:33:28+07:00" level=info msg="zeroconf server listening on port 35083" Jan 28 23:33:28 volumio go-librespot[6377]: time="2026-01-28T23:33:28+07:00" level=debug msg="obtained new client token: AAA03oS5KWiLdYmq9DXau2bv13LqB8mOO2fWAQ80I5UkFgnr2BzZ5VrkCarbdqFY5PiMATfyCXb6Z1p4sh6S1R0Cdc3HMHLdrN2FaOx5D7BhQmORw2bjre8vcjj7tbrqEKtPC2N6YO+1eiUDoOf8HDYDwZJ84hhu0xuchNG9ln/pkJVmlShqz7DcJEIZyr/PVgmUtTZfkLODMW+Y9Hne1PXubTGawNAj0zLsdBy7i+URMtgJGjl1omUuudY=" Jan 28 23:33:28 volumio go-librespot[6377]: time="2026-01-28T23:33:28+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 23:33:28 volumio volumio[6131]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 28 23:33:28 volumio volumio[6131]: SPOTIFY: BQCAi0yIKZt6BVrJlc2T24dgCa3SgvkI1obQpFCwSu2cV2vuykaOVI37ZTFpLriMo7c7PdceRXDL2KdRFLJs8HzVjdITV3iO1_JjAbcEFHnITbua-sCOa71TDXjAZdb1BpFe7ads61a2WXdJLRmBmkToTOJX8fuIxInXmYtLsVMAjm71mAEFbyIbZG6hVO2rAmOVe05VnAKGlEcnWnJ7MD8BmOY3k9Q6rS0nOHq2W4CfoOxPhGaufgGTk-Flf5CMhpZsnmW7xH2SD1qxbcniCHeoM_y-OhNpLBxKfXjWVUOeq0MGgYRl2zBz Jan 28 23:33:28 volumio volumio[6131]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 28 23:33:28 volumio volumio[6131]: info: New Spotify access token = BQCAi0yIKZt6BVrJlc2T24dgCa3SgvkI1obQpFCwSu2cV2vuykaOVI37ZTFpLriMo7c7PdceRXDL2KdRFLJs8HzVjdITV3iO1_JjAbcEFHnITbua-sCOa71TDXjAZdb1BpFe7ads61a2WXdJLRmBmkToTOJX8fuIxInXmYtLsVMAjm71mAEFbyIbZG6hVO2rAmOVe05VnAKGlEcnWnJ7MD8BmOY3k9Q6rS0nOHq2W4CfoOxPhGaufgGTk-Flf5CMhpZsnmW7xH2SD1qxbcniCHeoM_y-OhNpLBxKfXjWVUOeq0MGgYRl2zBz Jan 28 23:33:28 volumio volumio[6131]: info: Spotify credentials grant success - running version from March 24, 2019 Jan 28 23:33:28 volumio go-librespot[6377]: time="2026-01-28T23:33:28+07:00" level=debug msg="completed keyexchange" Jan 28 23:33:28 volumio go-librespot[6377]: time="2026-01-28T23:33:28+07:00" level=debug msg="completed challenge" Jan 28 23:33:28 volumio volumio[6131]: info: Starting Shairport Sync Jan 28 23:33:28 volumio go-librespot[6377]: time="2026-01-28T23:33:28+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 23:33:28 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 23:33:28 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 23:33:28 volumio volumio[6131]: info: Starting Shairport Sync Jan 28 23:33:28 volumio volumio[6131]: info: Starting Shairport Sync Jan 28 23:33:28 volumio sudo[6416]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 28 23:33:28 volumio sudo[6414]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 28 23:33:28 volumio sudo[6414]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 23:33:28 volumio sudo[6416]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 23:33:28 volumio sudo[6418]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 28 23:33:28 volumio sudo[6418]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 23:33:29 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 28 23:33:29 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Jan 28 23:33:29 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 28 23:33:29 volumio systemd[1]: shairport-sync.service: Consumed 2.430s CPU time. Jan 28 23:33:29 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 28 23:33:29 volumio sudo[6418]: pam_unix(sudo:session): session closed for user root Jan 28 23:33:29 volumio sudo[6416]: pam_unix(sudo:session): session closed for user root Jan 28 23:33:29 volumio sudo[6414]: pam_unix(sudo:session): session closed for user root Jan 28 23:33:29 volumio volumio[6131]: info: Shairport-Sync Started Jan 28 23:33:29 volumio volumio[6131]: Error adding Membership: Error: addMembership EINVAL Jan 28 23:33:29 volumio volumio[6131]: info: Shairport-Sync Started Jan 28 23:33:29 volumio volumio[6131]: info: Shairport-Sync Started Jan 28 23:33:29 volumio volumio[6131]: info: CoreCommandRouter::volumioGetState Jan 28 23:33:29 volumio volumio[6131]: info: CorePlayQueue::getTrack 0 Jan 28 23:33:29 volumio volumio[6131]: SPOTIFY: User informations: {"country":"PK","display_name":"215mmgea6kss3jxeqsqdquvji","email":"linh.ngotran@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/215mmgea6kss3jxeqsqdquvji"},"followers":{"href":null,"total":1},"href":"https://api.spotify.com/v1/users/215mmgea6kss3jxeqsqdquvji","id":"215mmgea6kss3jxeqsqdquvji","images":[],"product":"premium","type":"user","uri":"spotify:user:215mmgea6kss3jxeqsqdquvji"} Jan 28 23:33:29 volumio volumio[6131]: info: Spotify Successfully logged in Jan 28 23:33:29 volumio volumio[6131]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 23:33:29 volumio volumio[6131]: info: [1769618009607] CoreMusicLibrary::Adding element Spotify Jan 28 23:33:29 volumio volumio[6131]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 23:33:29 volumio volumio[6131]: Cannot find translation for source YouTube Music Jan 28 23:33:29 volumio volumio[6131]: Cannot find translation for source Spotify Jan 28 23:33:29 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 23:33:29 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 23:33:29 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 23:33:30 volumio volumio[6131]: info: [yt-cast-receiver] DIAL server listening on port 8098 Jan 28 23:33:30 volumio volumio[6131]: info: CoreCommandRouter::volumioRetrievevolume Jan 28 23:33:30 volumio volumio[6131]: info: VolumeController:: Volume=100 Mute =false Jan 28 23:33:30 volumio volumio[6131]: info: CoreCommandRouter::volumioGetState Jan 28 23:33:30 volumio volumio[6131]: info: CorePlayQueue::getTrack 0 Jan 28 23:33:30 volumio volumio[6131]: info: CoreStateMachine::pushState Jan 28 23:33:30 volumio volumio[6131]: info: CorePlayQueue::getTrack 0 Jan 28 23:33:30 volumio volumio[6131]: info: CoreCommandRouter::volumioPushState Jan 28 23:33:31 volumio volumio[6131]: info: go-librespot daemon successfully initialized Jan 28 23:33:31 volumio mpd[6357]: 2026-01-28T23:33:31 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 28 23:33:31 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Jan 28 23:33:31 volumio systemd[1]: Started mpd.service - Music Player Daemon. Jan 28 23:33:31 volumio sudo[6317]: pam_unix(sudo:session): session closed for user root Jan 28 23:33:31 volumio sudo[6328]: pam_unix(sudo:session): session closed for user root Jan 28 23:33:31 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 23:33:31 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 23:33:31 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 23:33:31 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 23:33:32 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 23:33:32 volumio go-librespot[6456]: go-librespot daemon starting... Jan 28 23:33:32 volumio go-librespot[6459]: time="2026-01-28T23:33:32+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 23:33:32 volumio go-librespot[6459]: time="2026-01-28T23:33:32+07:00" level=debug msg="app state loaded" Jan 28 23:33:32 volumio go-librespot[6459]: time="2026-01-28T23:33:32+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 23:33:32 volumio volumio[6131]: error: MPD error: The expression evaluated to a falsy value: Jan 28 23:33:32 volumio volumio[6131]: assert.ok(self.idling) Jan 28 23:33:32 volumio volumio[6131]: error: The expression evaluated to a falsy value: Jan 28 23:33:32 volumio volumio[6131]: assert.ok(self.idling) Jan 28 23:33:32 volumio volumio[6131]: error: updateQueue error: null Jan 28 23:33:32 volumio volumio[6131]: info: MPD running with PID6357 Jan 28 23:33:32 volumio volumio[6131]: ,establishing connection Jan 28 23:33:32 volumio volumio[6131]: info: Completed starting Core Plugins Jan 28 23:33:32 volumio volumio[6131]: info: ------------------------------------------- Jan 28 23:33:32 volumio volumio[6131]: info: ----- MyVolumio plugins startup ---- Jan 28 23:33:32 volumio volumio[6131]: info: ------------------------------------------- Jan 28 23:33:32 volumio volumio[6131]: info: [MyVolumio PluginManager] Fetching plans data.... Jan 28 23:33:32 volumio volumio[6131]: error: updateQueue error: null Jan 28 23:33:32 volumio go-librespot[6459]: time="2026-01-28T23:33:32+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 23:33:32 volumio go-librespot[6459]: time="2026-01-28T23:33:32+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 28 23:33:32 volumio go-librespot[6459]: time="2026-01-28T23:33:32+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 28 23:33:32 volumio go-librespot[6459]: time="2026-01-28T23:33:32+07:00" level=info msg="zeroconf server listening on port 38937" Jan 28 23:33:32 volumio go-librespot[6459]: time="2026-01-28T23:33:32+07:00" level=debug msg="obtained new client token: AAAZBWLwuq/Ch6Qrv7xqYYqDGtvCMt/cdDcT8WgHK4xYvN+krB/O6jMkbRAjTRrnR5auoR5Nm2C6GCeoLNh3TXyMe9ihqYHKC/u+KEgtwIXFuBLTSWWvOun/ucW0wvCqKio3IzEnxBbR3sfwe//j24yvWCo3FVBEKRbTrgFJbuXRUOq623bFNkiVkLAM4hqvRCtWjwBKEbiYm7xk1diksIctHjwRZRvqZxuZlMWQ/NsKPNtdPLtm3jvBkp0=" Jan 28 23:33:33 volumio go-librespot[6459]: time="2026-01-28T23:33:33+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 23:33:33 volumio go-librespot[6459]: time="2026-01-28T23:33:33+07:00" level=debug msg="completed keyexchange" Jan 28 23:33:33 volumio go-librespot[6459]: time="2026-01-28T23:33:33+07:00" level=debug msg="completed challenge" Jan 28 23:33:33 volumio go-librespot[6459]: time="2026-01-28T23:33:33+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 23:33:33 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 23:33:33 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 23:33:33 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 23:33:33 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 23:33:33 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 23:33:34 volumio volumio[6131]: info: Initializing connection to go-librespot Websocket Jan 28 23:33:34 volumio volumio[6131]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 28 23:33:35 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 23:33:35 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 23:33:35 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 23:33:36 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Jan 28 23:33:36 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 23:33:36 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 23:33:36 volumio go-librespot[6466]: go-librespot daemon starting... Jan 28 23:33:36 volumio go-librespot[6467]: time="2026-01-28T23:33:36+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 23:33:36 volumio go-librespot[6467]: time="2026-01-28T23:33:36+07:00" level=debug msg="app state loaded" Jan 28 23:33:36 volumio go-librespot[6467]: time="2026-01-28T23:33:36+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 23:33:37 volumio volumio[6131]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Jan 28 23:33:37 volumio go-librespot[6467]: time="2026-01-28T23:33:37+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 23:33:37 volumio go-librespot[6467]: time="2026-01-28T23:33:37+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 28 23:33:37 volumio go-librespot[6467]: time="2026-01-28T23:33:37+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 28 23:33:37 volumio go-librespot[6467]: time="2026-01-28T23:33:37+07:00" level=info msg="zeroconf server listening on port 38189" Jan 28 23:33:37 volumio go-librespot[6467]: time="2026-01-28T23:33:37+07:00" level=debug msg="obtained new client token: AAAByloR9GqwUevLQIlPK/JwdcpRefgSfvB6UhILOkI2wTpV2gIJ1GsawhvAO7nbEodimX1IHqoqbxTBydlgV7YgytX+2udZw5K570MFqmRY3J/5IAl17XBm4k30B8rVsb8Xjsn+CJU4LNHdldUAUnJWA7S0zQSLYszwvi1z/5f38iEH/OcIjhI5vQWAepRvgIhj+iMFh7GgyIuTKfQ/tY7RothTsRpYqiCBCMigLcH4KgGpxHK2amlG4xA=" Jan 28 23:33:37 volumio go-librespot[6467]: time="2026-01-28T23:33:37+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 23:33:37 volumio volumio[6131]: info: Initializing connection to go-librespot Websocket Jan 28 23:33:37 volumio go-librespot[6467]: time="2026-01-28T23:33:37+07:00" level=debug msg="new websocket client" Jan 28 23:33:37 volumio volumio[6131]: info: Connection to go-librespot Websocket established Jan 28 23:33:37 volumio go-librespot[6467]: time="2026-01-28T23:33:37+07:00" level=debug msg="completed keyexchange" Jan 28 23:33:37 volumio go-librespot[6467]: time="2026-01-28T23:33:37+07:00" level=debug msg="completed challenge" Jan 28 23:33:37 volumio go-librespot[6467]: time="2026-01-28T23:33:37+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 23:33:37 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 23:33:37 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 23:33:37 volumio volumio[6131]: info: Connection to go-librespot Websocket closed Jan 28 23:33:37 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 23:33:37 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 23:33:37 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 23:33:39 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 23:33:39 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 23:33:39 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 23:33:40 volumio volumio[6131]: info: Getting Spotify volume Jan 28 23:33:40 volumio volumio[6131]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 28 23:33:40 volumio volumio[6131]: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 28 23:33:40 volumio volumio[6131]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Jan 28 23:33:40 volumio volumio[6131]: errno: -111, Jan 28 23:33:40 volumio volumio[6131]: code: 'ECONNREFUSED', Jan 28 23:33:40 volumio volumio[6131]: syscall: 'connect', Jan 28 23:33:40 volumio volumio[6131]: address: '127.0.0.1', Jan 28 23:33:40 volumio volumio[6131]: port: 9879, Jan 28 23:33:40 volumio volumio[6131]: response: undefined Jan 28 23:33:40 volumio volumio[6131]: } Jan 28 23:33:40 volumio volumio[6131]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 28 23:33:40 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Jan 28 23:33:40 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 23:33:41 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 23:33:41 volumio go-librespot[6486]: go-librespot daemon starting... Jan 28 23:33:41 volumio go-librespot[6487]: time="2026-01-28T23:33:41+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 23:33:41 volumio go-librespot[6487]: time="2026-01-28T23:33:41+07:00" level=debug msg="app state loaded" Jan 28 23:33:41 volumio go-librespot[6487]: time="2026-01-28T23:33:41+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 23:33:41 volumio go-librespot[6487]: time="2026-01-28T23:33:41+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 23:33:41 volumio go-librespot[6487]: time="2026-01-28T23:33:41+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 28 23:33:41 volumio go-librespot[6487]: time="2026-01-28T23:33:41+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 28 23:33:41 volumio go-librespot[6487]: time="2026-01-28T23:33:41+07:00" level=info msg="zeroconf server listening on port 41981" Jan 28 23:33:41 volumio go-librespot[6487]: time="2026-01-28T23:33:41+07:00" level=debug msg="obtained new client token: AAAmDr+05+ZOOVRwHuq4qX+ZPh2Yk4vX0ZSV06xXinkQqaZ27SF8svch0uJqO5doVHRKIhQpHLCnNdos22GWdSk3ShFFbSch3G3pJILp5b+cOBUIgSoXYSGjYHvsAY57khFSWWrm37aI8A8c3QsskAR4Pmgg5HVq/2H/OiRFAlJHUI7tFpCxgfoiYbNhHoxyOStjy5vXCggsIAYK0YzN0p9g/36ySWuDbUTx1MeioyyvL6s6Olu51y9Mk44=" Jan 28 23:33:41 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 23:33:41 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 23:33:41 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 23:33:41 volumio go-librespot[6487]: time="2026-01-28T23:33:41+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 23:33:42 volumio go-librespot[6487]: time="2026-01-28T23:33:42+07:00" level=debug msg="completed keyexchange" Jan 28 23:33:42 volumio go-librespot[6487]: time="2026-01-28T23:33:42+07:00" level=debug msg="completed challenge" Jan 28 23:33:42 volumio go-librespot[6487]: time="2026-01-28T23:33:42+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 23:33:42 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 23:33:42 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 23:33:42 volumio sudo[6511]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-01-28 23:32' Jan 28 23:33:42 volumio sudo[6511]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) PRETTY_NAME="Raspbian GNU/Linux 12 (bookworm)" NAME="Raspbian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="b05a530ca81d05eb9a84d0acf82089f0a60b8ee6" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="4ad85e2147d972f0b838d33c21382d2d813b2ae8" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu Dec 25 09:13:19 UTC 2025" VOLUMIO_VERSION="4.084" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="792f09af7488531aecd1aadcaa9b175e"