Jan 27 07:38:00 volumio go-librespot[27799]: time="2026-01-27T07:38: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-gew1.spotify.com:80]" Jan 27 07:38:00 volumio go-librespot[27799]: time="2026-01-27T07:38:00+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Jan 27 07:38:00 volumio go-librespot[27799]: time="2026-01-27T07:38:00+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Jan 27 07:38:00 volumio go-librespot[27799]: time="2026-01-27T07:38:00+07:00" level=info msg="zeroconf server listening on port 37399" Jan 27 07:38:00 volumio go-librespot[27799]: time="2026-01-27T07:38:00+07:00" level=debug msg="obtained new client token: AADZaFJ5EEELBclMVyRHo3n35a5Dka9bmQiOupEBHQp+0mFDpX4egUX3Nmr64H8+o6GpmcNGJBome5BMXVZYcRI+A+qS4k+xUB4OgMqszEQad/78/Z7PJCzA3ax6aHj32HwK/qKkUTH+Y81FcXGIgWBhPgh5Jtwu/qIuxvN/NkaRbxXDebvpqfF2FRSgcbyr+GGI/mHHHyKsCxa9XnwWpjpR6YGeY1QiZ9BuQxRMx9Oym1XqDgCHSsqxnXY=" Jan 27 07:38:00 volumio go-librespot[27799]: time="2026-01-27T07:38:00+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 07:38:00 volumio go-librespot[27799]: time="2026-01-27T07:38:00+07:00" level=debug msg="completed keyexchange" Jan 27 07:38:00 volumio go-librespot[27799]: time="2026-01-27T07:38:00+07:00" level=debug msg="completed challenge" Jan 27 07:38:00 volumio go-librespot[27799]: time="2026-01-27T07:38:00+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 27 07:38:00 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 07:38:00 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 07:38:01 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 07:38:01 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 07:38:01 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 07:38:01 volumio volumio[27466]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Jan 27 07:38:01 volumio volumio[27466]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Jan 27 07:38:01 volumio volumio[27466]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 07:38:01 volumio volumio[27466]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 07:38:01 volumio volumio[27466]: info: Starting MyVolumio Remote Streaming Endpoints Jan 27 07:38:01 volumio volumio[27466]: info: MyVolumio login type: Token Jan 27 07:38:01 volumio volumio[27466]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Jan 27 07:38:01 volumio volumio[27466]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Jan 27 07:38:03 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 07:38:03 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 07:38:03 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 07:38:03 volumio volumio[27466]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Jan 27 07:38:03 volumio volumio[27466]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Jan 27 07:38:03 volumio volumio[27466]: info: Streaming services startup Jan 27 07:38:03 volumio volumio[27466]: info: Starting Streaming Daemon Jan 27 07:38:03 volumio sudo[27821]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jan 27 07:38:03 volumio sudo[27821]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 07:38:03 volumio volumio[27466]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Jan 27 07:38:03 volumio sudo[27821]: pam_unix(sudo:session): session closed for user root Jan 27 07:38:03 volumio volumio[27466]: info: Initializing connection to go-librespot Websocket Jan 27 07:38:03 volumio volumio[27466]: error: Cannot start Volumio Streaming Daemon Jan 27 07:38:03 volumio volumio[27466]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Jan 27 07:38:03 volumio volumio[27466]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Jan 27 07:38:03 volumio volumio[27466]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 27 07:38:03 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 11. Jan 27 07:38:03 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 07:38:04 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 07:38:04 volumio go-librespot[27828]: go-librespot daemon starting... Jan 27 07:38:04 volumio go-librespot[27829]: time="2026-01-27T07:38:04+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 07:38:04 volumio go-librespot[27829]: time="2026-01-27T07:38:04+07:00" level=debug msg="app state loaded" Jan 27 07:38:04 volumio go-librespot[27829]: time="2026-01-27T07:38:04+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 07:38:04 volumio go-librespot[27829]: time="2026-01-27T07:38:04+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 27 07:38:04 volumio go-librespot[27829]: time="2026-01-27T07:38:04+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Jan 27 07:38:04 volumio go-librespot[27829]: time="2026-01-27T07:38:04+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Jan 27 07:38:04 volumio go-librespot[27829]: time="2026-01-27T07:38:04+07:00" level=info msg="zeroconf server listening on port 35437" Jan 27 07:38:04 volumio volumio[27466]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Jan 27 07:38:04 volumio go-librespot[27829]: time="2026-01-27T07:38:04+07:00" level=debug msg="obtained new client token: AAAyd+foLYmEjEelNr3h11S+1YWLQ1pOa2OySOGWCg+sb904xwsB17bMNZv95xPg5vrVoUDiRlXktsYAJ27qrufDDCwp3HS93gKRv1NEI13gcyvWJUKfZtwEIki+ZEPvVh+70T4MMVJVm5KT6z/hCTQt63vA292zvGTvFwik7c4YtVsmpoShfiaoNqZ8/pPpniJVQJmQvsA09/6MT0ZaXgTNdHRLquH+Pow0ndri6wB8gJWkGvsFW7mOw4E=" Jan 27 07:38:05 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 07:38:05 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 07:38:05 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 07:38:05 volumio go-librespot[27829]: time="2026-01-27T07:38:05+07:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:4070, retrying with a different AP" error="dial tcp 104.199.241.202:4070: connect: connection refused" Jan 27 07:38:05 volumio go-librespot[27829]: time="2026-01-27T07:38:05+07:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:443, retrying with a different AP" error="dial tcp 104.199.241.202:443: connect: connection refused" Jan 27 07:38:05 volumio go-librespot[27829]: time="2026-01-27T07:38:05+07:00" level=debug msg="connected to ap-gae2.spotify.com:80" Jan 27 07:38:05 volumio go-librespot[27829]: time="2026-01-27T07:38:05+07:00" level=debug msg="completed keyexchange" Jan 27 07:38:05 volumio go-librespot[27829]: time="2026-01-27T07:38:05+07:00" level=debug msg="completed challenge" Jan 27 07:38:05 volumio go-librespot[27829]: time="2026-01-27T07:38:05+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 27 07:38:05 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 07:38:05 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 07:38:05 volumio volumio[27466]: info: MyVolumio token set successfully Jan 27 07:38:05 volumio volumio[27466]: info: MYVOLUMIO: Adding device Jan 27 07:38:05 volumio volumio[27466]: info: MYVOLUMIO: Evaluating Server Jan 27 07:38:06 volumio volumio[27466]: info: MyVolumio status changed Jan 27 07:38:06 volumio volumio[27466]: info: Streaming services startup Jan 27 07:38:06 volumio volumio[27466]: info: Starting Streaming Daemon Jan 27 07:38:06 volumio volumio[27466]: info: Removing browser output: myVolumio user plan is not superstar Jan 27 07:38:06 volumio volumio[27466]: info: Removing audio output: Jan 27 07:38:06 volumio volumio[27466]: info: Stoppping Tunnel 1 Jan 27 07:38:06 volumio sudo[27857]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jan 27 07:38:06 volumio sudo[27857]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 07:38:06 volumio sudo[27859]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Jan 27 07:38:06 volumio sudo[27859]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 07:38:06 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jan 27 07:38:06 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jan 27 07:38:06 volumio volumio[27466]: info: Setting Geolocation for MyVolumio to as1 Jan 27 07:38:06 volumio volumio[27466]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 07:38:06 volumio volumio[27466]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 07:38:06 volumio volumio[27466]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 07:38:06 volumio sudo[27857]: pam_unix(sudo:session): session closed for user root Jan 27 07:38:06 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jan 27 07:38:06 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jan 27 07:38:06 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jan 27 07:38:06 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jan 27 07:38:06 volumio sudo[27859]: pam_unix(sudo:session): session closed for user root Jan 27 07:38:06 volumio volumio[27466]: error: Cannot start Volumio Streaming Daemon Jan 27 07:38:06 volumio volumio[27466]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Jan 27 07:38:06 volumio volumio[27466]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Jan 27 07:38:06 volumio volumio[27466]: info: Remote SSH Stopped Jan 27 07:38:06 volumio volumio[27466]: info: Initializing connection to go-librespot Websocket Jan 27 07:38:06 volumio volumio[27466]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 27 07:38:07 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 07:38:07 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 07:38:07 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 07:38:07 volumio volumio[27466]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Jan 27 07:38:07 volumio volumio[27466]: info: Updating MyVolumio device info Jan 27 07:38:07 volumio volumio[27466]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 07:38:07 volumio volumio[27466]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 07:38:07 volumio volumio[27466]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 07:38:08 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 12. Jan 27 07:38:08 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 07:38:08 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 07:38:08 volumio go-librespot[27863]: go-librespot daemon starting... Jan 27 07:38:08 volumio go-librespot[27864]: time="2026-01-27T07:38:08+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 07:38:08 volumio go-librespot[27864]: time="2026-01-27T07:38:08+07:00" level=debug msg="app state loaded" Jan 27 07:38:08 volumio go-librespot[27864]: time="2026-01-27T07:38:08+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 07:38:08 volumio volumio[27466]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Jan 27 07:38:09 volumio go-librespot[27864]: time="2026-01-27T07:38:09+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 27 07:38:09 volumio go-librespot[27864]: time="2026-01-27T07:38:09+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 27 07:38:09 volumio go-librespot[27864]: time="2026-01-27T07:38:09+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 27 07:38:09 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 07:38:09 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 07:38:09 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 07:38:09 volumio go-librespot[27864]: time="2026-01-27T07:38:09+07:00" level=info msg="zeroconf server listening on port 35931" Jan 27 07:38:09 volumio go-librespot[27864]: time="2026-01-27T07:38:09+07:00" level=debug msg="obtained new client token: AAD7SXpQ4AanGW8/J0rNBoFMWA71humecDwRNuIXnd32t2I3PvmT4N3VCALOLPVrAnUz7tCTLVsP81wm2T7E3ihgpkJbZajNXWpongtBH+v0uELOxz+42t4etCfJKriG/NcsrDsyu/1AKxw/SXXq4pwXodCMZuyDcCLYm8R0mq/MeM0YsfVvY5v2OFl5leftGXB52C9dRzX+kxOMeace9PFtPIaoZ7Iy4aQrcaHm5BL9rh3M9VVSgpyE" Jan 27 07:38:09 volumio go-librespot[27864]: time="2026-01-27T07:38:09+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 07:38:09 volumio go-librespot[27864]: time="2026-01-27T07:38:09+07:00" level=debug msg="completed keyexchange" Jan 27 07:38:09 volumio go-librespot[27864]: time="2026-01-27T07:38:09+07:00" level=debug msg="completed challenge" Jan 27 07:38:09 volumio go-librespot[27864]: time="2026-01-27T07:38:09+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 27 07:38:09 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 07:38:09 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 07:38:09 volumio volumio[27466]: info: Initializing connection to go-librespot Websocket Jan 27 07:38:09 volumio volumio[27466]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 27 07:38:11 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 07:38:11 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 07:38:11 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 07:38:11 volumio volumio[27466]: info: MYVOLUMIO: Adding device Jan 27 07:38:11 volumio volumio[27466]: info: MYVOLUMIO: Evaluating Server Jan 27 07:38:11 volumio volumio[27466]: info: Setting Geolocation for MyVolumio to as1 Jan 27 07:38:11 volumio volumio[27466]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 07:38:11 volumio volumio[27466]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 07:38:11 volumio volumio[27466]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 07:38:12 volumio volumio[27466]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Jan 27 07:38:12 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 13. Jan 27 07:38:12 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 07:38:12 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 07:38:12 volumio go-librespot[27905]: go-librespot daemon starting... Jan 27 07:38:12 volumio go-librespot[27906]: time="2026-01-27T07:38:12+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 07:38:12 volumio go-librespot[27906]: time="2026-01-27T07:38:12+07:00" level=debug msg="app state loaded" Jan 27 07:38:12 volumio go-librespot[27906]: time="2026-01-27T07:38:12+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 07:38:12 volumio volumio[27466]: info: Updating MyVolumio device info Jan 27 07:38:12 volumio volumio[27466]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 07:38:12 volumio volumio[27466]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 07:38:12 volumio volumio[27466]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 07:38:12 volumio volumio[27466]: info: Initializing connection to go-librespot Websocket Jan 27 07:38:12 volumio go-librespot[27906]: time="2026-01-27T07:38:12+07:00" level=debug msg="new websocket client" Jan 27 07:38:12 volumio volumio[27466]: info: Connection to go-librespot Websocket established Jan 27 07:38:13 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 07:38:13 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 07:38:13 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 07:38:13 volumio go-librespot[27906]: time="2026-01-27T07:38: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 27 07:38:13 volumio go-librespot[27906]: time="2026-01-27T07:38:13+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 27 07:38:13 volumio go-librespot[27906]: time="2026-01-27T07:38:13+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 27 07:38:13 volumio go-librespot[27906]: time="2026-01-27T07:38:13+07:00" level=info msg="zeroconf server listening on port 38651" Jan 27 07:38:13 volumio volumio[27466]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Jan 27 07:38:13 volumio go-librespot[27906]: time="2026-01-27T07:38:13+07:00" level=debug msg="obtained new client token: AACw6bvBBOiusgNUyqNZtC68ir5KArR/5hjswOYyAtAAU+JWEbOQfvuZzzgqC5Psm1CKIgHVDEcIUG1/0OTK2ii2xQ8a/Sr7vUyRA4k2XUs8LnO5DJtH5n1n2o7EPgBgNowCN8PA8sVF4aGyEnqpfLRESgLK6UITs2IevBkdTujKxONv9i2WkMQVyKaJE3DiyhBwd5oNswUgDmUMSk5SreJ55s4yiggyxZBfP/0UeqWD1audlkchQQJ/awY=" Jan 27 07:38:13 volumio go-librespot[27906]: time="2026-01-27T07:38:13+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 07:38:14 volumio volumio[27466]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 27 07:38:14 volumio volumio[27466]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 07:38:14 volumio volumio[27466]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Jan 27 07:38:14 volumio volumio-remote-updater[628]: Test mode disabled Jan 27 07:38:14 volumio volumio-remote-updater[628]: Alpha mode disabled Jan 27 07:38:14 volumio volumio-remote-updater[628]: Alpha legacy test mode disabled Jan 27 07:38:14 volumio volumio[27466]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled Jan 27 07:38:14 volumio go-librespot[27906]: time="2026-01-27T07:38:14+07:00" level=debug msg="completed keyexchange" Jan 27 07:38:14 volumio go-librespot[27906]: time="2026-01-27T07:38:14+07:00" level=debug msg="completed challenge" Jan 27 07:38:14 volumio go-librespot[27906]: time="2026-01-27T07:38:14+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 27 07:38:14 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 07:38:14 volumio volumio[27466]: info: Connection to go-librespot Websocket closed Jan 27 07:38:14 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 07:38:15 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 07:38:15 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 07:38:15 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 07:38:15 volumio volumio[27466]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Jan 27 07:38:15 volumio volumio[27466]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Jan 27 07:38:16 volumio volumio[27466]: info: Getting Spotify volume Jan 27 07:38:16 volumio volumio[27466]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 27 07:38:16 volumio volumio[27466]: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 27 07:38:16 volumio volumio[27466]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Jan 27 07:38:16 volumio volumio[27466]: errno: -111, Jan 27 07:38:16 volumio volumio[27466]: code: 'ECONNREFUSED', Jan 27 07:38:16 volumio volumio[27466]: syscall: 'connect', Jan 27 07:38:16 volumio volumio[27466]: address: '127.0.0.1', Jan 27 07:38:16 volumio volumio[27466]: port: 9879, Jan 27 07:38:16 volumio volumio[27466]: response: undefined Jan 27 07:38:16 volumio volumio[27466]: } Jan 27 07:38:16 volumio volumio[27466]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 27 07:38:17 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 07:38:17 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 07:38:17 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 07:38:17 volumio sudo[27931]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-01-27 07:37' Jan 27 07:38:17 volumio sudo[27931]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 07:38:17 volumio sudo[27931]: pam_unix(sudo:session): session closed for user root Jan 27 07:38:17 volumio volumio-remote-updater[628]: [2026-01-27 07:38:17] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Jan 27 07:38:17 volumio volumio-remote-updater[628]: [2026-01-27 07:38:17] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Jan 27 07:38:17 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Jan 27 07:38:17 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 14. Jan 27 07:38:17 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 07:38:18 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 07:38:18 volumio go-librespot[27937]: go-librespot daemon starting... Jan 27 07:38:18 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Jan 27 07:38:18 volumio systemd[1]: volumio.service: Consumed 1min 16.023s CPU time. Jan 27 07:38:18 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 27 07:38:18 volumio go-librespot[27938]: time="2026-01-27T07:38:18+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 07:38:18 volumio go-librespot[27938]: time="2026-01-27T07:38:18+07:00" level=debug msg="app state loaded" Jan 27 07:38:18 volumio go-librespot[27938]: time="2026-01-27T07:38:18+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 07:38:18 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Jan 27 07:38:18 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 8200. Jan 27 07:38:18 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 27 07:38:18 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Jan 27 07:38:18 volumio systemd[1]: volumio.service: Consumed 1min 16.023s CPU time. Jan 27 07:38:18 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Jan 27 07:38:18 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Jan 27 07:38:18 volumio go-librespot[27938]: time="2026-01-27T07:38: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 27 07:38:18 volumio go-librespot[27938]: time="2026-01-27T07:38:18+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 27 07:38:18 volumio go-librespot[27938]: time="2026-01-27T07:38:18+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 27 07:38:18 volumio go-librespot[27938]: time="2026-01-27T07:38:18+07:00" level=info msg="zeroconf server listening on port 41347" Jan 27 07:38:18 volumio go-librespot[27938]: time="2026-01-27T07:38:18+07:00" level=debug msg="obtained new client token: AABcsW8+UOF3a255wnv7CCxknoi52xXjHzYBKt8n3zvAsZLGHyjSYePnvu2PFUzwCpYGGx3tirh336NbkpOo/f6jnFl+KNzLrgh16jaYB5FbopvTcuZANPZcSybuohE/GFDZ8lRggMzjnPxjuzecEMrqIMegaK6vUw7auktK1laO76PEq4OiWLYh+0wlVq5nyhMgTJ41LMeomgQaLFBw/kfW5YINJ50/Jp7MJyAlKZJIje1zi/tqlLP+soM=" Jan 27 07:38:18 volumio go-librespot[27938]: time="2026-01-27T07:38:18+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 07:38:19 volumio go-librespot[27938]: time="2026-01-27T07:38:19+07:00" level=debug msg="completed keyexchange" Jan 27 07:38:19 volumio go-librespot[27938]: time="2026-01-27T07:38:19+07:00" level=debug msg="completed challenge" Jan 27 07:38:19 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 07:38:19 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 07:38:19 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 07:38:19 volumio go-librespot[27938]: time="2026-01-27T07:38:19+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 27 07:38:19 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 07:38:19 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 07:38:21 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 07:38:21 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 07:38:21 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 07:38:21 volumio volumio[27951]: info: ------------------------------------------- Jan 27 07:38:21 volumio volumio[27951]: info: ----- Volumio3 ---- Jan 27 07:38:21 volumio volumio[27951]: info: ------------------------------------------- Jan 27 07:38:21 volumio volumio[27951]: info: ----- System startup ---- Jan 27 07:38:21 volumio volumio[27951]: info: ------------------------------------------- Jan 27 07:38:22 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 15. Jan 27 07:38:22 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 07:38:22 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 07:38:22 volumio go-librespot[27974]: go-librespot daemon starting... Jan 27 07:38:22 volumio go-librespot[27975]: time="2026-01-27T07:38:22+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 07:38:22 volumio go-librespot[27975]: time="2026-01-27T07:38:22+07:00" level=debug msg="app state loaded" Jan 27 07:38:22 volumio go-librespot[27975]: time="2026-01-27T07:38:22+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 07:38:22 volumio go-librespot[27975]: time="2026-01-27T07:38: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-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 27 07:38:22 volumio go-librespot[27975]: time="2026-01-27T07:38:22+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 27 07:38:22 volumio go-librespot[27975]: time="2026-01-27T07:38:22+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 27 07:38:22 volumio volumio-remote-updater[628]: [2026-01-27 07:38:22] [connect] Successful connection Jan 27 07:38:22 volumio go-librespot[27975]: time="2026-01-27T07:38:22+07:00" level=info msg="zeroconf server listening on port 35975" Jan 27 07:38:23 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 07:38:23 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 07:38:23 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 07:38:23 volumio go-librespot[27975]: time="2026-01-27T07:38:23+07:00" level=debug msg="obtained new client token: AAAnPJKVEORcrxSP8KgpYf2YcX/KIIK/kvMply74cmFO0jxBGJdC5hvobBBgGDAkgDyfxfzPK2QZ4yq5cbvXAtq8UDIMZlyf3f5Nf9GuVukDOYz+4Zjq05nmmY/1+3s/q160m6z5tSzanSwcOiG5d4ESRavBKiy+txWUkaOPlFzRR/zdYQQk8uYHhh8Vj2QYRXqoMg5LEhWlfKtBgpnObb/JW6kvT38FHOqQXz04uNc1I5rIsZkRWSb2" Jan 27 07:38:23 volumio go-librespot[27975]: time="2026-01-27T07:38:23+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 07:38:23 volumio go-librespot[27975]: time="2026-01-27T07:38:23+07:00" level=debug msg="completed keyexchange" Jan 27 07:38:23 volumio go-librespot[27975]: time="2026-01-27T07:38:23+07:00" level=debug msg="completed challenge" Jan 27 07:38:23 volumio volumio[27951]: info: MYVOLUMIO Environment detected Jan 27 07:38:23 volumio go-librespot[27975]: time="2026-01-27T07:38:23+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 27 07:38:23 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 07:38:23 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 07:38:23 volumio volumio[27951]: info: Plugin folders cleanup Jan 27 07:38:23 volumio volumio[27951]: info: Scanning into folder /volumio/app/plugins/ Jan 27 07:38:23 volumio volumio[27951]: info: Scanning category audio_interface Jan 27 07:38:23 volumio volumio[27951]: info: Scanning category miscellanea Jan 27 07:38:23 volumio volumio[27951]: info: Scanning category music_service Jan 27 07:38:23 volumio volumio[27951]: info: Scanning category plugins.json Jan 27 07:38:23 volumio volumio[27951]: info: Scanning category system_controller Jan 27 07:38:23 volumio volumio[27951]: info: Scanning category user_interface Jan 27 07:38:23 volumio volumio[27951]: info: Scanning into folder /data/plugins/ Jan 27 07:38:23 volumio volumio[27951]: info: Scanning category music_service Jan 27 07:38:23 volumio volumio[27951]: info: Plugin folders cleanup completed Jan 27 07:38:23 volumio volumio[27951]: info: ------------------------------------------- Jan 27 07:38:23 volumio volumio[27951]: info: ----- Core plugins startup ---- Jan 27 07:38:23 volumio volumio[27951]: info: ------------------------------------------- Jan 27 07:38:23 volumio volumio[27951]: info: Loading plugins from folder /volumio/app/plugins/ Jan 27 07:38:23 volumio volumio[27951]: info: Adding plugin upnp to MyMusic Plugins Jan 27 07:38:23 volumio volumio[27951]: info: Adding plugin airplay_emulation to MyMusic Plugins Jan 27 07:38:23 volumio volumio[27951]: info: Adding plugin upnp_browser to MyMusic Plugins Jan 27 07:38:23 volumio volumio[27951]: info: Loading plugins from folder /data/plugins/ Jan 27 07:38:23 volumio volumio[27951]: info: Loading plugin "system"... Jan 27 07:38:23 volumio volumio[27951]: info: Loading plugin "appearance"... Jan 27 07:38:25 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 07:38:25 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 07:38:25 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 07:38:25 volumio volumio[27951]: info: Loading plugin "network"... Jan 27 07:38:25 volumio volumio[27951]: info: Refreshing Cached IP Addresses Jan 27 07:38:25 volumio sudo[27990]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 27 07:38:25 volumio sudo[27990]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 07:38:25 volumio sudo[27992]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 27 07:38:25 volumio volumio[27951]: info: Loading plugin "services"... Jan 27 07:38:25 volumio sudo[27992]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 07:38:25 volumio sudo[27990]: pam_unix(sudo:session): session closed for user root Jan 27 07:38:25 volumio volumio[27951]: info: Loading plugin "alsa_controller"... Jan 27 07:38:25 volumio sudo[27992]: pam_unix(sudo:session): session closed for user root Jan 27 07:38:25 volumio sudo[27999]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Jan 27 07:38:25 volumio sudo[27999]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 07:38:25 volumio volumio[27951]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 27 07:38:25 volumio volumio[27951]: info: Loading plugin "wizard"... Jan 27 07:38:25 volumio volumio[27951]: info: Loading plugin "networkfs"... Jan 27 07:38:25 volumio volumio[27951]: info: Starting Udev Watcher for removable devices Jan 27 07:38:25 volumio volumio[27951]: info: Ignoring mount for partition: boot Jan 27 07:38:25 volumio volumio[27951]: info: Ignoring mount for partition: volumio Jan 27 07:38:25 volumio volumio[27951]: info: Ignoring mount for partition: volumio_data Jan 27 07:38:25 volumio volumio[27951]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 27 07:38:25 volumio volumio[27951]: info: Loading plugin "volumio_command_line_client"... Jan 27 07:38:25 volumio volumio[27951]: info: Loading plugin "upnp"... Jan 27 07:38:25 volumio volumio[27951]: info: [1769474305858] Starting Upmpd Daemon Jan 27 07:38:25 volumio volumio[27951]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 27 07:38:25 volumio volumio[27951]: info: Loading plugin "my_music"... Jan 27 07:38:25 volumio volumio[27951]: info: Loading plugin "mpd"... Jan 27 07:38:26 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 16. Jan 27 07:38:26 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 07:38:26 volumio volumio[27951]: info: Loading plugin "upnp_browser"... Jan 27 07:38:26 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 07:38:26 volumio go-librespot[28023]: go-librespot daemon starting... Jan 27 07:38:26 volumio go-librespot[28024]: time="2026-01-27T07:38:26+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 07:38:26 volumio go-librespot[28024]: time="2026-01-27T07:38:26+07:00" level=debug msg="app state loaded" Jan 27 07:38:26 volumio go-librespot[28024]: time="2026-01-27T07:38:26+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 07:38:27 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 07:38:27 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 07:38:27 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 07:38:27 volumio go-librespot[28024]: time="2026-01-27T07:38:27+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 27 07:38:27 volumio go-librespot[28024]: time="2026-01-27T07:38:27+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 27 07:38:27 volumio go-librespot[28024]: time="2026-01-27T07:38:27+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 27 07:38:27 volumio go-librespot[28024]: time="2026-01-27T07:38:27+07:00" level=info msg="zeroconf server listening on port 34271" Jan 27 07:38:27 volumio go-librespot[28024]: time="2026-01-27T07:38:27+07:00" level=debug msg="obtained new client token: AABGNY7yrZFutYyDsz5fIqlS4wLGUVmNVkLpemUGTLVSr3zUWBDeNrM91djqjw4VYMGlxvYOkfKdMcZza8/g6BoDIeJCbMA9F2kKLZ7WXsfNPUioRVDcEAEw1ux5yhNIRg87VWzYBZjQbr/HF9ar63nSASW1/WWmgGDbZXOVDdT3DLIiWUTXPNi+K01NVqgXOWJbmOBzT0QHG2QYX3YtTKfQLABmrr1hr2R0xa1nULYDgwr+4bwEddcuNss=" Jan 27 07:38:27 volumio go-librespot[28024]: time="2026-01-27T07:38:27+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 07:38:27 volumio go-librespot[28024]: time="2026-01-27T07:38:27+07:00" level=debug msg="completed keyexchange" Jan 27 07:38:27 volumio go-librespot[28024]: time="2026-01-27T07:38:27+07:00" level=debug msg="completed challenge" Jan 27 07:38:27 volumio go-librespot[28024]: time="2026-01-27T07:38:27+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 27 07:38:27 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 07:38:27 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 07:38:28 volumio sudo[27999]: pam_unix(sudo:session): session closed for user root Jan 27 07:38:29 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 07:38:29 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 07:38:29 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 07:38:29 volumio volumio[27951]: info: Starting UPNP Browser Jan 27 07:38:29 volumio volumio[27951]: info: Loading plugin "alarm-clock"... Jan 27 07:38:29 volumio volumio[27951]: info: Loading plugin "airplay_emulation"... Jan 27 07:38:29 volumio volumio[27951]: info: Starting Shairport Sync Jan 27 07:38:29 volumio volumio[27951]: info: Loading plugin "last_100"... Jan 27 07:38:29 volumio volumio[27951]: info: Loading plugin "webradio"... Jan 27 07:38:30 volumio volumio[27951]: info: Loading plugin "i2s_dacs"... Jan 27 07:38:30 volumio volumio[27951]: info: Loading plugin "volumiodiscovery"... Jan 27 07:38:30 volumio volumio[27951]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 27 07:38:30 volumio volumio[27951]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 27 07:38:30 volumio volumio[27951]: *** WARNING *** For more information see Jan 27 07:38:30 volumio volumio[27951]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 27 07:38:30 volumio volumio[27951]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 27 07:38:30 volumio volumio[27951]: *** WARNING *** For more information see Jan 27 07:38:30 volumio node[27951]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 27 07:38:30 volumio node[27951]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 27 07:38:30 volumio node[27951]: *** WARNING *** For more information see Jan 27 07:38:30 volumio node[27951]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 27 07:38:30 volumio node[27951]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 27 07:38:30 volumio node[27951]: *** WARNING *** For more information see Jan 27 07:38:30 volumio volumio[27951]: info: Applying required configuration parameters for plugin volumiodiscovery Jan 27 07:38:30 volumio volumio[27951]: info: Discovery: Started advertising with name: Volumio Jan 27 07:38:30 volumio volumio[27951]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 27 07:38:30 volumio volumio[27951]: info: Loading plugin "spop"... Jan 27 07:38:30 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 17. Jan 27 07:38:30 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 07:38:30 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 07:38:30 volumio go-librespot[28034]: go-librespot daemon starting... Jan 27 07:38:30 volumio go-librespot[28035]: time="2026-01-27T07:38:30+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 07:38:30 volumio go-librespot[28035]: time="2026-01-27T07:38:30+07:00" level=debug msg="app state loaded" Jan 27 07:38:30 volumio go-librespot[28035]: time="2026-01-27T07:38:30+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 07:38:31 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 07:38:31 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 07:38:31 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 07:38:31 volumio go-librespot[28035]: time="2026-01-27T07:38:31+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 27 07:38:31 volumio go-librespot[28035]: time="2026-01-27T07:38:31+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 27 07:38:31 volumio go-librespot[28035]: time="2026-01-27T07:38:31+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 27 07:38:31 volumio go-librespot[28035]: time="2026-01-27T07:38:31+07:00" level=info msg="zeroconf server listening on port 33309" Jan 27 07:38:31 volumio go-librespot[28035]: time="2026-01-27T07:38:31+07:00" level=debug msg="obtained new client token: AACOFlH/EIsNsApPWev5m4Pi2Hc6wvqiIpWOXVXK4M0csuuI5ER+rNJM8DhCM8L1RCrougBMGHBSdHa4XreUXgzSJDQdKz993MnmDv/KmO8pHwEVz0e8x7Tzhg/6BvySbU3jI4vMcNG9xFzghK72MdnUsmjn3GJ6TkYQ8AxiqAPIem+wn3hSI6RKnfnN2zuLlrMI/A9uY+ge0Bb252KwzVX047anM9TZmhQnG+ioX0cE5KIatVBb727uWxg=" Jan 27 07:38:31 volumio go-librespot[28035]: time="2026-01-27T07:38:31+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 07:38:31 volumio go-librespot[28035]: time="2026-01-27T07:38:31+07:00" level=debug msg="completed keyexchange" Jan 27 07:38:31 volumio go-librespot[28035]: time="2026-01-27T07:38:31+07:00" level=debug msg="completed challenge" Jan 27 07:38:31 volumio go-librespot[28035]: time="2026-01-27T07:38:31+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 27 07:38:31 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 07:38:31 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 07:38:32 volumio volumio[27951]: info: Loading plugin "ytcr"... Jan 27 07:38:33 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 07:38:33 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 07:38:33 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 07:38:34 volumio volumio[27951]: info: Loading plugin "ytmusic"... Jan 27 07:38:34 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 18. Jan 27 07:38:34 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 07:38:35 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 07:38:35 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 07:38:35 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 07:38:35 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 07:38:35 volumio go-librespot[28043]: go-librespot daemon starting... Jan 27 07:38:35 volumio go-librespot[28044]: time="2026-01-27T07:38:35+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 07:38:35 volumio go-librespot[28044]: time="2026-01-27T07:38:35+07:00" level=debug msg="app state loaded" Jan 27 07:38:35 volumio go-librespot[28044]: time="2026-01-27T07:38:35+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 07:38:35 volumio volumio-remote-updater[628]: [2026-01-27 07:38:35] [connect] Successful connection Jan 27 07:38:35 volumio go-librespot[28044]: time="2026-01-27T07:38:35+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 27 07:38:35 volumio go-librespot[28044]: time="2026-01-27T07:38:35+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 27 07:38:35 volumio go-librespot[28044]: time="2026-01-27T07:38:35+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 27 07:38:35 volumio go-librespot[28044]: time="2026-01-27T07:38:35+07:00" level=info msg="zeroconf server listening on port 33215" Jan 27 07:38:35 volumio volumio[27951]: info: Loading plugin "outputs"... Jan 27 07:38:35 volumio volumio[27951]: info: Loading plugin "albumart"... Jan 27 07:38:35 volumio volumio[27951]: info: Plugin example_plugin is not enabled Jan 27 07:38:35 volumio volumio[27951]: info: Loading plugin "inputs"... Jan 27 07:38:35 volumio go-librespot[28044]: time="2026-01-27T07:38:35+07:00" level=debug msg="obtained new client token: AAA28k3eXIQEZXSShTwovaxoGYatoQFyJVlXg3QA+UTa9wZgfLIyyyUIjKCsxJaEnTfFj4M4+uzX22RitfFxTd+/VfWx0IeC6u5nErNybKPvMbOXHT8KZ1Vvvtp1a7dHTyKMlGnmdcNpns0AEirOaEt77E6xn992WeXpjmFkGVT/r9fg9jVgxfeJKubhrR6wLm0wa4ZxnTpQbg9Alga3QR0hY/LheHpkiS9LaO1tlPPUJoyTJ99qcajkAm4=" Jan 27 07:38:35 volumio volumio[27951]: info: Loading plugin "updater_comm"... Jan 27 07:38:36 volumio go-librespot[28044]: time="2026-01-27T07:38:36+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 07:38:36 volumio volumio[27951]: info: Plugin mpdemulation is not enabled Jan 27 07:38:36 volumio volumio[27951]: info: Loading plugin "rest_api"... Jan 27 07:38:36 volumio volumio[27951]: info: Loading plugin "websocket"... Jan 27 07:38:36 volumio go-librespot[28044]: time="2026-01-27T07:38:36+07:00" level=debug msg="completed keyexchange" Jan 27 07:38:36 volumio go-librespot[28044]: time="2026-01-27T07:38:36+07:00" level=debug msg="completed challenge" Jan 27 07:38:36 volumio volumio[27951]: info: Starting Socket.io Server version 1.7.4 Jan 27 07:38:36 volumio volumio[27951]: info: Loading plugin "RoonBridge"... Jan 27 07:38:36 volumio go-librespot[28044]: time="2026-01-27T07:38:36+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 27 07:38:36 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 07:38:36 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 07:38:36 volumio volumio[27951]: info: Applying required configuration parameters for plugin RoonBridge Jan 27 07:38:36 volumio volumio[27951]: info: Loading i18n strings for locale en Jan 27 07:38:36 volumio volumio[27951]: Updating browse sources language Jan 27 07:38:36 volumio volumio[27951]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 27 07:38:36 volumio volumio[28065]: Forking 3 albumart workers Jan 27 07:38:37 volumio volumio[27951]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 27 07:38:37 volumio volumio[27951]: info: CoreCommandRouter::initPlayerControls Jan 27 07:38:37 volumio volumio[27951]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 07:38:37 volumio volumio[27951]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 07:38:37 volumio volumio[27951]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 07:38:37 volumio volumio[27951]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 07:38:37 volumio volumio[27951]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 07:38:37 volumio volumio[27951]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 07:38:37 volumio volumio[27951]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 07:38:37 volumio volumio[27951]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 07:38:37 volumio volumio[27951]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 27 07:38:37 volumio volumio[27951]: Express server listening on port 3000 Jan 27 07:38:37 volumio volumio[27951]: [Metrics] WebUI: 16s 60.38ms Jan 27 07:38:37 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 07:38:37 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 07:38:37 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 07:38:37 volumio volumio[27951]: info: CoreStateMachine::resetVolumioState Jan 27 07:38:37 volumio volumio[27951]: info: CoreStateMachine::getcurrentVolume Jan 27 07:38:37 volumio volumio[27951]: info: CoreCommandRouter::volumioRetrievevolume Jan 27 07:38:37 volumio sudo[28108]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 27 07:38:37 volumio sudo[28108]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 07:38:37 volumio volumio[27951]: info: Volumio Network Manager: Network status updated: 1 Jan 27 07:38:37 volumio sudo[28112]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 27 07:38:37 volumio sudo[28112]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 07:38:37 volumio sudo[28108]: pam_unix(sudo:session): session closed for user root Jan 27 07:38:37 volumio sudo[28112]: pam_unix(sudo:session): session closed for user root Jan 27 07:38:37 volumio volumio[27951]: info: VolumeController:: Volume=100 Mute =false Jan 27 07:38:37 volumio volumio[27951]: info: CoreStateMachine::pushState Jan 27 07:38:37 volumio volumio[27951]: info: CorePlayQueue::getTrack 0 Jan 27 07:38:37 volumio volumio[27951]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 27 07:38:37 volumio volumio[27951]: info: CoreCommandRouter::volumioPushState Jan 27 07:38:37 volumio volumio[27951]: info: CoreStateMachine::updateTrackBlock Jan 27 07:38:37 volumio volumio[27951]: info: CorePlayQueue::getTrackBlock Jan 27 07:38:37 volumio volumio[27951]: info: CoreCommandRouter::volumioRetrievevolume Jan 27 07:38:37 volumio volumio-remote-updater[628]: [2026-01-27 07:38:37] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1769474315 101 Jan 27 07:38:37 volumio volumio[27951]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 1 Jan 27 07:38:37 volumio volumio[27951]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 07:38:37 volumio volumio[27951]: info: Reloading queue from file Jan 27 07:38:37 volumio volumio[27951]: info: CoreStateMachine::setRepeat null single undefined Jan 27 07:38:37 volumio volumio[27951]: info: CoreStateMachine::pushState Jan 27 07:38:37 volumio volumio[27951]: info: CorePlayQueue::getTrack 0 Jan 27 07:38:37 volumio volumio[27951]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 27 07:38:37 volumio volumio[27951]: info: CoreCommandRouter::volumioPushState Jan 27 07:38:37 volumio volumio[27951]: info: CoreStateMachine::setRandom null Jan 27 07:38:37 volumio volumio[27951]: info: CoreStateMachine::pushState Jan 27 07:38:37 volumio volumio[27951]: info: CorePlayQueue::getTrack 0 Jan 27 07:38:37 volumio volumio[27951]: info: CoreCommandRouter::volumioPushState Jan 27 07:38:37 volumio volumio[27951]: info: Setting Device type: Raspberry PI Jan 27 07:38:37 volumio volumio[27951]: info: Completed loading Core Plugins Jan 27 07:38:37 volumio volumio[27951]: info: Preparing to generate the ALSA configuration file Jan 27 07:38:38 volumio volumio[27951]: info: VolumeController:: Volume=100 Mute =false Jan 27 07:38:38 volumio volumio[27951]: info: CoreStateMachine::pushState Jan 27 07:38:38 volumio volumio[27951]: info: CorePlayQueue::getTrack 0 Jan 27 07:38:38 volumio volumio[27951]: info: CoreCommandRouter::volumioPushState Jan 27 07:38:38 volumio volumio[27951]: info: Asound.conf file unchanged, so no further update is needed Jan 27 07:38:38 volumio volumio[27951]: info: Output device has changed, restarting MPD Jan 27 07:38:38 volumio volumio[27951]: info: Output device has changed, restarting Shairport Sync Jan 27 07:38:38 volumio volumio[27951]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 07:38:38 volumio volumio[27951]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 07:38:38 volumio sudo[28128]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Jan 27 07:38:38 volumio sudo[28128]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 07:38:38 volumio sudo[28130]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 27 07:38:38 volumio sudo[28130]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 07:38:38 volumio sudo[28130]: pam_unix(sudo:session): session closed for user root Jan 27 07:38:38 volumio sudo[28132]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 27 07:38:38 volumio sudo[28132]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 07:38:38 volumio volumio[27951]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 27 07:38:38 volumio volumio[27951]: info: ___________ START PLUGINS ___________ Jan 27 07:38:38 volumio volumio[27951]: info: ControllerMpd::onStart: Initializing MPD Jan 27 07:38:38 volumio volumio[27951]: info: Creating MPD Configuration file Jan 27 07:38:38 volumio volumio[27951]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 27 07:38:38 volumio volumio[27951]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 27 07:38:38 volumio volumio[27951]: info: [1769474318379] CoreMusicLibrary::Adding element Media Servers Jan 27 07:38:38 volumio volumio[27951]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 27 07:38:38 volumio sudo[28128]: pam_unix(sudo:session): session closed for user root Jan 27 07:38:38 volumio volumio[27951]: info: UPNP Browser: Client initialized successfully Jan 27 07:38:38 volumio sudo[28143]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 27 07:38:38 volumio sudo[28143]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 07:38:38 volumio sudo[28141]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 27 07:38:38 volumio sudo[28141]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 07:38:38 volumio volumio[27951]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 07:38:38 volumio volumio[27951]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 07:38:38 volumio sudo[28141]: pam_unix(sudo:session): session closed for user root Jan 27 07:38:38 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Jan 27 07:38:38 volumio volumio[27951]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 27 07:38:38 volumio volumio[27951]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 07:38:38 volumio volumio[27951]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 07:38:38 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 27 07:38:38 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 27 07:38:38 volumio systemd[1]: mpd.service: Consumed 7.363s CPU time. Jan 27 07:38:38 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 27 07:38:38 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 27 07:38:38 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 27 07:38:38 volumio volumio[27951]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 27 07:38:38 volumio volumio[27951]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 27 07:38:38 volumio volumio[27951]: info: [1769474318710] CoreMusicLibrary::Adding element Last_100 Jan 27 07:38:38 volumio volumio[27951]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 27 07:38:38 volumio volumio[27951]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 27 07:38:38 volumio volumio[27951]: info: [1769474318728] CoreMusicLibrary::Adding element Webradio Jan 27 07:38:38 volumio volumio[27951]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 27 07:38:38 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 27 07:38:38 volumio volumio[27951]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 27 07:38:38 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 27 07:38:38 volumio volumio[27951]: info: Initializing BBC Radios Jan 27 07:38:38 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 27 07:38:38 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 27 07:38:38 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 27 07:38:38 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 27 07:38:38 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 27 07:38:38 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 27 07:38:38 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 27 07:38:38 volumio volumio[27951]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 27 07:38:38 volumio volumio[27951]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 07:38:38 volumio volumio[27951]: info: Creating Spotify config file Jan 27 07:38:38 volumio volumio[27951]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 07:38:39 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 07:38:39 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 07:38:39 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 07:38:39 volumio sudo[28162]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 27 07:38:39 volumio sudo[28162]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jan 27 07:38:39 volumio sudo[28162]: pam_unix(sudo:session): session closed for user root Jan 27 07:38:39 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 19. Jan 27 07:38:39 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 07:38:39 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 07:38:39 volumio go-librespot[28173]: go-librespot daemon starting... Jan 27 07:38:39 volumio go-librespot[28174]: time="2026-01-27T07:38:39+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 07:38:40 volumio volumio[27951]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 27 07:38:40 volumio volumio[27951]: info: [1769474320171] CoreMusicLibrary::Adding element YouTube Music Jan 27 07:38:40 volumio volumio[27951]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 27 07:38:40 volumio volumio[27951]: Cannot find translation for source YouTube Music Jan 27 07:38:40 volumio go-librespot[28174]: time="2026-01-27T07:38:40+07:00" level=info msg="zeroconf server listening on port 45561" Jan 27 07:38:40 volumio volumio[27951]: info: Volumio Calling Home Jan 27 07:38:40 volumio volumio[28076]: Starting albumart workers Jan 27 07:38:40 volumio sudo[28185]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Jan 27 07:38:40 volumio sudo[28185]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 07:38:40 volumio sudo[28185]: pam_unix(sudo:session): session closed for user root Jan 27 07:38:40 volumio volumio[28077]: Starting albumart workers Jan 27 07:38:40 volumio volumio[28075]: Starting albumart workers Jan 27 07:38:41 volumio volumio[27951]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Jan 27 07:38:41 volumio volumio[27951]: info: Discovery: Found device Volumio Jan 27 07:38:41 volumio volumio[27951]: info: CoreCommandRouter::volumioGetState Jan 27 07:38:41 volumio volumio[27951]: info: CorePlayQueue::getTrack 0 Jan 27 07:38:41 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 07:38:41 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 07:38:41 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 07:38:41 volumio volumio[27951]: info: MPD Permissions set Jan 27 07:38:41 volumio volumio[27951]: info: MPD Permissions set Jan 27 07:38:41 volumio volumio[27951]: info: Upmpdcli Daemon Started Jan 27 07:38:41 volumio volumio[27951]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Jan 27 07:38:41 volumio volumio[27951]: info: Discovery: Found device Volumio Jan 27 07:38:41 volumio volumio[27951]: info: CoreCommandRouter::volumioGetState Jan 27 07:38:41 volumio volumio[27951]: info: CorePlayQueue::getTrack 0 Jan 27 07:38:41 volumio volumio[27951]: info: Spotify config file written Jan 27 07:38:41 volumio volumio[27951]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Jan 27 07:38:41 volumio volumio[27951]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 07:38:41 volumio volumio[27951]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 07:38:41 volumio volumio[27951]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 07:38:41 volumio volumio[27951]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 07:38:41 volumio sudo[28190]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jan 27 07:38:41 volumio volumio[27951]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 07:38:41 volumio volumio[27951]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 07:38:41 volumio volumio[27951]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 07:38:41 volumio volumio[27951]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 07:38:41 volumio sudo[28190]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 07:38:41 volumio volumio[27951]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 07:38:41 volumio volumio[27951]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 07:38:41 volumio volumio[27951]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 07:38:41 volumio volumio[27951]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 07:38:41 volumio volumio[27951]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 07:38:41 volumio volumio[27951]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 07:38:41 volumio volumio[27951]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 07:38:41 volumio volumio[27951]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 07:38:41 volumio volumio[27951]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 07:38:41 volumio volumio[27951]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 07:38:41 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Jan 27 07:38:41 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Jan 27 07:38:41 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 07:38:41 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 07:38:41 volumio volumio[27951]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 07:38:41 volumio volumio[27951]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 07:38:41 volumio go-librespot[28202]: go-librespot daemon starting... Jan 27 07:38:41 volumio volumio[27951]: info: No need to fix Spotify hosts Jan 27 07:38:41 volumio sudo[28190]: pam_unix(sudo:session): session closed for user root Jan 27 07:38:41 volumio go-librespot[28203]: time="2026-01-27T07:38:41+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 07:38:41 volumio go-librespot[28203]: time="2026-01-27T07:38:41+07:00" level=debug msg="app state loaded" Jan 27 07:38:41 volumio go-librespot[28203]: time="2026-01-27T07:38:41+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 07:38:42 volumio go-librespot[28203]: time="2026-01-27T07:38:42+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 27 07:38:42 volumio go-librespot[28203]: time="2026-01-27T07:38:42+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 27 07:38:42 volumio go-librespot[28203]: time="2026-01-27T07:38:42+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 27 07:38:42 volumio go-librespot[28203]: time="2026-01-27T07:38:42+07:00" level=info msg="zeroconf server listening on port 33635" Jan 27 07:38:42 volumio volumio[27951]: info: Volumio called home Jan 27 07:38:42 volumio go-librespot[28203]: time="2026-01-27T07:38:42+07:00" level=debug msg="obtained new client token: AADH5BgVRgzPGQPEXJ4dSd4hfkkFcY1PUZq8Pk+z8Uz/HNuunKaUqTt2cM3JR862sP6YhuXnmVsVI4/8aGgSUEaEUpKrffms8AWfRCRM+lmMLyym+LZ0Uyn2/Ca13FtBlNoO7WZ1DhwnNBJsSbVxWgQh31rDBiwgJdoVz9qiv7V/iuxoOKEEqio1KMz/GCwdP9smwfG1vDztgctDju+QW2fshNB+EWll7lJLYmw+Qs3IFGAcr6I/kT4PcD0=" Jan 27 07:38:42 volumio go-librespot[28203]: time="2026-01-27T07:38:42+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 07:38:43 volumio go-librespot[28203]: time="2026-01-27T07:38:43+07:00" level=debug msg="completed keyexchange" Jan 27 07:38:43 volumio go-librespot[28203]: time="2026-01-27T07:38:43+07:00" level=debug msg="completed challenge" Jan 27 07:38:43 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 07:38:43 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 07:38:43 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 07:38:43 volumio volumio[27951]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 27 07:38:43 volumio go-librespot[28203]: time="2026-01-27T07:38:43+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 27 07:38:43 volumio volumio[27951]: SPOTIFY: BQC1XRezhHNJvzuJRlc4ZKduZ6SVtnyh5-8sqzikzowVQewkQMDAzYJ006kK93eTXPDSxpw_uZvYl3lJh5FGJ-dDNDOuaapkh-aHhCuU_DbluSjSRiDORH-brl1PkmbrilVRk1yPVWT3Gf3xdnR0ifMWgc5d0tX4MgEKr7UuPxQRMjrcP2T81kRRwccQx0IHfDlTIrm1c0C5VymnU0u_qvB2t6b-wRR5-5czOGGsbKR2wcZ8TlFx_E5WINii3woyGvXcPca16EzH9hN_AJ_lsFP6i4OA7HWheyog4UYgMl7kn5EGkWT0d8VF Jan 27 07:38:43 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 07:38:43 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 07:38:43 volumio volumio[27951]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 27 07:38:43 volumio volumio[27951]: info: New Spotify access token = BQC1XRezhHNJvzuJRlc4ZKduZ6SVtnyh5-8sqzikzowVQewkQMDAzYJ006kK93eTXPDSxpw_uZvYl3lJh5FGJ-dDNDOuaapkh-aHhCuU_DbluSjSRiDORH-brl1PkmbrilVRk1yPVWT3Gf3xdnR0ifMWgc5d0tX4MgEKr7UuPxQRMjrcP2T81kRRwccQx0IHfDlTIrm1c0C5VymnU0u_qvB2t6b-wRR5-5czOGGsbKR2wcZ8TlFx_E5WINii3woyGvXcPca16EzH9hN_AJ_lsFP6i4OA7HWheyog4UYgMl7kn5EGkWT0d8VF Jan 27 07:38:43 volumio volumio[27951]: info: Spotify credentials grant success - running version from March 24, 2019 Jan 27 07:38:43 volumio volumio[27951]: info: Starting Shairport Sync Jan 27 07:38:43 volumio volumio[27951]: info: Starting Shairport Sync Jan 27 07:38:43 volumio volumio[27951]: info: Starting Shairport Sync Jan 27 07:38:43 volumio sudo[28230]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 27 07:38:43 volumio sudo[28230]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 07:38:43 volumio sudo[28232]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 27 07:38:43 volumio sudo[28232]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 07:38:43 volumio sudo[28234]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 27 07:38:43 volumio sudo[28234]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 07:38:43 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 27 07:38:43 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Jan 27 07:38:43 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 27 07:38:43 volumio systemd[1]: shairport-sync.service: Consumed 2.535s CPU time. Jan 27 07:38:43 volumio volumio[27951]: info: CoreCommandRouter::volumioGetState Jan 27 07:38:43 volumio volumio[27951]: info: CorePlayQueue::getTrack 0 Jan 27 07:38:43 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 27 07:38:43 volumio sudo[28230]: pam_unix(sudo:session): session closed for user root Jan 27 07:38:43 volumio sudo[28232]: pam_unix(sudo:session): session closed for user root Jan 27 07:38:43 volumio sudo[28234]: pam_unix(sudo:session): session closed for user root Jan 27 07:38:43 volumio volumio[27951]: info: Shairport-Sync Started Jan 27 07:38:43 volumio volumio[27951]: Error adding Membership: Error: addMembership EINVAL Jan 27 07:38:43 volumio volumio[27951]: info: Shairport-Sync Started Jan 27 07:38:43 volumio volumio[27951]: info: Shairport-Sync Started Jan 27 07:38:44 volumio volumio[27951]: SPOTIFY: User informations: {"country":"PK","display_name":"215mmgea6kss3jxeqsqdquvji","email":"linh.ngotran@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/215mmgea6kss3jxeqsqdquvji"},"followers":{"href":null,"total":1},"href":"https://api.spotify.com/v1/users/215mmgea6kss3jxeqsqdquvji","id":"215mmgea6kss3jxeqsqdquvji","images":[],"product":"premium","type":"user","uri":"spotify:user:215mmgea6kss3jxeqsqdquvji"} Jan 27 07:38:44 volumio volumio[27951]: info: Spotify Successfully logged in Jan 27 07:38:44 volumio volumio[27951]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 27 07:38:44 volumio volumio[27951]: info: [1769474324036] CoreMusicLibrary::Adding element Spotify Jan 27 07:38:44 volumio volumio[27951]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 27 07:38:44 volumio volumio[27951]: Cannot find translation for source YouTube Music Jan 27 07:38:44 volumio volumio[27951]: Cannot find translation for source Spotify Jan 27 07:38:44 volumio volumio[27951]: info: [yt-cast-receiver] DIAL server listening on port 8098 Jan 27 07:38:44 volumio volumio[27951]: info: CoreCommandRouter::volumioRetrievevolume Jan 27 07:38:45 volumio volumio[27951]: info: VolumeController:: Volume=100 Mute =false Jan 27 07:38:45 volumio volumio[27951]: info: CoreCommandRouter::volumioGetState Jan 27 07:38:45 volumio volumio[27951]: info: CorePlayQueue::getTrack 0 Jan 27 07:38:45 volumio volumio[27951]: info: CoreStateMachine::pushState Jan 27 07:38:45 volumio volumio[27951]: info: CorePlayQueue::getTrack 0 Jan 27 07:38:45 volumio volumio[27951]: info: CoreCommandRouter::volumioPushState Jan 27 07:38:45 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 07:38:45 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 07:38:45 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 07:38:46 volumio volumio[27951]: info: go-librespot daemon successfully initialized Jan 27 07:38:46 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Jan 27 07:38:46 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 07:38:46 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 07:38:46 volumio go-librespot[28269]: go-librespot daemon starting... Jan 27 07:38:46 volumio go-librespot[28270]: time="2026-01-27T07:38:46+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 07:38:46 volumio go-librespot[28270]: time="2026-01-27T07:38:46+07:00" level=debug msg="app state loaded" Jan 27 07:38:46 volumio go-librespot[28270]: time="2026-01-27T07:38:46+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 07:38:46 volumio mpd[28172]: 2026-01-27T07:38:46 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 27 07:38:46 volumio systemd[1]: Started mpd.service - Music Player Daemon. Jan 27 07:38:46 volumio sudo[28132]: pam_unix(sudo:session): session closed for user root Jan 27 07:38:46 volumio sudo[28143]: pam_unix(sudo:session): session closed for user root Jan 27 07:38:46 volumio volumio[27951]: error: MPD error: The expression evaluated to a falsy value: Jan 27 07:38:46 volumio volumio[27951]: assert.ok(self.idling) Jan 27 07:38:46 volumio volumio[27951]: error: The expression evaluated to a falsy value: Jan 27 07:38:46 volumio volumio[27951]: assert.ok(self.idling) Jan 27 07:38:46 volumio volumio[27951]: error: updateQueue error: null Jan 27 07:38:46 volumio volumio[27951]: info: MPD running with PID28172 Jan 27 07:38:46 volumio volumio[27951]: ,establishing connection Jan 27 07:38:46 volumio volumio[27951]: info: Completed starting Core Plugins Jan 27 07:38:46 volumio volumio[27951]: info: ------------------------------------------- Jan 27 07:38:46 volumio volumio[27951]: info: ----- MyVolumio plugins startup ---- Jan 27 07:38:46 volumio volumio[27951]: info: ------------------------------------------- Jan 27 07:38:46 volumio volumio[27951]: info: [MyVolumio PluginManager] Fetching plans data.... Jan 27 07:38:46 volumio go-librespot[28270]: time="2026-01-27T07:38:46+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 27 07:38:46 volumio go-librespot[28270]: time="2026-01-27T07:38:46+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 27 07:38:46 volumio go-librespot[28270]: time="2026-01-27T07:38:46+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 27 07:38:46 volumio volumio[27951]: error: updateQueue error: null Jan 27 07:38:46 volumio go-librespot[28270]: time="2026-01-27T07:38:46+07:00" level=info msg="zeroconf server listening on port 46561" Jan 27 07:38:47 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 07:38:47 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 07:38:47 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 07:38:47 volumio go-librespot[28270]: time="2026-01-27T07:38:47+07:00" level=debug msg="obtained new client token: AABcsNwv/KQVcO2G+RX1MpmFwnsf462txATQYNNGmZrJNg5YLlsFV4lZkpxVoDwXp0keh2aFpZ/0njUKi0zZHq6VFlGZzNgmyFS1+QpdOPGD4xTumEDdN5lg/2ss4jNEWFCaISd4Uxn/y0pPK3GbVdKf+z8PbnHVozeNpZzNf8jrNTZTd/EPT8S31+WdXzI8JBHdtYuGctBYTFxpM9JOlWgBzranN4mxzsxIlUN28iLzeXuu5gcGjJgU" Jan 27 07:38:47 volumio go-librespot[28270]: time="2026-01-27T07:38:47+07:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:4070, retrying with a different AP" error="dial tcp 104.199.241.202:4070: connect: connection refused" Jan 27 07:38:47 volumio go-librespot[28270]: time="2026-01-27T07:38:47+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Jan 27 07:38:47 volumio go-librespot[28270]: time="2026-01-27T07:38:47+07:00" level=debug msg="completed keyexchange" Jan 27 07:38:47 volumio go-librespot[28270]: time="2026-01-27T07:38:47+07:00" level=debug msg="completed challenge" Jan 27 07:38:47 volumio go-librespot[28270]: time="2026-01-27T07:38:47+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 27 07:38:47 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 07:38:47 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 07:38:49 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 07:38:49 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 07:38:49 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 07:38:49 volumio volumio[27951]: info: Initializing connection to go-librespot Websocket Jan 27 07:38:49 volumio volumio[27951]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 27 07:38:50 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Jan 27 07:38:50 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 07:38:50 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 07:38:50 volumio go-librespot[28282]: go-librespot daemon starting... Jan 27 07:38:50 volumio go-librespot[28283]: time="2026-01-27T07:38:50+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 07:38:50 volumio go-librespot[28283]: time="2026-01-27T07:38:50+07:00" level=debug msg="app state loaded" Jan 27 07:38:50 volumio go-librespot[28283]: time="2026-01-27T07:38:50+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 07:38:51 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 07:38:51 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 07:38:51 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 07:38:51 volumio go-librespot[28283]: time="2026-01-27T07:38:51+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 27 07:38:51 volumio go-librespot[28283]: time="2026-01-27T07:38:51+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 27 07:38:51 volumio go-librespot[28283]: time="2026-01-27T07:38:51+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 27 07:38:51 volumio go-librespot[28283]: time="2026-01-27T07:38:51+07:00" level=info msg="zeroconf server listening on port 45111" Jan 27 07:38:51 volumio go-librespot[28283]: time="2026-01-27T07:38:51+07:00" level=debug msg="obtained new client token: AABLD/idRC1VNutpQtORhRm/lDx1GbT+oeulsL8Yz6jn78TCGzMG4J2GIQVhwSY28lGF9QD40Yv25MBDQ97Jza9ayl2EcspQ0gsn7qWte1kB2GYScF/jkrL6IIE5j2LBxOSJMvErQ5hIj2LafyE7Kg6kMQXYG7/wqTmfCzzJ05nzYqVUtnY3fx7PhSTw9N56QTzun91QELjHM2hFg1vq4CnN8/P6oGDPX9tZuvT1D+d4+KynKAllA8PMvcc=" Jan 27 07:38:51 volumio volumio[27951]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Jan 27 07:38:51 volumio go-librespot[28283]: time="2026-01-27T07:38:51+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 07:38:51 volumio go-librespot[28283]: time="2026-01-27T07:38:51+07:00" level=debug msg="completed keyexchange" Jan 27 07:38:51 volumio go-librespot[28283]: time="2026-01-27T07:38:51+07:00" level=debug msg="completed challenge" Jan 27 07:38:51 volumio go-librespot[28283]: time="2026-01-27T07:38:51+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 27 07:38:51 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 07:38:51 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 07:38:52 volumio volumio[27951]: info: Initializing connection to go-librespot Websocket Jan 27 07:38:52 volumio volumio[27951]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 27 07:38:53 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 07:38:53 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 07:38:53 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 07:38:54 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Jan 27 07:38:54 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 07:38:55 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 07:38:55 volumio go-librespot[28290]: go-librespot daemon starting... Jan 27 07:38:55 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 07:38:55 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 07:38:55 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 07:38:55 volumio go-librespot[28291]: time="2026-01-27T07:38:55+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 07:38:55 volumio go-librespot[28291]: time="2026-01-27T07:38:55+07:00" level=debug msg="app state loaded" Jan 27 07:38:55 volumio go-librespot[28291]: time="2026-01-27T07:38:55+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 07:38:55 volumio volumio[27951]: info: Initializing connection to go-librespot Websocket Jan 27 07:38:55 volumio go-librespot[28291]: time="2026-01-27T07:38:55+07:00" level=debug msg="new websocket client" Jan 27 07:38:55 volumio volumio[27951]: info: Connection to go-librespot Websocket established Jan 27 07:38:55 volumio volumio[27951]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Jan 27 07:38:55 volumio volumio[27951]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Jan 27 07:38:55 volumio volumio[27951]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Jan 27 07:38:55 volumio volumio[27951]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Jan 27 07:38:55 volumio volumio[27951]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Jan 27 07:38:55 volumio volumio[27951]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Jan 27 07:38:55 volumio volumio[27951]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Jan 27 07:38:55 volumio go-librespot[28291]: time="2026-01-27T07:38:55+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 27 07:38:55 volumio go-librespot[28291]: time="2026-01-27T07:38:55+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Jan 27 07:38:55 volumio go-librespot[28291]: time="2026-01-27T07:38:55+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Jan 27 07:38:55 volumio volumio[27951]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Jan 27 07:38:55 volumio volumio[27951]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Jan 27 07:38:55 volumio volumio[27951]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Jan 27 07:38:55 volumio volumio[27951]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Jan 27 07:38:55 volumio volumio[27951]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Jan 27 07:38:55 volumio volumio[27951]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Jan 27 07:38:55 volumio volumio[27951]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Jan 27 07:38:55 volumio volumio[27951]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Jan 27 07:38:55 volumio volumio[27951]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Jan 27 07:38:55 volumio volumio[27951]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Jan 27 07:38:55 volumio volumio[27951]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Jan 27 07:38:55 volumio volumio[27951]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Jan 27 07:38:55 volumio volumio[27951]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Jan 27 07:38:55 volumio volumio[27951]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Jan 27 07:38:55 volumio volumio[27951]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Jan 27 07:38:55 volumio volumio[27951]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Jan 27 07:38:55 volumio volumio[27951]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Jan 27 07:38:55 volumio volumio[27951]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Jan 27 07:38:55 volumio volumio[27951]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Jan 27 07:38:55 volumio volumio[27951]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Jan 27 07:38:55 volumio volumio[27951]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Jan 27 07:38:55 volumio volumio[27951]: info: Adding plugin bluetooth to MyMusic Plugins Jan 27 07:38:55 volumio volumio[27951]: info: Adding plugin multiroom to MyMusic Plugins Jan 27 07:38:55 volumio volumio[27951]: info: Adding plugin metavolumio to MyMusic Plugins Jan 27 07:38:55 volumio volumio[27951]: info: Adding plugin cd_controller to MyMusic Plugins Jan 27 07:38:55 volumio volumio[27951]: info: Adding plugin qobuzconnect to MyMusic Plugins Jan 27 07:38:55 volumio volumio[27951]: info: Adding plugin smart_inputs to MyMusic Plugins Jan 27 07:38:55 volumio volumio[27951]: info: Adding plugin tidalconnect to MyMusic Plugins Jan 27 07:38:55 volumio go-librespot[28291]: time="2026-01-27T07:38:55+07:00" level=info msg="zeroconf server listening on port 44913" Jan 27 07:38:55 volumio volumio[27951]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Jan 27 07:38:55 volumio go-librespot[28291]: time="2026-01-27T07:38:55+07:00" level=debug msg="obtained new client token: AAD9IiBBw7CjThyPyJK7gWuOYx3SdJBiHdPw24Si94wrlS1u2gR8bNh6lWRB9Wnkm72lV3QVrEAf8EKpKGtrjkb3H0erGBLbLEHWsmFDnPtFe+TQqEsxq2mm8x9n4DjDLmV1EltQ8Vhln7W1hiXXMw2PF+KD94Z/JOt+c6fFtG5criK7p86U/pQ5CLZ4jPSFQBaHWHXrWOj64i8r0eH2cqAi72AQLbAXZV6vPIq6BmmlJ8CwUG4exfdVfKQ=" Jan 27 07:38:56 volumio go-librespot[28291]: time="2026-01-27T07:38:56+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 07:38:56 volumio go-librespot[28291]: time="2026-01-27T07:38:56+07:00" level=debug msg="completed keyexchange" Jan 27 07:38:56 volumio go-librespot[28291]: time="2026-01-27T07:38:56+07:00" level=debug msg="completed challenge" Jan 27 07:38:56 volumio go-librespot[28291]: time="2026-01-27T07:38:56+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 27 07:38:56 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 07:38:56 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 07:38:57 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 07:38:57 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 07:38:57 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 07:38:57 volumio volumio[27951]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Jan 27 07:38:57 volumio volumio[27951]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Jan 27 07:38:57 volumio volumio[27951]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 07:38:57 volumio volumio[27951]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 07:38:57 volumio volumio[27951]: info: Starting MyVolumio Remote Streaming Endpoints Jan 27 07:38:57 volumio volumio[27951]: info: MyVolumio login type: Token Jan 27 07:38:57 volumio volumio[27951]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Jan 27 07:38:57 volumio volumio[27951]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Jan 27 07:38:59 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 07:38:59 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 07:38:59 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 07:38:59 volumio volumio[27951]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Jan 27 07:38:59 volumio volumio[27951]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Jan 27 07:38:59 volumio volumio[27951]: info: Streaming services startup Jan 27 07:38:59 volumio volumio[27951]: info: Starting Streaming Daemon Jan 27 07:38:59 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Jan 27 07:38:59 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 07:38:59 volumio sudo[28313]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jan 27 07:38:59 volumio sudo[28313]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 07:38:59 volumio volumio[27951]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Jan 27 07:38:59 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 07:38:59 volumio go-librespot[28315]: go-librespot daemon starting... Jan 27 07:38:59 volumio sudo[28313]: pam_unix(sudo:session): session closed for user root Jan 27 07:38:59 volumio go-librespot[28320]: time="2026-01-27T07:38:59+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 07:38:59 volumio go-librespot[28320]: time="2026-01-27T07:38:59+07:00" level=debug msg="app state loaded" Jan 27 07:38:59 volumio go-librespot[28320]: time="2026-01-27T07:38:59+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 07:38:59 volumio volumio[27951]: info: Getting Spotify volume Jan 27 07:38:59 volumio volumio[27951]: info: Connection to go-librespot Websocket closed Jan 27 07:38:59 volumio volumio[27951]: error: Cannot start Volumio Streaming Daemon Jan 27 07:38:59 volumio volumio[27951]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Jan 27 07:38:59 volumio volumio[27951]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Jan 27 07:38:59 volumio volumio[27951]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Jan 27 07:39:00 volumio go-librespot[28320]: time="2026-01-27T07:39:00+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 27 07:39:00 volumio go-librespot[28320]: time="2026-01-27T07:39:00+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 27 07:39:00 volumio go-librespot[28320]: time="2026-01-27T07:39:00+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 27 07:39:00 volumio go-librespot[28320]: time="2026-01-27T07:39:00+07:00" level=info msg="zeroconf server listening on port 36715" Jan 27 07:39:00 volumio volumio[27951]: info: CoreCommandRouter::volumioGetState Jan 27 07:39:00 volumio volumio[27951]: info: CorePlayQueue::getTrack 0 Jan 27 07:39:00 volumio volumio[27951]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jan 27 07:39:00 volumio volumio[27951]: SPOTIFY: SPOTIFY VOLUME undefined Jan 27 07:39:00 volumio volumio[27951]: SPOTIFY: VOLUMIO VOLUME 100 Jan 27 07:39:00 volumio volumio[27951]: info: Aligning Spotify Volume to Volumio Volume Jan 27 07:39:00 volumio volumio[27951]: info: CoreCommandRouter::volumioGetState Jan 27 07:39:00 volumio volumio[27951]: info: CorePlayQueue::getTrack 0 Jan 27 07:39:00 volumio volumio[27951]: info: Setting Spotify Volume from Volumio: 100 Jan 27 07:39:00 volumio go-librespot[28320]: time="2026-01-27T07:39:00+07:00" level=debug msg="obtained new client token: AABlI3NGBs7zLHtkLBuSt1OBv/387yHYGz0sHytbZWkXWo1pTqOfpSDU5exH99e8ALv5S5/LABhRm/Q20ebrWRizvZwNa6YuG5CvR9XzIJqxfuECAikUXDydNNJGKEOr9/fkg6xXukFr622o6mI6k2U0L+bF3OBgs/+M3P72k9sToWi5/PkqF6IYahGwz4Y+ml3DvW7OQ7ZHvvGSxMHIXdTSyj5/JIlGAIhiVJWZ25Yf8S9MpmTT9JDt" Jan 27 07:39:00 volumio go-librespot[28320]: time="2026-01-27T07:39:00+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 07:39:00 volumio go-librespot[28320]: time="2026-01-27T07:39:00+07:00" level=debug msg="completed keyexchange" Jan 27 07:39:00 volumio go-librespot[28320]: time="2026-01-27T07:39:00+07:00" level=debug msg="completed challenge" Jan 27 07:39:00 volumio go-librespot[28320]: time="2026-01-27T07:39:00+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 27 07:39:00 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 07:39:00 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 07:39:00 volumio volumio[27951]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Jan 27 07:39:00 volumio volumio[27951]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 27 07:39:00 volumio volumio[27951]: Error: socket hang up Jan 27 07:39:00 volumio volumio[27951]: at connResetException (node:internal/errors:720:14) Jan 27 07:39:00 volumio volumio[27951]: at Socket.socketOnEnd (node:_http_client:519:23) Jan 27 07:39:00 volumio volumio[27951]: at Socket.emit (node:events:526:35) Jan 27 07:39:00 volumio volumio[27951]: at endReadableNT (node:internal/streams/readable:1376:12) Jan 27 07:39:00 volumio volumio[27951]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Jan 27 07:39:00 volumio volumio[27951]: code: 'ECONNRESET', Jan 27 07:39:00 volumio volumio[27951]: response: undefined Jan 27 07:39:00 volumio volumio[27951]: } Jan 27 07:39:00 volumio volumio[27951]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 27 07:39:01 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 07:39:01 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 07:39:01 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 07:39:02 volumio sudo[28342]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-01-27 07:38' Jan 27 07:39:02 volumio sudo[28342]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 07:39:02 volumio sudo[28342]: pam_unix(sudo:session): session closed for user root Jan 27 07:39:03 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 07:39:03 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 07:39:03 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 07:39:03 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Jan 27 07:39:03 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 07:39:03 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 07:39:03 volumio go-librespot[28350]: go-librespot daemon starting... Jan 27 07:39:03 volumio go-librespot[28351]: time="2026-01-27T07:39:03+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 07:39:03 volumio go-librespot[28351]: time="2026-01-27T07:39:03+07:00" level=debug msg="app state loaded" Jan 27 07:39:03 volumio go-librespot[28351]: time="2026-01-27T07:39:03+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 07:39:03 volumio volumio-remote-updater[628]: [2026-01-27 07:39:03] [error] handle_read_frame error: asio.system:104 (Connection reset by peer) Jan 27 07:39:03 volumio volumio-remote-updater[628]: [2026-01-27 07:39:03] [disconnect] Disconnect close local:[1006,Connection reset by peer] remote:[1006] Jan 27 07:39:03 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Jan 27 07:39:04 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Jan 27 07:39:04 volumio systemd[1]: volumio.service: Consumed 1min 9.217s CPU time. Jan 27 07:39:04 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 27 07:39:04 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Jan 27 07:39:04 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 8201. Jan 27 07:39:04 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 27 07:39:04 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Jan 27 07:39:04 volumio systemd[1]: volumio.service: Consumed 1min 9.217s CPU time. Jan 27 07:39:04 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Jan 27 07:39:04 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Jan 27 07:39:04 volumio go-librespot[28351]: time="2026-01-27T07:39:04+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 27 07:39:04 volumio go-librespot[28351]: time="2026-01-27T07:39:04+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 27 07:39:04 volumio go-librespot[28351]: time="2026-01-27T07:39:04+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 27 07:39:04 volumio go-librespot[28351]: time="2026-01-27T07:39:04+07:00" level=info msg="zeroconf server listening on port 37481" Jan 27 07:39:04 volumio go-librespot[28351]: time="2026-01-27T07:39:04+07:00" level=debug msg="obtained new client token: AADWJn6i4FW0Fh7DZa/GFZbsgUvftLdNk81aglwe9nJ97oM74vyk9tG0t4ibf4QY3EXvDRQl+b8PKhZHxFTP35Q+p5BpHrPgWdvHuct/yZcNnMj1owWNOaHHNgcWENcugLMxXPaWS4yFc/Mc4wbQS1ED/oQEwWIx9WSf++GB4oro6nQhyD3ru5dYYcCgHuXvDw9zuHHjWzQ98o7HoTkCTK979Z0k3g/zdVnk7rC3haTw7WqsHTUelxgLkl8=" Jan 27 07:39:04 volumio go-librespot[28351]: time="2026-01-27T07:39:04+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 07:39:05 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 07:39:05 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 07:39:05 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 07:39:06 volumio go-librespot[28351]: time="2026-01-27T07:39:06+07:00" level=debug msg="completed keyexchange" Jan 27 07:39:06 volumio go-librespot[28351]: time="2026-01-27T07:39:06+07:00" level=debug msg="completed challenge" Jan 27 07:39:07 volumio go-librespot[28351]: time="2026-01-27T07:39:07+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 27 07:39:07 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 07:39:07 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 07:39:07 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 07:39:07 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 07:39:07 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 07:39:07 volumio volumio[28365]: info: ------------------------------------------- Jan 27 07:39:07 volumio volumio[28365]: info: ----- Volumio3 ---- Jan 27 07:39:07 volumio volumio[28365]: info: ------------------------------------------- Jan 27 07:39:07 volumio volumio[28365]: info: ----- System startup ---- Jan 27 07:39:07 volumio volumio[28365]: info: ------------------------------------------- Jan 27 07:39:08 volumio volumio-remote-updater[628]: [2026-01-27 07:39:08] [connect] Successful connection Jan 27 07:39:09 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 07:39:09 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 07:39:09 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 07:39:09 volumio volumio[28365]: info: MYVOLUMIO Environment detected Jan 27 07:39:09 volumio volumio[28365]: info: Plugin folders cleanup Jan 27 07:39:09 volumio volumio[28365]: info: Scanning into folder /volumio/app/plugins/ Jan 27 07:39:09 volumio volumio[28365]: info: Scanning category audio_interface Jan 27 07:39:09 volumio volumio[28365]: info: Scanning category miscellanea Jan 27 07:39:09 volumio volumio[28365]: info: Scanning category music_service Jan 27 07:39:09 volumio volumio[28365]: info: Scanning category plugins.json Jan 27 07:39:09 volumio volumio[28365]: info: Scanning category system_controller Jan 27 07:39:09 volumio volumio[28365]: info: Scanning category user_interface Jan 27 07:39:09 volumio volumio[28365]: info: Scanning into folder /data/plugins/ Jan 27 07:39:09 volumio volumio[28365]: info: Scanning category music_service Jan 27 07:39:09 volumio volumio[28365]: info: Plugin folders cleanup completed Jan 27 07:39:09 volumio volumio[28365]: info: ------------------------------------------- Jan 27 07:39:09 volumio volumio[28365]: info: ----- Core plugins startup ---- Jan 27 07:39:09 volumio volumio[28365]: info: ------------------------------------------- Jan 27 07:39:09 volumio volumio[28365]: info: Loading plugins from folder /volumio/app/plugins/ Jan 27 07:39:09 volumio volumio[28365]: info: Adding plugin upnp to MyMusic Plugins Jan 27 07:39:09 volumio volumio[28365]: info: Adding plugin airplay_emulation to MyMusic Plugins Jan 27 07:39:09 volumio volumio[28365]: info: Adding plugin upnp_browser to MyMusic Plugins Jan 27 07:39:09 volumio volumio[28365]: info: Loading plugins from folder /data/plugins/ Jan 27 07:39:09 volumio volumio[28365]: info: Loading plugin "system"... Jan 27 07:39:09 volumio volumio[28365]: info: Loading plugin "appearance"... Jan 27 07:39:10 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Jan 27 07:39:10 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 07:39:10 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 07:39:10 volumio go-librespot[28394]: go-librespot daemon starting... Jan 27 07:39:10 volumio go-librespot[28395]: time="2026-01-27T07:39:10+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 07:39:10 volumio go-librespot[28395]: time="2026-01-27T07:39:10+07:00" level=debug msg="app state loaded" Jan 27 07:39:10 volumio go-librespot[28395]: time="2026-01-27T07:39:10+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 07:39:10 volumio go-librespot[28395]: time="2026-01-27T07:39: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 27 07:39:10 volumio go-librespot[28395]: time="2026-01-27T07:39: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 27 07:39:10 volumio go-librespot[28395]: time="2026-01-27T07:39: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 27 07:39:10 volumio go-librespot[28395]: time="2026-01-27T07:39:10+07:00" level=info msg="zeroconf server listening on port 34743" Jan 27 07:39:11 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 07:39:11 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 07:39:11 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 07:39:11 volumio go-librespot[28395]: time="2026-01-27T07:39:11+07:00" level=debug msg="obtained new client token: AAAqCUoYPWhWtNH+gCPISSVCsJVkCAcKSJlnxVflD9/k71R9aaAIoWE+oFNpvxJMfTVThK4dpQ6jptDSF887GwZlpcYxf1fxFUUY5vRkKh7tJ3ZUaO58nq/0efR/vBdTsdub7e9VNxTqEy5/F7wZfh+bxfQmokqUAeBjYlqyZ4w05kY87W0ffe1uVeJDBu4wIE7KTijB2WTEbEaIGBYGQJ+bFFWXi7m/Yg2GCwx+a+FpoLKuLuc3mH1A" Jan 27 07:39:11 volumio go-librespot[28395]: time="2026-01-27T07:39:11+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 07:39:11 volumio volumio[28365]: info: Loading plugin "network"... Jan 27 07:39:11 volumio volumio[28365]: info: Refreshing Cached IP Addresses Jan 27 07:39:11 volumio sudo[28403]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 27 07:39:11 volumio sudo[28403]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 07:39:11 volumio volumio[28365]: info: Loading plugin "services"... Jan 27 07:39:11 volumio volumio[28365]: info: Loading plugin "alsa_controller"... Jan 27 07:39:11 volumio sudo[28403]: pam_unix(sudo:session): session closed for user root Jan 27 07:39:11 volumio sudo[28405]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 27 07:39:11 volumio sudo[28405]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 07:39:11 volumio sudo[28405]: pam_unix(sudo:session): session closed for user root Jan 27 07:39:11 volumio go-librespot[28395]: time="2026-01-27T07:39:11+07:00" level=debug msg="completed keyexchange" Jan 27 07:39:11 volumio go-librespot[28395]: time="2026-01-27T07:39:11+07:00" level=debug msg="completed challenge" Jan 27 07:39:11 volumio sudo[28413]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Jan 27 07:39:11 volumio sudo[28413]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 07:39:11 volumio go-librespot[28395]: time="2026-01-27T07:39:11+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 27 07:39:11 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 07:39:11 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 07:39:11 volumio volumio[28365]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 27 07:39:11 volumio volumio[28365]: info: Loading plugin "wizard"... Jan 27 07:39:11 volumio volumio[28365]: info: Loading plugin "networkfs"... Jan 27 07:39:11 volumio volumio[28365]: info: Starting Udev Watcher for removable devices Jan 27 07:39:11 volumio volumio[28365]: info: Ignoring mount for partition: boot Jan 27 07:39:11 volumio volumio[28365]: info: Ignoring mount for partition: volumio Jan 27 07:39:11 volumio volumio[28365]: info: Ignoring mount for partition: volumio_data Jan 27 07:39:11 volumio volumio[28365]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 27 07:39:11 volumio volumio[28365]: info: Loading plugin "volumio_command_line_client"... Jan 27 07:39:11 volumio volumio[28365]: info: Loading plugin "upnp"... Jan 27 07:39:11 volumio volumio[28365]: info: [1769474351790] Starting Upmpd Daemon Jan 27 07:39:11 volumio volumio[28365]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 27 07:39:11 volumio volumio[28365]: info: Loading plugin "my_music"... Jan 27 07:39:11 volumio volumio[28365]: info: Loading plugin "mpd"... Jan 27 07:39:12 volumio volumio[28365]: info: Loading plugin "upnp_browser"... Jan 27 07:39:13 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 07:39:13 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 07:39:13 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 07:39:14 volumio sudo[28413]: pam_unix(sudo:session): session closed for user root Jan 27 07:39:14 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Jan 27 07:39:14 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 07:39:14 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 07:39:14 volumio go-librespot[28436]: go-librespot daemon starting... Jan 27 07:39:14 volumio go-librespot[28437]: time="2026-01-27T07:39:14+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 07:39:14 volumio go-librespot[28437]: time="2026-01-27T07:39:14+07:00" level=debug msg="app state loaded" Jan 27 07:39:14 volumio go-librespot[28437]: time="2026-01-27T07:39:14+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 07:39:15 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 07:39:15 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 07:39:15 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 07:39:15 volumio go-librespot[28437]: time="2026-01-27T07:39:15+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 27 07:39:15 volumio go-librespot[28437]: time="2026-01-27T07:39:15+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 27 07:39:15 volumio go-librespot[28437]: time="2026-01-27T07:39:15+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 27 07:39:15 volumio go-librespot[28437]: time="2026-01-27T07:39:15+07:00" level=info msg="zeroconf server listening on port 46395" Jan 27 07:39:15 volumio volumio[28365]: info: Starting UPNP Browser Jan 27 07:39:15 volumio volumio[28365]: info: Loading plugin "alarm-clock"... Jan 27 07:39:15 volumio go-librespot[28437]: time="2026-01-27T07:39:15+07:00" level=debug msg="obtained new client token: AABlvc9DkkHJX4cNOVEO1lviLixmAxA6L9hzqgZoJ3X8u/MHKvK91+99TgO9r7SOC59FEQzP2u9sdTDKQs+cJv174CDLyahBzV5MOVOKYyLUJOTBiP7maWnz+eqIbzZyu9REWjiQX6apBSNfPouZBB6vIlbkPKyCtr8ecXrmPA98gEoXeJPxA7XwRjv/qvWlaCmeGDRH20aazAjNfNjde85pd3GFBATS40qj+V2OJQHFEFqqV5gg87NSSXU=" Jan 27 07:39:15 volumio go-librespot[28437]: time="2026-01-27T07:39:15+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 07:39:15 volumio volumio[28365]: info: Loading plugin "airplay_emulation"... Jan 27 07:39:15 volumio volumio[28365]: info: Starting Shairport Sync Jan 27 07:39:15 volumio volumio[28365]: info: Loading plugin "last_100"... Jan 27 07:39:15 volumio volumio[28365]: info: Loading plugin "webradio"... Jan 27 07:39:15 volumio go-librespot[28437]: time="2026-01-27T07:39:15+07:00" level=debug msg="completed keyexchange" Jan 27 07:39:15 volumio go-librespot[28437]: time="2026-01-27T07:39:15+07:00" level=debug msg="completed challenge" Jan 27 07:39:15 volumio go-librespot[28437]: time="2026-01-27T07:39:15+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 27 07:39:15 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 07:39:15 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 07:39:15 volumio volumio[28365]: info: Loading plugin "i2s_dacs"... Jan 27 07:39:15 volumio volumio[28365]: info: Loading plugin "volumiodiscovery"... Jan 27 07:39:16 volumio volumio[28365]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 27 07:39:16 volumio volumio[28365]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 27 07:39:16 volumio volumio[28365]: *** WARNING *** For more information see Jan 27 07:39:16 volumio volumio[28365]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 27 07:39:16 volumio volumio[28365]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 27 07:39:16 volumio volumio[28365]: *** WARNING *** For more information see Jan 27 07:39:16 volumio node[28365]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 27 07:39:16 volumio node[28365]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 27 07:39:16 volumio node[28365]: *** WARNING *** For more information see Jan 27 07:39:16 volumio node[28365]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 27 07:39:16 volumio node[28365]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 27 07:39:16 volumio node[28365]: *** WARNING *** For more information see Jan 27 07:39:16 volumio volumio[28365]: info: Applying required configuration parameters for plugin volumiodiscovery Jan 27 07:39:16 volumio volumio[28365]: info: Discovery: Started advertising with name: Volumio Jan 27 07:39:16 volumio volumio[28365]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 27 07:39:16 volumio volumio[28365]: info: Loading plugin "spop"... Jan 27 07:39:17 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 07:39:17 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 07:39:17 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 07:39:17 volumio volumio[28365]: info: Loading plugin "ytcr"... Jan 27 07:39:18 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Jan 27 07:39:18 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 07:39:19 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 07:39:19 volumio go-librespot[28446]: go-librespot daemon starting... Jan 27 07:39:19 volumio go-librespot[28447]: time="2026-01-27T07:39:19+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 07:39:19 volumio go-librespot[28447]: time="2026-01-27T07:39:19+07:00" level=debug msg="app state loaded" Jan 27 07:39:19 volumio go-librespot[28447]: time="2026-01-27T07:39:19+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 07:39:19 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 07:39:19 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 07:39:19 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 07:39:19 volumio go-librespot[28447]: time="2026-01-27T07:39: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 27 07:39:19 volumio go-librespot[28447]: time="2026-01-27T07:39:19+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 27 07:39:19 volumio go-librespot[28447]: time="2026-01-27T07:39:19+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 27 07:39:19 volumio go-librespot[28447]: time="2026-01-27T07:39:19+07:00" level=info msg="zeroconf server listening on port 42187" Jan 27 07:39:19 volumio go-librespot[28447]: time="2026-01-27T07:39:19+07:00" level=debug msg="obtained new client token: AAB4dEbk0nc3HT3/FqFWx/5dMr2o7HMVplrCbiaBXhhh978p8HK/A9KQThJdtc337mXfZnOAR8KNed6oJOqHeuz0/tzvu2hl2jBD/VarvmyAhqYxRrbl4Wwi+RpEu4n2vgrAXm3WcCwPuj7fpeRqpvoavJS9k8ITJ40yf2fMU3f7GLMlyTKP1otOGWjpNCXHCHwDCwdQRgLz4GycurM4NLmTfGbVtOrkiwSI4ek9iXdEal+JSX7QATqmCw4=" Jan 27 07:39:20 volumio go-librespot[28447]: time="2026-01-27T07:39:20+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 07:39:20 volumio go-librespot[28447]: time="2026-01-27T07:39:20+07:00" level=debug msg="completed keyexchange" Jan 27 07:39:20 volumio go-librespot[28447]: time="2026-01-27T07:39:20+07:00" level=debug msg="completed challenge" Jan 27 07:39:20 volumio go-librespot[28447]: time="2026-01-27T07:39:20+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 27 07:39:20 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 07:39:20 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 07:39:20 volumio volumio[28365]: info: Loading plugin "ytmusic"... Jan 27 07:39:21 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 07:39:21 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 07:39:21 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 07:39:21 volumio volumio-remote-updater[628]: [2026-01-27 07:39:21] [connect] Successful connection Jan 27 07:39:21 volumio volumio[28365]: info: Loading plugin "outputs"... Jan 27 07:39:21 volumio volumio[28365]: info: Loading plugin "albumart"... Jan 27 07:39:21 volumio volumio[28365]: info: Plugin example_plugin is not enabled Jan 27 07:39:21 volumio volumio[28365]: info: Loading plugin "inputs"... Jan 27 07:39:21 volumio volumio[28365]: info: Loading plugin "updater_comm"... Jan 27 07:39:22 volumio volumio[28365]: info: Plugin mpdemulation is not enabled Jan 27 07:39:22 volumio volumio[28365]: info: Loading plugin "rest_api"... Jan 27 07:39:22 volumio volumio[28365]: info: Loading plugin "websocket"... Jan 27 07:39:22 volumio volumio[28365]: info: Starting Socket.io Server version 1.7.4 Jan 27 07:39:22 volumio volumio[28365]: info: Loading plugin "RoonBridge"... Jan 27 07:39:22 volumio volumio[28365]: info: Applying required configuration parameters for plugin RoonBridge Jan 27 07:39:22 volumio volumio[28365]: info: Loading i18n strings for locale en Jan 27 07:39:22 volumio volumio[28365]: Updating browse sources language Jan 27 07:39:22 volumio volumio[28365]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 27 07:39:22 volumio volumio[28468]: Forking 3 albumart workers Jan 27 07:39:22 volumio volumio[28365]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 27 07:39:22 volumio volumio[28365]: info: CoreCommandRouter::initPlayerControls Jan 27 07:39:22 volumio volumio[28365]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 07:39:22 volumio volumio[28365]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 07:39:22 volumio volumio[28365]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 07:39:22 volumio volumio[28365]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 07:39:22 volumio volumio[28365]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 07:39:22 volumio volumio[28365]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 07:39:22 volumio volumio[28365]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 07:39:22 volumio volumio[28365]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 07:39:23 volumio volumio[28365]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 27 07:39:23 volumio volumio[28365]: Express server listening on port 3000 Jan 27 07:39:23 volumio volumio[28365]: [Metrics] WebUI: 16s 128.00ms Jan 27 07:39:23 volumio volumio[28365]: info: CoreStateMachine::resetVolumioState Jan 27 07:39:23 volumio volumio[28365]: info: CoreStateMachine::getcurrentVolume Jan 27 07:39:23 volumio volumio[28365]: info: CoreCommandRouter::volumioRetrievevolume Jan 27 07:39:23 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 07:39:23 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 07:39:23 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 07:39:23 volumio sudo[28510]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 27 07:39:23 volumio sudo[28510]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 07:39:23 volumio sudo[28513]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 27 07:39:23 volumio sudo[28513]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 07:39:23 volumio volumio[28365]: info: Volumio Network Manager: Network status updated: 1 Jan 27 07:39:23 volumio sudo[28513]: pam_unix(sudo:session): session closed for user root Jan 27 07:39:23 volumio sudo[28510]: pam_unix(sudo:session): session closed for user root Jan 27 07:39:23 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Jan 27 07:39:23 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 07:39:23 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 07:39:23 volumio go-librespot[28520]: go-librespot daemon starting... Jan 27 07:39:23 volumio volumio[28365]: info: VolumeController:: Volume=100 Mute =false Jan 27 07:39:23 volumio volumio[28365]: info: CoreStateMachine::pushState Jan 27 07:39:23 volumio volumio[28365]: info: CorePlayQueue::getTrack 0 Jan 27 07:39:23 volumio volumio[28365]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 27 07:39:23 volumio volumio[28365]: info: CoreCommandRouter::volumioPushState Jan 27 07:39:23 volumio volumio[28365]: info: CoreStateMachine::updateTrackBlock Jan 27 07:39:23 volumio volumio[28365]: info: CorePlayQueue::getTrackBlock Jan 27 07:39:23 volumio volumio[28365]: info: CoreCommandRouter::volumioRetrievevolume Jan 27 07:39:23 volumio go-librespot[28521]: time="2026-01-27T07:39:23+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 07:39:23 volumio go-librespot[28521]: time="2026-01-27T07:39:23+07:00" level=debug msg="app state loaded" Jan 27 07:39:23 volumio go-librespot[28521]: time="2026-01-27T07:39:23+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 07:39:23 volumio volumio-remote-updater[628]: [2026-01-27 07:39:23] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1769474361 101 Jan 27 07:39:23 volumio volumio[28365]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 1 Jan 27 07:39:23 volumio volumio[28365]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 07:39:23 volumio volumio[28365]: info: Reloading queue from file Jan 27 07:39:23 volumio volumio[28365]: info: CoreStateMachine::setRepeat null single undefined Jan 27 07:39:23 volumio volumio[28365]: info: CoreStateMachine::pushState Jan 27 07:39:23 volumio volumio[28365]: info: CorePlayQueue::getTrack 0 Jan 27 07:39:23 volumio volumio[28365]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 27 07:39:23 volumio volumio[28365]: info: CoreCommandRouter::volumioPushState Jan 27 07:39:23 volumio volumio[28365]: info: CoreStateMachine::setRandom null Jan 27 07:39:23 volumio volumio[28365]: info: CoreStateMachine::pushState Jan 27 07:39:23 volumio volumio[28365]: info: CorePlayQueue::getTrack 0 Jan 27 07:39:23 volumio volumio[28365]: info: CoreCommandRouter::volumioPushState Jan 27 07:39:23 volumio volumio[28365]: info: Setting Device type: Raspberry PI Jan 27 07:39:24 volumio volumio[28365]: info: Completed loading Core Plugins Jan 27 07:39:24 volumio volumio[28365]: info: Preparing to generate the ALSA configuration file Jan 27 07:39:24 volumio volumio[28365]: info: VolumeController:: Volume=100 Mute =false Jan 27 07:39:24 volumio volumio[28365]: info: CoreStateMachine::pushState Jan 27 07:39:24 volumio volumio[28365]: info: CorePlayQueue::getTrack 0 Jan 27 07:39:24 volumio volumio[28365]: info: CoreCommandRouter::volumioPushState Jan 27 07:39:24 volumio volumio[28365]: info: Asound.conf file unchanged, so no further update is needed Jan 27 07:39:24 volumio volumio[28365]: info: Output device has changed, restarting MPD Jan 27 07:39:24 volumio volumio[28365]: info: Output device has changed, restarting Shairport Sync Jan 27 07:39:24 volumio volumio[28365]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 07:39:24 volumio volumio[28365]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 07:39:24 volumio sudo[28537]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Jan 27 07:39:24 volumio sudo[28537]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 07:39:24 volumio go-librespot[28521]: time="2026-01-27T07:39:24+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 27 07:39:24 volumio go-librespot[28521]: time="2026-01-27T07:39:24+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 27 07:39:24 volumio go-librespot[28521]: time="2026-01-27T07:39:24+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 27 07:39:24 volumio sudo[28539]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 27 07:39:24 volumio sudo[28539]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 07:39:24 volumio sudo[28539]: pam_unix(sudo:session): session closed for user root Jan 27 07:39:24 volumio go-librespot[28521]: time="2026-01-27T07:39:24+07:00" level=info msg="zeroconf server listening on port 41097" Jan 27 07:39:24 volumio sudo[28541]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 27 07:39:24 volumio sudo[28541]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 07:39:24 volumio volumio[28365]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 27 07:39:24 volumio volumio[28365]: info: ___________ START PLUGINS ___________ Jan 27 07:39:24 volumio volumio[28365]: info: ControllerMpd::onStart: Initializing MPD Jan 27 07:39:24 volumio volumio[28365]: info: Creating MPD Configuration file Jan 27 07:39:24 volumio volumio[28365]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 27 07:39:24 volumio volumio[28365]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 27 07:39:24 volumio volumio[28365]: info: [1769474364538] CoreMusicLibrary::Adding element Media Servers Jan 27 07:39:24 volumio volumio[28365]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 27 07:39:24 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Jan 27 07:39:24 volumio sudo[28537]: pam_unix(sudo:session): session closed for user root Jan 27 07:39:24 volumio volumio[28365]: info: UPNP Browser: Client initialized successfully Jan 27 07:39:24 volumio sudo[28550]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 27 07:39:24 volumio go-librespot[28521]: time="2026-01-27T07:39:24+07:00" level=debug msg="obtained new client token: AADWSzKFLZr4JkMQ86zwgruHj8rr3fcGmcI3UkhzS6JuTfzH1rF4Wo0gnbTHsrp7M0xHTJTUvzNv+CKEJCJDlR1daPP2WJFS7/K+0MzGLfeKkCqYd/qsRX/WvGTtoOfGaAoR6t6Aw5fSN5nywSSBGre5C3MpBbzkoSGwMEoR/53rEsC4LU80ebuQRP86bhpq+YloymaVNJjx80qS9LMdTK4x1x4+WDTGC6G+r2wY4Ke4tibz5PTFGWofoHc=" Jan 27 07:39:24 volumio sudo[28552]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 27 07:39:24 volumio sudo[28552]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 07:39:24 volumio sudo[28550]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 07:39:24 volumio sudo[28550]: pam_unix(sudo:session): session closed for user root Jan 27 07:39:24 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 27 07:39:24 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 27 07:39:24 volumio systemd[1]: mpd.service: Consumed 7.397s CPU time. Jan 27 07:39:24 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 27 07:39:24 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 27 07:39:24 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 27 07:39:24 volumio volumio[28365]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 07:39:24 volumio volumio[28365]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 07:39:24 volumio go-librespot[28521]: time="2026-01-27T07:39:24+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 07:39:24 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 27 07:39:24 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 27 07:39:24 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 27 07:39:24 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 27 07:39:24 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 27 07:39:24 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 27 07:39:24 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 27 07:39:24 volumio volumio[28365]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 27 07:39:24 volumio volumio[28365]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 07:39:24 volumio volumio[28365]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 07:39:24 volumio go-librespot[28521]: time="2026-01-27T07:39:24+07:00" level=debug msg="completed keyexchange" Jan 27 07:39:24 volumio go-librespot[28521]: time="2026-01-27T07:39:24+07:00" level=debug msg="completed challenge" Jan 27 07:39:24 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 27 07:39:24 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 27 07:39:25 volumio volumio[28365]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 27 07:39:25 volumio go-librespot[28521]: time="2026-01-27T07:39:25+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 27 07:39:25 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 07:39:25 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 07:39:25 volumio volumio[28365]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 27 07:39:25 volumio volumio[28365]: info: [1769474365067] CoreMusicLibrary::Adding element Last_100 Jan 27 07:39:25 volumio volumio[28365]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 27 07:39:25 volumio volumio[28365]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 27 07:39:25 volumio volumio[28365]: info: [1769474365103] CoreMusicLibrary::Adding element Webradio Jan 27 07:39:25 volumio volumio[28365]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 27 07:39:25 volumio volumio[28365]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 27 07:39:25 volumio volumio[28365]: info: Initializing BBC Radios Jan 27 07:39:25 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 07:39:25 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 07:39:25 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 07:39:25 volumio volumio[28365]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 27 07:39:25 volumio volumio[28365]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 07:39:25 volumio volumio[28365]: info: Creating Spotify config file Jan 27 07:39:25 volumio volumio[28365]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 07:39:25 volumio sudo[28564]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 27 07:39:25 volumio sudo[28564]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jan 27 07:39:25 volumio sudo[28564]: pam_unix(sudo:session): session closed for user root Jan 27 07:39:26 volumio volumio[28365]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 27 07:39:26 volumio volumio[28365]: info: [1769474366230] CoreMusicLibrary::Adding element YouTube Music Jan 27 07:39:26 volumio volumio[28365]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 27 07:39:26 volumio volumio[28365]: Cannot find translation for source YouTube Music Jan 27 07:39:26 volumio volumio[28365]: info: Volumio Calling Home Jan 27 07:39:26 volumio volumio[28478]: Starting albumart workers Jan 27 07:39:26 volumio sudo[28583]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Jan 27 07:39:26 volumio sudo[28583]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 07:39:26 volumio sudo[28583]: pam_unix(sudo:session): session closed for user root Jan 27 07:39:26 volumio volumio[28479]: Starting albumart workers Jan 27 07:39:26 volumio volumio[28365]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Jan 27 07:39:26 volumio volumio[28365]: info: Discovery: Found device Volumio Jan 27 07:39:27 volumio volumio[28365]: info: CoreCommandRouter::volumioGetState Jan 27 07:39:27 volumio volumio[28480]: Starting albumart workers Jan 27 07:39:27 volumio volumio[28365]: info: CorePlayQueue::getTrack 0 Jan 27 07:39:27 volumio volumio[28365]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Jan 27 07:39:27 volumio volumio[28365]: info: Discovery: Found device Volumio Jan 27 07:39:27 volumio volumio[28365]: info: CoreCommandRouter::volumioGetState Jan 27 07:39:27 volumio volumio[28365]: info: CorePlayQueue::getTrack 0 Jan 27 07:39:27 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 07:39:27 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 07:39:27 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 07:39:27 volumio volumio[28365]: info: MPD Permissions set Jan 27 07:39:27 volumio volumio[28365]: info: MPD Permissions set Jan 27 07:39:27 volumio volumio[28365]: info: Upmpdcli Daemon Started Jan 27 07:39:27 volumio volumio[28365]: info: Volumio called home Jan 27 07:39:27 volumio volumio[28365]: info: Spotify config file written Jan 27 07:39:27 volumio volumio[28365]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Jan 27 07:39:27 volumio volumio[28365]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 07:39:27 volumio volumio[28365]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 07:39:27 volumio volumio[28365]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 07:39:27 volumio volumio[28365]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 07:39:27 volumio volumio[28365]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 07:39:27 volumio volumio[28365]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 07:39:27 volumio volumio[28365]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 07:39:27 volumio volumio[28365]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 07:39:27 volumio sudo[28589]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jan 27 07:39:27 volumio sudo[28589]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 07:39:27 volumio volumio[28365]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 07:39:27 volumio volumio[28365]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 07:39:27 volumio volumio[28365]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 07:39:27 volumio volumio[28365]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 07:39:27 volumio volumio[28365]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 07:39:27 volumio volumio[28365]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 07:39:27 volumio volumio[28365]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 07:39:27 volumio volumio[28365]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 07:39:27 volumio volumio[28365]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 07:39:27 volumio volumio[28365]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 07:39:27 volumio volumio[28365]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 07:39:27 volumio volumio[28365]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 07:39:27 volumio volumio[28365]: info: No need to fix Spotify hosts Jan 27 07:39:27 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 07:39:27 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 07:39:27 volumio go-librespot[28601]: go-librespot daemon starting... Jan 27 07:39:27 volumio sudo[28589]: pam_unix(sudo:session): session closed for user root Jan 27 07:39:27 volumio go-librespot[28602]: time="2026-01-27T07:39:27+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 07:39:27 volumio go-librespot[28602]: time="2026-01-27T07:39:27+07:00" level=debug msg="app state loaded" Jan 27 07:39:27 volumio go-librespot[28602]: time="2026-01-27T07:39:27+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 07:39:28 volumio go-librespot[28602]: time="2026-01-27T07:39: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-gew1.spotify.com:80]" Jan 27 07:39:28 volumio go-librespot[28602]: time="2026-01-27T07:39:28+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Jan 27 07:39:28 volumio go-librespot[28602]: time="2026-01-27T07:39:28+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Jan 27 07:39:28 volumio go-librespot[28602]: time="2026-01-27T07:39:28+07:00" level=info msg="zeroconf server listening on port 45721" Jan 27 07:39:28 volumio go-librespot[28602]: time="2026-01-27T07:39:28+07:00" level=debug msg="obtained new client token: AACxyGWYGYaruchkCVrQKxn1Ez8v/67h90BMsr3dBATFNmpEsReBQMqSqEVzlzjsK1ghGthIXFbj55nMh2i66fVdye5FOFtgnB3dN1+xgz61T/RGQ/SisPkq3C1V4oJ8VeTdnS4Fr4SQ1XaaoMwBYmR3IS4uuM9gjPmqEQQ/YPHlpNlbP9wrxMm9oqUJVD8rfpM0B6gUCAU1PS9y3aByenZqFEOoWQbC9TO5omFENNdQ0MRfrOBDCbSr5tE=" Jan 27 07:39:28 volumio go-librespot[28602]: time="2026-01-27T07:39:28+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 07:39:28 volumio go-librespot[28602]: time="2026-01-27T07:39:28+07:00" level=debug msg="completed keyexchange" Jan 27 07:39:28 volumio go-librespot[28602]: time="2026-01-27T07:39:28+07:00" level=debug msg="completed challenge" Jan 27 07:39:29 volumio volumio[28365]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 27 07:39:29 volumio volumio[28365]: SPOTIFY: BQDV8Jtx8Z4biHXdTBsBaQ27SBhKWmQSMoDGp8h9zWOIg_vUNAysFVLHgSE_63z5Xm3E7wzTULFfj-FGL9XvjsOL7C6l2pMFfM_UWQLBT3oj0NArbNM-eZ9Zvv_fMipHrCyLY1AXNFqSb30wMwGtzhLc0j0M0uZML_GyEAn2C-lLUHc2AE8SawNGSA4sRpmH7iM2ZIpraG1j2NCbdEY5E0XmNVbfqwwkvMWA766EECBZLngep6MY9tMyqSGLtY0pawg1sLYbJxipArgdG2y1J2KwfvePh-JcqsWTmomnEYzctY72aJRM5DO0 Jan 27 07:39:29 volumio volumio[28365]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 27 07:39:29 volumio volumio[28365]: info: New Spotify access token = BQDV8Jtx8Z4biHXdTBsBaQ27SBhKWmQSMoDGp8h9zWOIg_vUNAysFVLHgSE_63z5Xm3E7wzTULFfj-FGL9XvjsOL7C6l2pMFfM_UWQLBT3oj0NArbNM-eZ9Zvv_fMipHrCyLY1AXNFqSb30wMwGtzhLc0j0M0uZML_GyEAn2C-lLUHc2AE8SawNGSA4sRpmH7iM2ZIpraG1j2NCbdEY5E0XmNVbfqwwkvMWA766EECBZLngep6MY9tMyqSGLtY0pawg1sLYbJxipArgdG2y1J2KwfvePh-JcqsWTmomnEYzctY72aJRM5DO0 Jan 27 07:39:29 volumio go-librespot[28602]: time="2026-01-27T07:39:29+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 27 07:39:29 volumio volumio[28365]: info: Spotify credentials grant success - running version from March 24, 2019 Jan 27 07:39:29 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 07:39:29 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 07:39:29 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 07:39:29 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 07:39:29 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 07:39:29 volumio volumio[28365]: info: Starting Shairport Sync Jan 27 07:39:29 volumio volumio[28365]: info: Starting Shairport Sync Jan 27 07:39:29 volumio volumio[28365]: info: Starting Shairport Sync Jan 27 07:39:29 volumio sudo[28630]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 27 07:39:29 volumio sudo[28630]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 07:39:29 volumio sudo[28624]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 27 07:39:29 volumio sudo[28624]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 07:39:29 volumio sudo[28633]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 27 07:39:29 volumio sudo[28633]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 07:39:29 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 27 07:39:29 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Jan 27 07:39:29 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 27 07:39:29 volumio systemd[1]: shairport-sync.service: Consumed 2.431s CPU time. Jan 27 07:39:29 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 27 07:39:29 volumio sudo[28633]: pam_unix(sudo:session): session closed for user root Jan 27 07:39:29 volumio sudo[28624]: pam_unix(sudo:session): session closed for user root Jan 27 07:39:29 volumio sudo[28630]: pam_unix(sudo:session): session closed for user root Jan 27 07:39:29 volumio volumio[28365]: info: Shairport-Sync Started Jan 27 07:39:29 volumio volumio[28365]: Error adding Membership: Error: addMembership EINVAL Jan 27 07:39:29 volumio volumio[28365]: info: Shairport-Sync Started Jan 27 07:39:29 volumio volumio[28365]: info: Shairport-Sync Started Jan 27 07:39:29 volumio volumio[28365]: info: CoreCommandRouter::volumioGetState Jan 27 07:39:29 volumio volumio[28365]: info: CorePlayQueue::getTrack 0 Jan 27 07:39:30 volumio volumio[28365]: SPOTIFY: User informations: {"country":"PK","display_name":"215mmgea6kss3jxeqsqdquvji","email":"linh.ngotran@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/215mmgea6kss3jxeqsqdquvji"},"followers":{"href":null,"total":1},"href":"https://api.spotify.com/v1/users/215mmgea6kss3jxeqsqdquvji","id":"215mmgea6kss3jxeqsqdquvji","images":[],"product":"premium","type":"user","uri":"spotify:user:215mmgea6kss3jxeqsqdquvji"} Jan 27 07:39:30 volumio volumio[28365]: info: Spotify Successfully logged in Jan 27 07:39:30 volumio volumio[28365]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 27 07:39:30 volumio volumio[28365]: info: [1769474370063] CoreMusicLibrary::Adding element Spotify Jan 27 07:39:30 volumio volumio[28365]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 27 07:39:30 volumio volumio[28365]: Cannot find translation for source YouTube Music Jan 27 07:39:30 volumio volumio[28365]: Cannot find translation for source Spotify Jan 27 07:39:30 volumio volumio[28365]: info: [yt-cast-receiver] DIAL server listening on port 8098 Jan 27 07:39:30 volumio volumio[28365]: info: CoreCommandRouter::volumioRetrievevolume Jan 27 07:39:31 volumio volumio[28365]: info: VolumeController:: Volume=100 Mute =false Jan 27 07:39:31 volumio volumio[28365]: info: CoreCommandRouter::volumioGetState Jan 27 07:39:31 volumio volumio[28365]: info: CorePlayQueue::getTrack 0 Jan 27 07:39:31 volumio volumio[28365]: info: CoreStateMachine::pushState Jan 27 07:39:31 volumio volumio[28365]: info: CorePlayQueue::getTrack 0 Jan 27 07:39:31 volumio volumio[28365]: info: CoreCommandRouter::volumioPushState Jan 27 07:39:31 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 07:39:31 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 07:39:31 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 07:39:32 volumio volumio[28365]: info: go-librespot daemon successfully initialized Jan 27 07:39:32 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Jan 27 07:39:32 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 07:39:32 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 07:39:32 volumio go-librespot[28668]: go-librespot daemon starting... Jan 27 07:39:32 volumio go-librespot[28669]: time="2026-01-27T07:39:32+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 07:39:32 volumio go-librespot[28669]: time="2026-01-27T07:39:32+07:00" level=debug msg="app state loaded" Jan 27 07:39:32 volumio go-librespot[28669]: time="2026-01-27T07:39:32+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 07:39:32 volumio mpd[28581]: 2026-01-27T07:39:32 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 27 07:39:32 volumio systemd[1]: Started mpd.service - Music Player Daemon. Jan 27 07:39:32 volumio sudo[28552]: pam_unix(sudo:session): session closed for user root Jan 27 07:39:32 volumio sudo[28541]: pam_unix(sudo:session): session closed for user root Jan 27 07:39:32 volumio go-librespot[28669]: time="2026-01-27T07:39: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 27 07:39:32 volumio go-librespot[28669]: time="2026-01-27T07:39: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 27 07:39:32 volumio go-librespot[28669]: time="2026-01-27T07:39: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 27 07:39:33 volumio go-librespot[28669]: time="2026-01-27T07:39:33+07:00" level=info msg="zeroconf server listening on port 36705" Jan 27 07:39:33 volumio volumio[28365]: error: MPD error: The expression evaluated to a falsy value: Jan 27 07:39:33 volumio volumio[28365]: assert.ok(self.idling) Jan 27 07:39:33 volumio volumio[28365]: error: The expression evaluated to a falsy value: Jan 27 07:39:33 volumio volumio[28365]: assert.ok(self.idling) Jan 27 07:39:33 volumio volumio[28365]: error: updateQueue error: null Jan 27 07:39:33 volumio volumio[28365]: info: Completed starting Core Plugins Jan 27 07:39:33 volumio volumio[28365]: info: ------------------------------------------- Jan 27 07:39:33 volumio volumio[28365]: info: ----- MyVolumio plugins startup ---- Jan 27 07:39:33 volumio volumio[28365]: info: ------------------------------------------- Jan 27 07:39:33 volumio volumio[28365]: info: [MyVolumio PluginManager] Fetching plans data.... Jan 27 07:39:33 volumio volumio[28365]: info: MPD running with PID28581 Jan 27 07:39:33 volumio volumio[28365]: ,establishing connection Jan 27 07:39:33 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 07:39:33 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 07:39:33 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 07:39:33 volumio volumio[28365]: error: updateQueue error: null Jan 27 07:39:33 volumio go-librespot[28669]: time="2026-01-27T07:39:33+07:00" level=debug msg="obtained new client token: AABuR7jEQ3VjUOqOS5OF9O2zAorTnNsqPchuTNQeJeXkdN817NtvTytdl6exkOWGe8Tc61XlMrPJBSUrjFbC5hdv57nt8rcTpsJVWb4/yLzgWZz/+U5ykxNuPyOMyoNKxQwDL0sSwR3UF0L4CFO8uEJDdylZzLDayYFczh8Bvc7LygDaimM0EKOqBRNCmhygO/EAMhjrjlP+73TnVm6NFaO/T1VJj7feu9dJFPVH38YhRLXvDD4SH6O5" Jan 27 07:39:33 volumio go-librespot[28669]: time="2026-01-27T07:39:33+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 07:39:33 volumio go-librespot[28669]: time="2026-01-27T07:39:33+07:00" level=debug msg="completed keyexchange" Jan 27 07:39:33 volumio go-librespot[28669]: time="2026-01-27T07:39:33+07:00" level=debug msg="completed challenge" Jan 27 07:39:33 volumio go-librespot[28669]: time="2026-01-27T07:39: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 27 07:39:33 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 07:39:33 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 07:39:35 volumio volumio[28365]: info: Initializing connection to go-librespot Websocket Jan 27 07:39:35 volumio volumio[28365]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 27 07:39:35 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 07:39:35 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 07:39:35 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 07:39:36 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 11. Jan 27 07:39:36 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 07:39:36 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 07:39:36 volumio go-librespot[28682]: go-librespot daemon starting... Jan 27 07:39:36 volumio go-librespot[28683]: time="2026-01-27T07:39:36+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 07:39:36 volumio go-librespot[28683]: time="2026-01-27T07:39:36+07:00" level=debug msg="app state loaded" Jan 27 07:39:36 volumio go-librespot[28683]: time="2026-01-27T07:39:36+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 07:39:37 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 07:39:37 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 07:39:37 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 07:39:37 volumio go-librespot[28683]: time="2026-01-27T07:39:37+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 27 07:39:37 volumio go-librespot[28683]: time="2026-01-27T07:39:37+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Jan 27 07:39:37 volumio go-librespot[28683]: time="2026-01-27T07:39:37+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Jan 27 07:39:37 volumio go-librespot[28683]: time="2026-01-27T07:39:37+07:00" level=info msg="zeroconf server listening on port 33891" Jan 27 07:39:37 volumio go-librespot[28683]: time="2026-01-27T07:39:37+07:00" level=debug msg="obtained new client token: AADzqVUMkUJBjUpGffVT4ojPQgzrAra0DXNCdNqfW+JDbWoxXiBaaNDrj4THy0olhE1Roqk+Y09p+wYUyUnRCRJw/lLUTxnF97IQIfwyxBR8JOb4/522JQZWLzuYoqGheIVkDXRBHel/3J3zsCTpDX3S1KEWS9BGyUDUJ4+PnKM9txNKGD6K4ltzGYXbBU/tLvttWp0k+mhTD60e7z8/1bjaMEnh6DraZX1Vjg+F+B1WWtec4Ik5pDC2Kb8=" Jan 27 07:39:37 volumio go-librespot[28683]: time="2026-01-27T07:39:37+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 07:39:37 volumio volumio[28365]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Jan 27 07:39:37 volumio go-librespot[28683]: time="2026-01-27T07:39:37+07:00" level=debug msg="completed keyexchange" Jan 27 07:39:37 volumio go-librespot[28683]: time="2026-01-27T07:39:37+07:00" level=debug msg="completed challenge" Jan 27 07:39:37 volumio go-librespot[28683]: time="2026-01-27T07:39: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 27 07:39:38 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 07:39:38 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 07:39:38 volumio volumio[28365]: info: Initializing connection to go-librespot Websocket Jan 27 07:39:38 volumio volumio[28365]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 27 07:39:39 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 07:39:39 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 07:39:39 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 07:39:41 volumio volumio[28365]: info: Initializing connection to go-librespot Websocket Jan 27 07:39:41 volumio volumio[28365]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 27 07:39:41 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 07:39:41 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 07:39:41 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 07:39:41 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 12. Jan 27 07:39:41 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 07:39:41 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 07:39:41 volumio go-librespot[28690]: go-librespot daemon starting... Jan 27 07:39:41 volumio go-librespot[28691]: time="2026-01-27T07:39:41+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 07:39:41 volumio go-librespot[28691]: time="2026-01-27T07:39:41+07:00" level=debug msg="app state loaded" Jan 27 07:39:41 volumio go-librespot[28691]: time="2026-01-27T07:39:41+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 07:39:42 volumio go-librespot[28691]: time="2026-01-27T07:39:42+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 27 07:39:42 volumio go-librespot[28691]: time="2026-01-27T07:39:42+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 27 07:39:42 volumio go-librespot[28691]: time="2026-01-27T07:39:42+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 27 07:39:42 volumio go-librespot[28691]: time="2026-01-27T07:39:42+07:00" level=info msg="zeroconf server listening on port 44123" Jan 27 07:39:42 volumio volumio[28365]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Jan 27 07:39:42 volumio volumio[28365]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Jan 27 07:39:42 volumio volumio[28365]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Jan 27 07:39:42 volumio volumio[28365]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Jan 27 07:39:42 volumio volumio[28365]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Jan 27 07:39:42 volumio volumio[28365]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Jan 27 07:39:42 volumio volumio[28365]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Jan 27 07:39:42 volumio volumio[28365]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Jan 27 07:39:42 volumio volumio[28365]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Jan 27 07:39:42 volumio volumio[28365]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Jan 27 07:39:42 volumio volumio[28365]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Jan 27 07:39:42 volumio volumio[28365]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Jan 27 07:39:42 volumio volumio[28365]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Jan 27 07:39:42 volumio volumio[28365]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Jan 27 07:39:42 volumio volumio[28365]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Jan 27 07:39:42 volumio volumio[28365]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Jan 27 07:39:42 volumio volumio[28365]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Jan 27 07:39:42 volumio volumio[28365]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Jan 27 07:39:42 volumio volumio[28365]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Jan 27 07:39:42 volumio volumio[28365]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Jan 27 07:39:42 volumio volumio[28365]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Jan 27 07:39:42 volumio volumio[28365]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Jan 27 07:39:42 volumio volumio[28365]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Jan 27 07:39:42 volumio volumio[28365]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Jan 27 07:39:42 volumio volumio[28365]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Jan 27 07:39:42 volumio volumio[28365]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Jan 27 07:39:42 volumio volumio[28365]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Jan 27 07:39:42 volumio volumio[28365]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Jan 27 07:39:42 volumio volumio[28365]: info: Adding plugin bluetooth to MyMusic Plugins Jan 27 07:39:42 volumio volumio[28365]: info: Adding plugin multiroom to MyMusic Plugins Jan 27 07:39:42 volumio volumio[28365]: info: Adding plugin metavolumio to MyMusic Plugins Jan 27 07:39:42 volumio volumio[28365]: info: Adding plugin cd_controller to MyMusic Plugins Jan 27 07:39:42 volumio volumio[28365]: info: Adding plugin qobuzconnect to MyMusic Plugins Jan 27 07:39:42 volumio volumio[28365]: info: Adding plugin smart_inputs to MyMusic Plugins Jan 27 07:39:42 volumio volumio[28365]: info: Adding plugin tidalconnect to MyMusic Plugins Jan 27 07:39:42 volumio volumio[28365]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Jan 27 07:39:42 volumio go-librespot[28691]: time="2026-01-27T07:39:42+07:00" level=debug msg="obtained new client token: AACOIQDUwE3kcdV4fKomvQcKuGvNGtFiQHoXJ0/eS9SK2XeI6VRh/wO9yF5IkePWj8ymfa3bcuJYke4UtHKwusHe5FZhnCJyIlFTP32gsjvIbwtfSW9QQe9mYclREMkM/2gPlzV9EsJu1jGoXxl9YDbvlWAC59d25NYNBGP+Q6YO+yQ9vEKmTBllvItASKjueHE/tIseVACbkLaey09Qns/hcN/a/QXHpKyzyUzDkBI5bykAzjjEYlBpWaQ=" Jan 27 07:39:42 volumio go-librespot[28691]: time="2026-01-27T07:39:42+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 07:39:42 volumio go-librespot[28691]: time="2026-01-27T07:39:42+07:00" level=debug msg="completed keyexchange" Jan 27 07:39:42 volumio go-librespot[28691]: time="2026-01-27T07:39:42+07:00" level=debug msg="completed challenge" Jan 27 07:39:42 volumio go-librespot[28691]: time="2026-01-27T07:39:42+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 27 07:39:42 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 07:39:42 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 07:39:43 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 07:39:43 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 07:39:43 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 07:39:43 volumio volumio[28365]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Jan 27 07:39:43 volumio volumio[28365]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Jan 27 07:39:43 volumio volumio[28365]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 07:39:43 volumio volumio[28365]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 07:39:43 volumio volumio[28365]: info: Starting MyVolumio Remote Streaming Endpoints Jan 27 07:39:44 volumio volumio[28365]: info: MyVolumio login type: Token Jan 27 07:39:44 volumio volumio[28365]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Jan 27 07:39:44 volumio volumio[28365]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Jan 27 07:39:45 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 07:39:45 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 07:39:45 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 07:39:45 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 13. Jan 27 07:39:45 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 07:39:45 volumio volumio[28365]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Jan 27 07:39:45 volumio volumio[28365]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Jan 27 07:39:45 volumio volumio[28365]: info: Streaming services startup Jan 27 07:39:45 volumio volumio[28365]: info: Starting Streaming Daemon Jan 27 07:39:45 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 07:39:45 volumio volumio[28365]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Jan 27 07:39:45 volumio sudo[28715]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jan 27 07:39:45 volumio sudo[28715]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 07:39:45 volumio go-librespot[28713]: go-librespot daemon starting... Jan 27 07:39:45 volumio go-librespot[28721]: time="2026-01-27T07:39:45+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 07:39:45 volumio go-librespot[28721]: time="2026-01-27T07:39:45+07:00" level=debug msg="app state loaded" Jan 27 07:39:45 volumio sudo[28715]: pam_unix(sudo:session): session closed for user root Jan 27 07:39:45 volumio go-librespot[28721]: time="2026-01-27T07:39:45+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 07:39:45 volumio volumio[28365]: info: Initializing connection to go-librespot Websocket Jan 27 07:39:46 volumio volumio[28365]: error: Cannot start Volumio Streaming Daemon Jan 27 07:39:46 volumio volumio[28365]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Jan 27 07:39:46 volumio volumio[28365]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Jan 27 07:39:46 volumio go-librespot[28721]: time="2026-01-27T07:39:46+07:00" level=debug msg="new websocket client" Jan 27 07:39:46 volumio volumio[28365]: info: Connection to go-librespot Websocket established Jan 27 07:39:46 volumio go-librespot[28721]: time="2026-01-27T07:39:46+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 27 07:39:46 volumio go-librespot[28721]: time="2026-01-27T07:39:46+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 27 07:39:46 volumio go-librespot[28721]: time="2026-01-27T07:39:46+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 27 07:39:46 volumio go-librespot[28721]: time="2026-01-27T07:39:46+07:00" level=info msg="zeroconf server listening on port 43093" Jan 27 07:39:46 volumio go-librespot[28721]: time="2026-01-27T07:39:46+07:00" level=debug msg="obtained new client token: AAAR8a1FrZikJcQkp3yd6M314riP69C4FNV3ebCiM36lifyFYyJTum/LEqeeuyOx1DO4W2y8x6wZ+z+Dnczxtd6wem580IQGqqr/SDmT8VqPsShpQsaHt7UMQRtF26N+t5NDD1RZKTRYVt9Ety/WJiMrpdJYSJnQlkVSrdGD8ECJb2eaD5XQRlEWKKPq6Mmh0Kktm+D7fdisVz3OhNcoWJ2dRwb0iQcCeADIjH4GH1qub4tEYLcpwBmniOI=" Jan 27 07:39:46 volumio go-librespot[28721]: time="2026-01-27T07:39:46+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 07:39:46 volumio go-librespot[28721]: time="2026-01-27T07:39:46+07:00" level=debug msg="completed keyexchange" Jan 27 07:39:46 volumio go-librespot[28721]: time="2026-01-27T07:39:46+07:00" level=debug msg="completed challenge" Jan 27 07:39:47 volumio go-librespot[28721]: time="2026-01-27T07:39:47+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 27 07:39:47 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 07:39:47 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 07:39:47 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 07:39:47 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 07:39:47 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 07:39:47 volumio volumio[28365]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Jan 27 07:39:47 volumio volumio[28365]: info: Connection to go-librespot Websocket closed Jan 27 07:39:47 volumio volumio[28365]: info: MyVolumio token set successfully Jan 27 07:39:47 volumio volumio[28365]: info: MYVOLUMIO: Adding device Jan 27 07:39:47 volumio volumio[28365]: info: MYVOLUMIO: Evaluating Server Jan 27 07:39:48 volumio volumio[28365]: info: MyVolumio status changed Jan 27 07:39:48 volumio volumio[28365]: info: Streaming services startup Jan 27 07:39:48 volumio volumio[28365]: info: Starting Streaming Daemon Jan 27 07:39:48 volumio volumio[28365]: info: Removing browser output: myVolumio user plan is not superstar Jan 27 07:39:48 volumio volumio[28365]: info: Removing audio output: Jan 27 07:39:48 volumio volumio[28365]: info: Stoppping Tunnel 1 Jan 27 07:39:48 volumio sudo[28750]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jan 27 07:39:48 volumio sudo[28750]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 07:39:48 volumio sudo[28752]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Jan 27 07:39:48 volumio sudo[28752]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 07:39:48 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jan 27 07:39:48 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jan 27 07:39:48 volumio sudo[28750]: pam_unix(sudo:session): session closed for user root Jan 27 07:39:48 volumio volumio[28365]: info: Setting Geolocation for MyVolumio to as1 Jan 27 07:39:48 volumio volumio[28365]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 07:39:48 volumio volumio[28365]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 07:39:48 volumio volumio[28365]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 07:39:48 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jan 27 07:39:48 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jan 27 07:39:48 volumio volumio[28365]: error: Cannot start Volumio Streaming Daemon Jan 27 07:39:48 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jan 27 07:39:48 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jan 27 07:39:48 volumio volumio[28365]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Jan 27 07:39:48 volumio volumio[28365]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Jan 27 07:39:48 volumio sudo[28752]: pam_unix(sudo:session): session closed for user root Jan 27 07:39:48 volumio volumio[28365]: info: Remote SSH Stopped Jan 27 07:39:49 volumio volumio[28365]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Jan 27 07:39:49 volumio volumio[28365]: info: Getting Spotify volume Jan 27 07:39:49 volumio volumio[28365]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 27 07:39:49 volumio volumio[28365]: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 27 07:39:49 volumio volumio[28365]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Jan 27 07:39:49 volumio volumio[28365]: errno: -111, Jan 27 07:39:49 volumio volumio[28365]: code: 'ECONNREFUSED', Jan 27 07:39:49 volumio volumio[28365]: syscall: 'connect', Jan 27 07:39:49 volumio volumio[28365]: address: '127.0.0.1', Jan 27 07:39:49 volumio volumio[28365]: port: 9879, Jan 27 07:39:49 volumio volumio[28365]: response: undefined Jan 27 07:39:49 volumio volumio[28365]: } Jan 27 07:39:49 volumio volumio[28365]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 27 07:39:49 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 07:39:49 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 07:39:49 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 07:39:50 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 14. Jan 27 07:39:50 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 07:39:50 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 07:39:50 volumio go-librespot[28767]: go-librespot daemon starting... Jan 27 07:39:50 volumio go-librespot[28768]: time="2026-01-27T07:39:50+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 07:39:50 volumio go-librespot[28768]: time="2026-01-27T07:39:50+07:00" level=debug msg="app state loaded" Jan 27 07:39:50 volumio go-librespot[28768]: time="2026-01-27T07:39:50+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 07:39:50 volumio sudo[28776]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-01-27 07:38' Jan 27 07:39:50 volumio sudo[28776]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 07:39:50 volumio go-librespot[28768]: time="2026-01-27T07:39:50+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 27 07:39:50 volumio go-librespot[28768]: time="2026-01-27T07:39:50+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Jan 27 07:39:50 volumio go-librespot[28768]: time="2026-01-27T07:39:50+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Jan 27 07:39:50 volumio go-librespot[28768]: time="2026-01-27T07:39:50+07:00" level=info msg="zeroconf server listening on port 40605" 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"