Jan 26 13:50:00 volumio go-librespot[32665]: time="2026-01-26T13:50: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 26 13:50:00 volumio go-librespot[32665]: time="2026-01-26T13:50: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 26 13:50:00 volumio go-librespot[32665]: time="2026-01-26T13:50: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 26 13:50:00 volumio go-librespot[32665]: time="2026-01-26T13:50:00+07:00" level=info msg="zeroconf server listening on port 36271" Jan 26 13:50:00 volumio go-librespot[32665]: time="2026-01-26T13:50:00+07:00" level=debug msg="obtained new client token: AABMwpbMIMjlFlZ/GxrzWVA2gBDuj8LWRk2q5Klj1Nz9UYrjiZSZLy4Qw85wQpW9EKOU5RTFi8JRh/pqICcM1GN2XAg4TtZlAZb0J6u9ey+iKPt8DdlDu1OyoN5MBbcjKwwwizrCCvp9sA4Rvx/hY1Wj+2d2jGDdC/QcOQZpEjUnJWd2JHTfDKd/W8yVuRslcYNiZRxmOwBnDpXb9HzHKypRvhB44gjc/ttD4V8LdWy/sn9NYiw9q26bfUs=" Jan 26 13:50:00 volumio sudo[32674]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-01-26 13:49' Jan 26 13:50:00 volumio sudo[32674]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 13:50:00 volumio go-librespot[32665]: time="2026-01-26T13:50:00+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 26 13:50:00 volumio go-librespot[32665]: time="2026-01-26T13:50:00+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Jan 26 13:50:00 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 26 13:50:00 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 26 13:50:00 volumio sudo[32674]: pam_unix(sudo:session): session closed for user root Jan 26 13:50:01 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 13:50:01 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 13:50:01 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 13:50:02 volumio volumio-remote-updater[628]: [2026-01-26 13:50:02] [error] handle_read_frame error: asio.system:104 (Connection reset by peer) Jan 26 13:50:02 volumio volumio-remote-updater[628]: [2026-01-26 13:50:02] [disconnect] Disconnect close local:[1006,Connection reset by peer] remote:[1006] Jan 26 13:50:02 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Jan 26 13:50:02 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Jan 26 13:50:02 volumio systemd[1]: volumio.service: Consumed 1min 8.820s CPU time. Jan 26 13:50:02 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 26 13:50:02 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 7045. Jan 26 13:50:02 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Jan 26 13:50:02 volumio systemd[1]: volumio.service: Consumed 1min 8.820s CPU time. Jan 26 13:50:02 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Jan 26 13:50:02 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Jan 26 13:50:03 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 13:50:03 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 13:50:03 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 13:50:03 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Jan 26 13:50:03 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 26 13:50:03 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 26 13:50:03 volumio go-librespot[32698]: go-librespot daemon starting... Jan 26 13:50:03 volumio go-librespot[32699]: time="2026-01-26T13:50:03+07:00" level=info msg="running go-librespot 0.4.0" Jan 26 13:50:03 volumio go-librespot[32699]: time="2026-01-26T13:50:03+07:00" level=debug msg="app state loaded" Jan 26 13:50:03 volumio go-librespot[32699]: time="2026-01-26T13:50:03+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 26 13:50:04 volumio go-librespot[32699]: time="2026-01-26T13:50: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 26 13:50:04 volumio go-librespot[32699]: time="2026-01-26T13:50: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 26 13:50:04 volumio go-librespot[32699]: time="2026-01-26T13:50: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 26 13:50:04 volumio go-librespot[32699]: time="2026-01-26T13:50:04+07:00" level=info msg="zeroconf server listening on port 44013" Jan 26 13:50:04 volumio go-librespot[32699]: time="2026-01-26T13:50:04+07:00" level=debug msg="obtained new client token: AAArdJgrR4fe3LRdJxAt9M53AjOALzNBGenVHJMAkfp8v5fdqHgp/3owRN75eTiMkIaouBVngtvDHsUV373sF9bnNOv8+l4vig854jY9N8mjrVZ7RhqZW1sF6gzjehUMvchwTW5XUdQDs/C1BrNy1i1P5Q89q1a7289gfQYwLBbLRh2eA916gI43efh2r2KkQpvGPgTtg7vnHmZdjfKAfrgK9KFapUoth8nivleOWpXpwza2LLECaSR4my8=" Jan 26 13:50:04 volumio go-librespot[32699]: time="2026-01-26T13:50:04+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 26 13:50:04 volumio go-librespot[32699]: time="2026-01-26T13:50:04+07:00" level=debug msg="completed keyexchange" Jan 26 13:50:04 volumio go-librespot[32699]: time="2026-01-26T13:50:04+07:00" level=debug msg="completed challenge" Jan 26 13:50:04 volumio go-librespot[32699]: time="2026-01-26T13:50:04+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 26 13:50:04 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 26 13:50:04 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 26 13:50:05 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 13:50:05 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 13:50:05 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 13:50:05 volumio volumio[32688]: info: ------------------------------------------- Jan 26 13:50:05 volumio volumio[32688]: info: ----- Volumio3 ---- Jan 26 13:50:05 volumio volumio[32688]: info: ------------------------------------------- Jan 26 13:50:05 volumio volumio[32688]: info: ----- System startup ---- Jan 26 13:50:05 volumio volumio[32688]: info: ------------------------------------------- Jan 26 13:50:07 volumio volumio-remote-updater[628]: [2026-01-26 13:50:07] [connect] Successful connection Jan 26 13:50:07 volumio volumio[32688]: info: MYVOLUMIO Environment detected Jan 26 13:50:07 volumio volumio[32688]: info: Plugin folders cleanup Jan 26 13:50:07 volumio volumio[32688]: info: Scanning into folder /volumio/app/plugins/ Jan 26 13:50:07 volumio volumio[32688]: info: Scanning category audio_interface Jan 26 13:50:07 volumio volumio[32688]: info: Scanning category miscellanea Jan 26 13:50:07 volumio volumio[32688]: info: Scanning category music_service Jan 26 13:50:07 volumio volumio[32688]: info: Scanning category plugins.json Jan 26 13:50:07 volumio volumio[32688]: info: Scanning category system_controller Jan 26 13:50:07 volumio volumio[32688]: info: Scanning category user_interface Jan 26 13:50:07 volumio volumio[32688]: info: Scanning into folder /data/plugins/ Jan 26 13:50:07 volumio volumio[32688]: info: Scanning category music_service Jan 26 13:50:07 volumio volumio[32688]: info: Plugin folders cleanup completed Jan 26 13:50:07 volumio volumio[32688]: info: ------------------------------------------- Jan 26 13:50:07 volumio volumio[32688]: info: ----- Core plugins startup ---- Jan 26 13:50:07 volumio volumio[32688]: info: ------------------------------------------- Jan 26 13:50:07 volumio volumio[32688]: info: Loading plugins from folder /volumio/app/plugins/ Jan 26 13:50:07 volumio volumio[32688]: info: Adding plugin upnp to MyMusic Plugins Jan 26 13:50:07 volumio volumio[32688]: info: Adding plugin airplay_emulation to MyMusic Plugins Jan 26 13:50:07 volumio volumio[32688]: info: Adding plugin upnp_browser to MyMusic Plugins Jan 26 13:50:07 volumio volumio[32688]: info: Loading plugins from folder /data/plugins/ Jan 26 13:50:07 volumio volumio[32688]: info: Loading plugin "system"... Jan 26 13:50:07 volumio volumio[32688]: info: Loading plugin "appearance"... Jan 26 13:50:07 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 13:50:07 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 13:50:07 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 13:50:08 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Jan 26 13:50:08 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 26 13:50:08 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 26 13:50:08 volumio go-librespot[32719]: go-librespot daemon starting... Jan 26 13:50:08 volumio go-librespot[32720]: time="2026-01-26T13:50:08+07:00" level=info msg="running go-librespot 0.4.0" Jan 26 13:50:08 volumio go-librespot[32720]: time="2026-01-26T13:50:08+07:00" level=debug msg="app state loaded" Jan 26 13:50:08 volumio go-librespot[32720]: time="2026-01-26T13:50:08+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 26 13:50:08 volumio go-librespot[32720]: time="2026-01-26T13:50:08+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 26 13:50:08 volumio go-librespot[32720]: time="2026-01-26T13:50:08+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 26 13:50:08 volumio go-librespot[32720]: time="2026-01-26T13:50:08+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 26 13:50:08 volumio go-librespot[32720]: time="2026-01-26T13:50:08+07:00" level=info msg="zeroconf server listening on port 33827" Jan 26 13:50:09 volumio go-librespot[32720]: time="2026-01-26T13:50:09+07:00" level=debug msg="obtained new client token: AABAglSKr2fqOSw0NxKWiVD7I4B2QtgTx3Q7vt9taWVKB4lPHHJQtfBiP17XxJbUmqyMxLWFvXLd0ufgCA9omvGmTnJ4H9HhBcEHvOtaINxmz8WCTZWsJuImHkHb/c3KNSDyqwl/RkYrDnbQal8gDKQjZMgT0N7znhgDlLoWSoe80SGOqcYCjJQS2DR+WwIyhw3rxgaNinBCsLar7jbM33jye7TnP3Rl48Sr0HHMEDVkxvpjVl0r7zOb" Jan 26 13:50:09 volumio go-librespot[32720]: time="2026-01-26T13:50:09+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 26 13:50:09 volumio go-librespot[32720]: time="2026-01-26T13:50:09+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Jan 26 13:50:09 volumio volumio[32688]: info: Loading plugin "network"... Jan 26 13:50:09 volumio go-librespot[32720]: time="2026-01-26T13:50:09+07:00" level=debug msg="completed keyexchange" Jan 26 13:50:09 volumio go-librespot[32720]: time="2026-01-26T13:50:09+07:00" level=debug msg="completed challenge" Jan 26 13:50:09 volumio volumio[32688]: info: Refreshing Cached IP Addresses Jan 26 13:50:09 volumio sudo[32729]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 26 13:50:09 volumio sudo[32729]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 13:50:09 volumio go-librespot[32720]: time="2026-01-26T13:50: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 26 13:50:09 volumio sudo[32729]: pam_unix(sudo:session): session closed for user root Jan 26 13:50:09 volumio sudo[32731]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 26 13:50:09 volumio sudo[32731]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 13:50:09 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 26 13:50:09 volumio volumio[32688]: info: Loading plugin "services"... Jan 26 13:50:09 volumio volumio[32688]: info: Loading plugin "alsa_controller"... Jan 26 13:50:09 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 13:50:09 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 13:50:09 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 13:50:09 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 26 13:50:09 volumio sudo[32731]: pam_unix(sudo:session): session closed for user root Jan 26 13:50:09 volumio sudo[32739]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Jan 26 13:50:09 volumio sudo[32739]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 13:50:09 volumio volumio[32688]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 26 13:50:09 volumio volumio[32688]: info: Loading plugin "wizard"... Jan 26 13:50:09 volumio volumio[32688]: info: Loading plugin "networkfs"... Jan 26 13:50:09 volumio volumio[32688]: info: Starting Udev Watcher for removable devices Jan 26 13:50:09 volumio volumio[32688]: info: Ignoring mount for partition: boot Jan 26 13:50:09 volumio volumio[32688]: info: Ignoring mount for partition: volumio Jan 26 13:50:09 volumio volumio[32688]: info: Ignoring mount for partition: volumio_data Jan 26 13:50:09 volumio volumio[32688]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 26 13:50:09 volumio volumio[32688]: info: Loading plugin "volumio_command_line_client"... Jan 26 13:50:09 volumio volumio[32688]: info: Loading plugin "upnp"... Jan 26 13:50:09 volumio volumio[32688]: info: [1769410209895] Starting Upmpd Daemon Jan 26 13:50:09 volumio volumio[32688]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 26 13:50:09 volumio volumio[32688]: info: Loading plugin "my_music"... Jan 26 13:50:09 volumio volumio[32688]: info: Loading plugin "mpd"... Jan 26 13:50:10 volumio volumio[32688]: info: Loading plugin "upnp_browser"... Jan 26 13:50:11 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 13:50:11 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 13:50:11 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 13:50:12 volumio sudo[32739]: pam_unix(sudo:session): session closed for user root Jan 26 13:50:12 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Jan 26 13:50:12 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 26 13:50:12 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 26 13:50:12 volumio go-librespot[32762]: go-librespot daemon starting... Jan 26 13:50:12 volumio go-librespot[32763]: time="2026-01-26T13:50:12+07:00" level=info msg="running go-librespot 0.4.0" Jan 26 13:50:12 volumio go-librespot[32763]: time="2026-01-26T13:50:12+07:00" level=debug msg="app state loaded" Jan 26 13:50:12 volumio go-librespot[32763]: time="2026-01-26T13:50:12+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 26 13:50:13 volumio go-librespot[32763]: time="2026-01-26T13:50:13+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 26 13:50:13 volumio go-librespot[32763]: time="2026-01-26T13:50:13+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 26 13:50:13 volumio go-librespot[32763]: time="2026-01-26T13:50:13+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 26 13:50:13 volumio go-librespot[32763]: time="2026-01-26T13:50:13+07:00" level=info msg="zeroconf server listening on port 42085" Jan 26 13:50:13 volumio volumio[32688]: info: Starting UPNP Browser Jan 26 13:50:13 volumio volumio[32688]: info: Loading plugin "alarm-clock"... Jan 26 13:50:13 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 13:50:13 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 13:50:13 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 13:50:13 volumio go-librespot[32763]: time="2026-01-26T13:50:13+07:00" level=debug msg="obtained new client token: AADSZni6JEBulH9orZIT+XR5W4K9dENvXHaVavW9ZWP+yUREO9HYXKEueEQYRIVsPs8hr5s4Plrv/k21B68CbIMWJwFSnBdW8fbz46eCn/XVAbxuy/N5Gv39o6t8Y3l/o0Dce0OjphBxXv96Ih+kNNfG8fRlG1r2UUtEQJnYEFWe4Z9sSLmykVNwbxeUf99OUvD4TdKs8kT1r/i4h+XM03ZjXa2fyrvkQLT8GY2ejaWYh+vSOWLtt3Fajms=" Jan 26 13:50:13 volumio go-librespot[32763]: time="2026-01-26T13:50:13+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 26 13:50:13 volumio go-librespot[32763]: time="2026-01-26T13:50:13+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Jan 26 13:50:13 volumio volumio[32688]: info: Loading plugin "airplay_emulation"... Jan 26 13:50:13 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 26 13:50:13 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 26 13:50:13 volumio volumio[32688]: info: Starting Shairport Sync Jan 26 13:50:13 volumio volumio[32688]: info: Loading plugin "last_100"... Jan 26 13:50:13 volumio volumio[32688]: info: Loading plugin "webradio"... Jan 26 13:50:14 volumio volumio[32688]: info: Loading plugin "i2s_dacs"... Jan 26 13:50:14 volumio volumio[32688]: info: Loading plugin "volumiodiscovery"... Jan 26 13:50:14 volumio volumio[32688]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 26 13:50:14 volumio node[32688]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 26 13:50:14 volumio volumio[32688]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 26 13:50:14 volumio volumio[32688]: *** WARNING *** For more information see Jan 26 13:50:14 volumio volumio[32688]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 26 13:50:14 volumio volumio[32688]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 26 13:50:14 volumio volumio[32688]: *** WARNING *** For more information see Jan 26 13:50:14 volumio node[32688]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 26 13:50:14 volumio volumio[32688]: info: Applying required configuration parameters for plugin volumiodiscovery Jan 26 13:50:14 volumio node[32688]: *** WARNING *** For more information see Jan 26 13:50:14 volumio node[32688]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 26 13:50:14 volumio node[32688]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 26 13:50:14 volumio node[32688]: *** WARNING *** For more information see Jan 26 13:50:14 volumio volumio[32688]: info: Discovery: Started advertising with name: Volumio Jan 26 13:50:14 volumio volumio[32688]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 26 13:50:14 volumio volumio[32688]: info: Loading plugin "spop"... Jan 26 13:50:15 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 13:50:15 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 13:50:15 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 13:50:16 volumio volumio[32688]: info: Loading plugin "ytcr"... Jan 26 13:50:16 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Jan 26 13:50:16 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 26 13:50:17 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 26 13:50:17 volumio go-librespot[305]: go-librespot daemon starting... Jan 26 13:50:17 volumio go-librespot[306]: time="2026-01-26T13:50:17+07:00" level=info msg="running go-librespot 0.4.0" Jan 26 13:50:17 volumio go-librespot[306]: time="2026-01-26T13:50:17+07:00" level=debug msg="app state loaded" Jan 26 13:50:17 volumio go-librespot[306]: time="2026-01-26T13:50:17+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 26 13:50:17 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 13:50:17 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 13:50:17 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 13:50:17 volumio go-librespot[306]: time="2026-01-26T13:50:17+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 26 13:50:17 volumio go-librespot[306]: time="2026-01-26T13:50:17+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 26 13:50:17 volumio go-librespot[306]: time="2026-01-26T13:50:17+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 26 13:50:17 volumio go-librespot[306]: time="2026-01-26T13:50:17+07:00" level=info msg="zeroconf server listening on port 39065" Jan 26 13:50:17 volumio go-librespot[306]: time="2026-01-26T13:50:17+07:00" level=debug msg="obtained new client token: AADGl7vn4s5jL98JcWT+z5v9yDY23RolBRMn9V/DxhEUpd/oSj+LfZtt9S9Qlmm9DYw2VCk6hI60/VYYNUpTETKL5TGARfMPZUznoT+fo/p8ehke1ac4VlVZxFyXggu1UU+RcR9GzyWIwgdFJkozJeo0jjwHzsmtbPkWzghFuOUJjCXAj4Nud6i7or0wlUKQJHfEIzYP64i2aSW8leBbBQs0sWh7lctrVt2hyA3EzJFvhbHexaPBvXgxAzA=" Jan 26 13:50:18 volumio go-librespot[306]: time="2026-01-26T13:50:18+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 26 13:50:18 volumio go-librespot[306]: time="2026-01-26T13:50:18+07:00" level=debug msg="completed keyexchange" Jan 26 13:50:18 volumio go-librespot[306]: time="2026-01-26T13:50:18+07:00" level=debug msg="completed challenge" Jan 26 13:50:18 volumio go-librespot[306]: time="2026-01-26T13:50:18+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 26 13:50:18 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 26 13:50:18 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 26 13:50:18 volumio volumio[32688]: info: Loading plugin "ytmusic"... Jan 26 13:50:19 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 13:50:19 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 13:50:19 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 13:50:19 volumio volumio-remote-updater[628]: [2026-01-26 13:50:19] [connect] Successful connection Jan 26 13:50:19 volumio volumio[32688]: info: Loading plugin "outputs"... Jan 26 13:50:19 volumio volumio[32688]: info: Loading plugin "albumart"... Jan 26 13:50:19 volumio volumio[32688]: info: Plugin example_plugin is not enabled Jan 26 13:50:19 volumio volumio[32688]: info: Loading plugin "inputs"... Jan 26 13:50:19 volumio volumio[32688]: info: Loading plugin "updater_comm"... Jan 26 13:50:20 volumio volumio[32688]: info: Plugin mpdemulation is not enabled Jan 26 13:50:20 volumio volumio[32688]: info: Loading plugin "rest_api"... Jan 26 13:50:20 volumio volumio[32688]: info: Loading plugin "websocket"... Jan 26 13:50:20 volumio volumio[32688]: info: Starting Socket.io Server version 1.7.4 Jan 26 13:50:20 volumio volumio[32688]: info: Loading plugin "RoonBridge"... Jan 26 13:50:20 volumio volumio[32688]: info: Applying required configuration parameters for plugin RoonBridge Jan 26 13:50:20 volumio volumio[32688]: info: Loading i18n strings for locale en Jan 26 13:50:20 volumio volumio[32688]: Updating browse sources language Jan 26 13:50:20 volumio volumio[32688]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 26 13:50:20 volumio volumio[32688]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 26 13:50:20 volumio volumio[32688]: info: CoreCommandRouter::initPlayerControls Jan 26 13:50:20 volumio volumio[32688]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 13:50:20 volumio volumio[32688]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 13:50:20 volumio volumio[32688]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 13:50:20 volumio volumio[32688]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 13:50:20 volumio volumio[32688]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 13:50:20 volumio volumio[32688]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 13:50:20 volumio volumio[32688]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 13:50:20 volumio volumio[32688]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 13:50:20 volumio volumio[328]: Forking 3 albumart workers Jan 26 13:50:20 volumio volumio[32688]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 26 13:50:20 volumio volumio[32688]: Express server listening on port 3000 Jan 26 13:50:20 volumio volumio[32688]: [Metrics] WebUI: 15s 993.28ms Jan 26 13:50:21 volumio volumio[32688]: info: CoreStateMachine::resetVolumioState Jan 26 13:50:21 volumio volumio[32688]: info: CoreStateMachine::getcurrentVolume Jan 26 13:50:21 volumio volumio[32688]: info: CoreCommandRouter::volumioRetrievevolume Jan 26 13:50:21 volumio sudo[375]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 26 13:50:21 volumio sudo[375]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 13:50:21 volumio volumio[32688]: info: Volumio Network Manager: Network status updated: 1 Jan 26 13:50:21 volumio sudo[377]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 26 13:50:21 volumio sudo[375]: pam_unix(sudo:session): session closed for user root Jan 26 13:50:21 volumio sudo[377]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 13:50:21 volumio sudo[377]: pam_unix(sudo:session): session closed for user root Jan 26 13:50:21 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Jan 26 13:50:21 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 26 13:50:21 volumio volumio-remote-updater[628]: [2026-01-26 13:50:21] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1769410219 101 Jan 26 13:50:21 volumio volumio[32688]: 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 26 13:50:21 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 26 13:50:21 volumio go-librespot[384]: go-librespot daemon starting... Jan 26 13:50:21 volumio volumio[32688]: info: VolumeController:: Volume=100 Mute =false Jan 26 13:50:21 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 13:50:21 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 13:50:21 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 13:50:21 volumio volumio[32688]: info: CoreStateMachine::pushState Jan 26 13:50:21 volumio volumio[32688]: info: CorePlayQueue::getTrack 0 Jan 26 13:50:21 volumio volumio[32688]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 26 13:50:21 volumio volumio[32688]: info: CoreCommandRouter::volumioPushState Jan 26 13:50:21 volumio go-librespot[385]: time="2026-01-26T13:50:21+07:00" level=info msg="running go-librespot 0.4.0" Jan 26 13:50:21 volumio volumio[32688]: info: CoreStateMachine::updateTrackBlock Jan 26 13:50:21 volumio volumio[32688]: info: CorePlayQueue::getTrackBlock Jan 26 13:50:21 volumio volumio[32688]: info: CoreCommandRouter::volumioRetrievevolume Jan 26 13:50:21 volumio go-librespot[385]: time="2026-01-26T13:50:21+07:00" level=debug msg="app state loaded" Jan 26 13:50:21 volumio go-librespot[385]: time="2026-01-26T13:50:21+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 26 13:50:21 volumio volumio[32688]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 13:50:21 volumio volumio[32688]: info: Reloading queue from file Jan 26 13:50:21 volumio volumio[32688]: info: CoreStateMachine::setRepeat null single undefined Jan 26 13:50:21 volumio volumio[32688]: info: CoreStateMachine::pushState Jan 26 13:50:21 volumio volumio[32688]: info: CorePlayQueue::getTrack 0 Jan 26 13:50:21 volumio volumio[32688]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 26 13:50:21 volumio volumio[32688]: info: CoreCommandRouter::volumioPushState Jan 26 13:50:21 volumio volumio[32688]: info: CoreStateMachine::setRandom null Jan 26 13:50:21 volumio volumio[32688]: info: CoreStateMachine::pushState Jan 26 13:50:21 volumio volumio[32688]: info: CorePlayQueue::getTrack 0 Jan 26 13:50:21 volumio volumio[32688]: info: CoreCommandRouter::volumioPushState Jan 26 13:50:21 volumio volumio[32688]: info: Setting Device type: Raspberry PI Jan 26 13:50:21 volumio volumio[32688]: info: Completed loading Core Plugins Jan 26 13:50:22 volumio volumio[32688]: info: Preparing to generate the ALSA configuration file Jan 26 13:50:22 volumio volumio[32688]: info: VolumeController:: Volume=100 Mute =false Jan 26 13:50:22 volumio volumio[32688]: info: CoreStateMachine::pushState Jan 26 13:50:22 volumio volumio[32688]: info: CorePlayQueue::getTrack 0 Jan 26 13:50:22 volumio volumio[32688]: info: CoreCommandRouter::volumioPushState Jan 26 13:50:22 volumio volumio[32688]: info: Asound.conf file unchanged, so no further update is needed Jan 26 13:50:22 volumio volumio[32688]: info: Output device has changed, restarting MPD Jan 26 13:50:22 volumio sudo[402]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Jan 26 13:50:22 volumio sudo[402]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 13:50:22 volumio volumio[32688]: info: Output device has changed, restarting Shairport Sync Jan 26 13:50:22 volumio volumio[32688]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 13:50:22 volumio volumio[32688]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 13:50:22 volumio go-librespot[385]: time="2026-01-26T13:50: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 26 13:50:22 volumio go-librespot[385]: time="2026-01-26T13:50: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 26 13:50:22 volumio go-librespot[385]: time="2026-01-26T13:50: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 26 13:50:22 volumio go-librespot[385]: time="2026-01-26T13:50:22+07:00" level=info msg="zeroconf server listening on port 37859" Jan 26 13:50:22 volumio sudo[405]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 26 13:50:22 volumio sudo[405]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 13:50:22 volumio sudo[405]: pam_unix(sudo:session): session closed for user root Jan 26 13:50:22 volumio sudo[407]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 26 13:50:22 volumio sudo[402]: pam_unix(sudo:session): session closed for user root Jan 26 13:50:22 volumio sudo[407]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 13:50:22 volumio volumio[32688]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 26 13:50:22 volumio volumio[32688]: info: ___________ START PLUGINS ___________ Jan 26 13:50:22 volumio volumio[32688]: info: ControllerMpd::onStart: Initializing MPD Jan 26 13:50:22 volumio volumio[32688]: info: Creating MPD Configuration file Jan 26 13:50:22 volumio volumio[32688]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 26 13:50:22 volumio volumio[32688]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 26 13:50:22 volumio volumio[32688]: info: [1769410222442] CoreMusicLibrary::Adding element Media Servers Jan 26 13:50:22 volumio volumio[32688]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 26 13:50:22 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Jan 26 13:50:22 volumio go-librespot[385]: time="2026-01-26T13:50:22+07:00" level=debug msg="obtained new client token: AAAznNy5AjAytQOmZvqp2/Gh6bFSdKplGfHNhre/sXbxqNlIiAax89Gi797JgOu8hiL++NEFsXpFDBFuUBfIQYlqFCYD6FqXSB31Zdsl8J0tLJhySrwzvlI69gMfzn20dGTK5Bj3hhwfb0ECUxJgPbGzp8W7QGEZ/4xMQH/H79knQobuS0jbo0lEG4DRCvF8LzRWQ4L9RzLvqYPKoQis6Kce647krrFc+tDE+3yuPiUqQ5aBFJsUULP8OQA=" Jan 26 13:50:22 volumio sudo[416]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 26 13:50:22 volumio sudo[416]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 13:50:22 volumio sudo[416]: pam_unix(sudo:session): session closed for user root Jan 26 13:50:22 volumio volumio[32688]: info: UPNP Browser: Client initialized successfully Jan 26 13:50:22 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 26 13:50:22 volumio sudo[418]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 26 13:50:22 volumio sudo[418]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 13:50:22 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 26 13:50:22 volumio systemd[1]: mpd.service: Consumed 7.398s CPU time. Jan 26 13:50:22 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 26 13:50:22 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 26 13:50:22 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 26 13:50:22 volumio volumio[32688]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 13:50:22 volumio volumio[32688]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 13:50:22 volumio volumio[32688]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 26 13:50:22 volumio volumio[32688]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 13:50:22 volumio volumio[32688]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 13:50:22 volumio go-librespot[385]: time="2026-01-26T13:50:22+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 26 13:50:22 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 26 13:50:22 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 26 13:50:22 volumio volumio[32688]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 26 13:50:22 volumio go-librespot[385]: time="2026-01-26T13:50:22+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Jan 26 13:50:22 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 26 13:50:22 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 26 13:50:22 volumio volumio[32688]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 26 13:50:22 volumio volumio[32688]: info: [1769410222815] CoreMusicLibrary::Adding element Last_100 Jan 26 13:50:22 volumio volumio[32688]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 26 13:50:22 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 26 13:50:22 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 26 13:50:22 volumio volumio[32688]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 26 13:50:22 volumio volumio[32688]: info: [1769410222856] CoreMusicLibrary::Adding element Webradio Jan 26 13:50:22 volumio volumio[32688]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 26 13:50:22 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 26 13:50:22 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 26 13:50:22 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 26 13:50:22 volumio volumio[32688]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 26 13:50:22 volumio volumio[32688]: info: Initializing BBC Radios Jan 26 13:50:22 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 26 13:50:23 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 26 13:50:23 volumio volumio[32688]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 26 13:50:23 volumio volumio[32688]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 13:50:23 volumio volumio[32688]: info: Creating Spotify config file Jan 26 13:50:23 volumio volumio[32688]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 13:50:23 volumio sudo[441]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 26 13:50:23 volumio sudo[441]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jan 26 13:50:23 volumio sudo[441]: pam_unix(sudo:session): session closed for user root Jan 26 13:50:23 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 13:50:23 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 13:50:23 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 13:50:24 volumio volumio[344]: Starting albumart workers Jan 26 13:50:24 volumio volumio[32688]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 26 13:50:24 volumio volumio[32688]: info: [1769410224393] CoreMusicLibrary::Adding element YouTube Music Jan 26 13:50:24 volumio volumio[32688]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 26 13:50:24 volumio volumio[32688]: Cannot find translation for source YouTube Music Jan 26 13:50:24 volumio volumio[32688]: info: Volumio Calling Home Jan 26 13:50:24 volumio sudo[450]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Jan 26 13:50:24 volumio sudo[450]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 13:50:24 volumio volumio[345]: Starting albumart workers Jan 26 13:50:24 volumio sudo[450]: pam_unix(sudo:session): session closed for user root Jan 26 13:50:24 volumio volumio[340]: Starting albumart workers Jan 26 13:50:25 volumio volumio[32688]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Jan 26 13:50:25 volumio volumio[32688]: info: Discovery: Found device Volumio Jan 26 13:50:25 volumio volumio[32688]: info: CoreCommandRouter::volumioGetState Jan 26 13:50:25 volumio volumio[32688]: info: CorePlayQueue::getTrack 0 Jan 26 13:50:25 volumio volumio[32688]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Jan 26 13:50:25 volumio volumio[32688]: info: Discovery: Found device Volumio Jan 26 13:50:25 volumio volumio[32688]: info: CoreCommandRouter::volumioGetState Jan 26 13:50:25 volumio volumio[32688]: info: CorePlayQueue::getTrack 0 Jan 26 13:50:25 volumio volumio[32688]: info: MPD Permissions set Jan 26 13:50:25 volumio volumio[32688]: info: MPD Permissions set Jan 26 13:50:25 volumio volumio[32688]: info: Upmpdcli Daemon Started Jan 26 13:50:25 volumio volumio[32688]: info: Spotify config file written Jan 26 13:50:25 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 13:50:25 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 13:50:25 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 13:50:25 volumio volumio[32688]: 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 26 13:50:25 volumio volumio[32688]: info: Volumio called home Jan 26 13:50:25 volumio volumio[32688]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 13:50:25 volumio volumio[32688]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 13:50:25 volumio volumio[32688]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 13:50:25 volumio volumio[32688]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 13:50:25 volumio volumio[32688]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 13:50:25 volumio volumio[32688]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 13:50:25 volumio volumio[32688]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 13:50:25 volumio volumio[32688]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 13:50:25 volumio sudo[457]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jan 26 13:50:25 volumio sudo[457]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 13:50:25 volumio volumio[32688]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 13:50:25 volumio volumio[32688]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 13:50:25 volumio volumio[32688]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 13:50:25 volumio volumio[32688]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 13:50:25 volumio volumio[32688]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 13:50:25 volumio volumio[32688]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 13:50:25 volumio volumio[32688]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 13:50:25 volumio volumio[32688]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 13:50:25 volumio volumio[32688]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 13:50:25 volumio volumio[32688]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 13:50:25 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Jan 26 13:50:25 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 26 13:50:25 volumio volumio[32688]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 13:50:25 volumio volumio[32688]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 13:50:25 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 26 13:50:25 volumio go-librespot[465]: go-librespot daemon starting... Jan 26 13:50:25 volumio volumio[32688]: info: No need to fix Spotify hosts Jan 26 13:50:25 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Jan 26 13:50:25 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Jan 26 13:50:25 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 26 13:50:26 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 26 13:50:26 volumio go-librespot[475]: go-librespot daemon starting... Jan 26 13:50:26 volumio sudo[457]: pam_unix(sudo:session): session closed for user root Jan 26 13:50:26 volumio go-librespot[476]: time="2026-01-26T13:50:26+07:00" level=info msg="running go-librespot 0.4.0" Jan 26 13:50:26 volumio go-librespot[476]: time="2026-01-26T13:50:26+07:00" level=debug msg="app state loaded" Jan 26 13:50:26 volumio go-librespot[476]: time="2026-01-26T13:50:26+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 26 13:50:26 volumio go-librespot[476]: time="2026-01-26T13:50:26+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 26 13:50:26 volumio go-librespot[476]: time="2026-01-26T13:50:26+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 26 13:50:26 volumio go-librespot[476]: time="2026-01-26T13:50:26+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 26 13:50:26 volumio go-librespot[476]: time="2026-01-26T13:50:26+07:00" level=info msg="zeroconf server listening on port 41361" Jan 26 13:50:27 volumio go-librespot[476]: time="2026-01-26T13:50:27+07:00" level=debug msg="obtained new client token: AABCJAoCK/+VyNexNUua94XQ/jHO80zJadUSeVZT/NhnqRP6GUDi4nya6HGiIaYvHwjxPDr+e9ccNsEWQaOzSTuxRPTtkhZeuM5SYPojinAEiHXL66F7o0QF8CrHeJbdNx1Os+EeinSvjwmoBuUIMB0ECNDISf/My+EUaG3tvnH6XojZeVZ0O4eSwJ7RNkgAILhMRUwywRYag8vsz1y+Ybg2RJElq0qdw+tupnb67UDCVkUQ0KRGqAF9" Jan 26 13:50:27 volumio go-librespot[476]: time="2026-01-26T13:50:27+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 26 13:50:27 volumio go-librespot[476]: time="2026-01-26T13:50:27+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Jan 26 13:50:27 volumio volumio[32688]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 26 13:50:27 volumio volumio[32688]: SPOTIFY: BQAhYSjoVKGSRMzQoxTHhWo_lyQQMUXdPIixzHqSfcTOPbNW7e351pblGGOLZ6p7GVSQmHr-giFIFVPs_yR9mGTrpgoIelb27rNl0WjuDTyZe0qlzp7ChETISHbI73olhXpWViZOdS_hsdKa2EBHtj85e-1QRYRqy2elTQzs8DC5YZ2peJqc1_LYim5M_JZSwpbHDdoq4JJJSph0YA5FdTqLxybYuF1iOGL6t73DiwCcGbGob4qtx0KsdNQSW-g0Bu-GOAl8j6Fj8U4XOWwoup2kJgpHOGUK7YAvr2A7hpEvsph7vzjVr8Wm Jan 26 13:50:27 volumio volumio[32688]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 26 13:50:27 volumio volumio[32688]: info: New Spotify access token = BQAhYSjoVKGSRMzQoxTHhWo_lyQQMUXdPIixzHqSfcTOPbNW7e351pblGGOLZ6p7GVSQmHr-giFIFVPs_yR9mGTrpgoIelb27rNl0WjuDTyZe0qlzp7ChETISHbI73olhXpWViZOdS_hsdKa2EBHtj85e-1QRYRqy2elTQzs8DC5YZ2peJqc1_LYim5M_JZSwpbHDdoq4JJJSph0YA5FdTqLxybYuF1iOGL6t73DiwCcGbGob4qtx0KsdNQSW-g0Bu-GOAl8j6Fj8U4XOWwoup2kJgpHOGUK7YAvr2A7hpEvsph7vzjVr8Wm Jan 26 13:50:27 volumio volumio[32688]: info: Spotify credentials grant success - running version from March 24, 2019 Jan 26 13:50:27 volumio volumio[32688]: info: Starting Shairport Sync Jan 26 13:50:27 volumio go-librespot[476]: time="2026-01-26T13:50:27+07:00" level=debug msg="completed keyexchange" Jan 26 13:50:27 volumio volumio[32688]: info: Starting Shairport Sync Jan 26 13:50:27 volumio go-librespot[476]: time="2026-01-26T13:50:27+07:00" level=debug msg="completed challenge" Jan 26 13:50:27 volumio volumio[32688]: info: Starting Shairport Sync Jan 26 13:50:27 volumio sudo[512]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 26 13:50:27 volumio sudo[512]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 13:50:27 volumio go-librespot[476]: time="2026-01-26T13:50: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 26 13:50:27 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 26 13:50:27 volumio sudo[514]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 26 13:50:27 volumio sudo[514]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 13:50:27 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 26 13:50:27 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 13:50:27 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 13:50:27 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 13:50:27 volumio sudo[516]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 26 13:50:27 volumio sudo[516]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 13:50:27 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 26 13:50:27 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Jan 26 13:50:27 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 26 13:50:27 volumio systemd[1]: shairport-sync.service: Consumed 2.514s CPU time. Jan 26 13:50:27 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 26 13:50:27 volumio sudo[512]: pam_unix(sudo:session): session closed for user root Jan 26 13:50:27 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 26 13:50:27 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Jan 26 13:50:27 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 26 13:50:27 volumio sudo[514]: pam_unix(sudo:session): session closed for user root Jan 26 13:50:27 volumio volumio[32688]: info: Shairport-Sync Started Jan 26 13:50:27 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 26 13:50:27 volumio sudo[516]: pam_unix(sudo:session): session closed for user root Jan 26 13:50:27 volumio volumio[32688]: Error adding Membership: Error: addMembership EINVAL Jan 26 13:50:28 volumio volumio[32688]: info: Shairport-Sync Started Jan 26 13:50:28 volumio volumio[32688]: info: Shairport-Sync Started Jan 26 13:50:28 volumio volumio[32688]: info: CoreCommandRouter::volumioGetState Jan 26 13:50:28 volumio volumio[32688]: info: CorePlayQueue::getTrack 0 Jan 26 13:50:28 volumio volumio[32688]: 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 26 13:50:28 volumio volumio[32688]: info: Spotify Successfully logged in Jan 26 13:50:28 volumio volumio[32688]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 26 13:50:28 volumio volumio[32688]: info: [1769410228313] CoreMusicLibrary::Adding element Spotify Jan 26 13:50:28 volumio volumio[32688]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 26 13:50:28 volumio volumio[32688]: Cannot find translation for source YouTube Music Jan 26 13:50:28 volumio volumio[32688]: Cannot find translation for source Spotify Jan 26 13:50:29 volumio volumio[32688]: info: [yt-cast-receiver] DIAL server listening on port 8098 Jan 26 13:50:29 volumio volumio[32688]: info: CoreCommandRouter::volumioRetrievevolume Jan 26 13:50:29 volumio volumio[32688]: info: VolumeController:: Volume=100 Mute =false Jan 26 13:50:29 volumio volumio[32688]: info: CoreCommandRouter::volumioGetState Jan 26 13:50:29 volumio volumio[32688]: info: CorePlayQueue::getTrack 0 Jan 26 13:50:29 volumio volumio[32688]: info: CoreStateMachine::pushState Jan 26 13:50:29 volumio volumio[32688]: info: CorePlayQueue::getTrack 0 Jan 26 13:50:29 volumio volumio[32688]: info: CoreCommandRouter::volumioPushState Jan 26 13:50:29 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 13:50:29 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 13:50:29 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 13:50:30 volumio volumio[32688]: info: go-librespot daemon successfully initialized Jan 26 13:50:30 volumio mpd[448]: 2026-01-26T13:50:30 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 26 13:50:30 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Jan 26 13:50:30 volumio systemd[1]: Started mpd.service - Music Player Daemon. Jan 26 13:50:30 volumio sudo[418]: pam_unix(sudo:session): session closed for user root Jan 26 13:50:30 volumio sudo[407]: pam_unix(sudo:session): session closed for user root Jan 26 13:50:30 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 26 13:50:30 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 26 13:50:30 volumio go-librespot[554]: go-librespot daemon starting... Jan 26 13:50:30 volumio go-librespot[557]: time="2026-01-26T13:50:30+07:00" level=info msg="running go-librespot 0.4.0" Jan 26 13:50:30 volumio go-librespot[557]: time="2026-01-26T13:50:30+07:00" level=debug msg="app state loaded" Jan 26 13:50:30 volumio go-librespot[557]: time="2026-01-26T13:50:30+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 26 13:50:30 volumio volumio[32688]: error: MPD error: The expression evaluated to a falsy value: Jan 26 13:50:30 volumio volumio[32688]: assert.ok(self.idling) Jan 26 13:50:30 volumio volumio[32688]: error: The expression evaluated to a falsy value: Jan 26 13:50:30 volumio volumio[32688]: assert.ok(self.idling) Jan 26 13:50:30 volumio volumio[32688]: info: MPD running with PID448 Jan 26 13:50:30 volumio volumio[32688]: ,establishing connection Jan 26 13:50:30 volumio volumio[32688]: error: updateQueue error: null Jan 26 13:50:31 volumio volumio[32688]: info: Completed starting Core Plugins Jan 26 13:50:31 volumio volumio[32688]: info: ------------------------------------------- Jan 26 13:50:31 volumio volumio[32688]: info: ----- MyVolumio plugins startup ---- Jan 26 13:50:31 volumio volumio[32688]: info: ------------------------------------------- Jan 26 13:50:31 volumio volumio[32688]: info: [MyVolumio PluginManager] Fetching plans data.... Jan 26 13:50:31 volumio volumio[32688]: error: updateQueue error: null Jan 26 13:50:31 volumio go-librespot[557]: time="2026-01-26T13:50:31+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 26 13:50:31 volumio go-librespot[557]: time="2026-01-26T13:50:31+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 26 13:50:31 volumio go-librespot[557]: time="2026-01-26T13:50:31+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 26 13:50:31 volumio go-librespot[557]: time="2026-01-26T13:50:31+07:00" level=info msg="zeroconf server listening on port 44865" Jan 26 13:50:31 volumio go-librespot[557]: time="2026-01-26T13:50:31+07:00" level=debug msg="obtained new client token: AACLmljcpWgsVYss2RA7SXXduaXXLvxZDMt5HtTuQIZmVtX8p22BxxScDnqHL1c0cP7LSi433ZaLaEPN9Eq05S6Jr3JvmLn1bmjNxX29QyGW89Dn1lx4s7Xw63Lh5XhXqhiSQkm/YHGG6Mu4FrWzY2pYxkpsr1GAtnKN9uPciCK6kxy6qyXHbNidLCLaebMG4nPU18lMdiMqBDSKnDR5XpBZhZP1E//neBtcvOC+acpnsEgLsHt2HblV3Dg=" Jan 26 13:50:31 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 13:50:31 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 13:50:31 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 13:50:31 volumio go-librespot[557]: time="2026-01-26T13:50:31+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 26 13:50:31 volumio go-librespot[557]: time="2026-01-26T13:50:31+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Jan 26 13:50:31 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 26 13:50:31 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 26 13:50:33 volumio volumio[32688]: info: Initializing connection to go-librespot Websocket Jan 26 13:50:33 volumio volumio[32688]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 26 13:50:33 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 13:50:33 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 13:50:33 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 13:50:34 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Jan 26 13:50:34 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 26 13:50:35 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 26 13:50:35 volumio go-librespot[564]: go-librespot daemon starting... Jan 26 13:50:35 volumio go-librespot[565]: time="2026-01-26T13:50:35+07:00" level=info msg="running go-librespot 0.4.0" Jan 26 13:50:35 volumio go-librespot[565]: time="2026-01-26T13:50:35+07:00" level=debug msg="app state loaded" Jan 26 13:50:35 volumio go-librespot[565]: time="2026-01-26T13:50:35+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 26 13:50:35 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 13:50:35 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 13:50:35 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 13:50:35 volumio go-librespot[565]: time="2026-01-26T13:50: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 26 13:50:35 volumio go-librespot[565]: time="2026-01-26T13:50: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 26 13:50:35 volumio go-librespot[565]: time="2026-01-26T13:50: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 26 13:50:35 volumio go-librespot[565]: time="2026-01-26T13:50:35+07:00" level=info msg="zeroconf server listening on port 37385" Jan 26 13:50:35 volumio volumio[32688]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Jan 26 13:50:35 volumio go-librespot[565]: time="2026-01-26T13:50:35+07:00" level=debug msg="obtained new client token: AACkf0EihpQT/V21Ym2hM6lDfDq/i0MQUxdXZ73MiGWceUHRPnyW+2J+ye/qcy6cWKM/uwiwR9PjElsESqHW7mZq/5M3MfHKX7egNgODL0IJ3OT5mGtF3PfsaYyzAjMrcaPKeeGSgL7glP3XfqE79A8Q7aMBJv73qOzYLGEYwVPcntbfH9V01yDq7s1RCqx3G+Wh4fc+tT4HdAc6yiG50fdV0QO46NkIHBpATXKrXFJhh+rl6l0Ukyl681Q=" Jan 26 13:50:35 volumio go-librespot[565]: time="2026-01-26T13:50:35+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 26 13:50:36 volumio go-librespot[565]: time="2026-01-26T13:50:36+07:00" level=debug msg="completed keyexchange" Jan 26 13:50:36 volumio go-librespot[565]: time="2026-01-26T13:50:36+07:00" level=debug msg="completed challenge" Jan 26 13:50:36 volumio go-librespot[565]: time="2026-01-26T13:50: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 26 13:50:36 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 26 13:50:36 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 26 13:50:36 volumio volumio[32688]: info: Initializing connection to go-librespot Websocket Jan 26 13:50:36 volumio volumio[32688]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 26 13:50:37 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 13:50:37 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 13:50:37 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 13:50:39 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Jan 26 13:50:39 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 26 13:50:39 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 26 13:50:39 volumio go-librespot[574]: go-librespot daemon starting... Jan 26 13:50:39 volumio go-librespot[576]: time="2026-01-26T13:50:39+07:00" level=info msg="running go-librespot 0.4.0" Jan 26 13:50:39 volumio go-librespot[576]: time="2026-01-26T13:50:39+07:00" level=debug msg="app state loaded" Jan 26 13:50:39 volumio go-librespot[576]: time="2026-01-26T13:50:39+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 26 13:50:39 volumio volumio[32688]: info: Initializing connection to go-librespot Websocket Jan 26 13:50:39 volumio go-librespot[576]: time="2026-01-26T13:50:39+07:00" level=debug msg="new websocket client" Jan 26 13:50:39 volumio volumio[32688]: info: Connection to go-librespot Websocket established Jan 26 13:50:39 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 13:50:39 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 13:50:39 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 13:50:39 volumio go-librespot[576]: time="2026-01-26T13:50:39+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 26 13:50:39 volumio go-librespot[576]: time="2026-01-26T13:50:39+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 26 13:50:39 volumio go-librespot[576]: time="2026-01-26T13:50:39+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 26 13:50:39 volumio go-librespot[576]: time="2026-01-26T13:50:39+07:00" level=info msg="zeroconf server listening on port 44149" Jan 26 13:50:39 volumio volumio[32688]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Jan 26 13:50:39 volumio volumio[32688]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Jan 26 13:50:39 volumio volumio[32688]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Jan 26 13:50:39 volumio volumio[32688]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Jan 26 13:50:39 volumio volumio[32688]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Jan 26 13:50:39 volumio volumio[32688]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Jan 26 13:50:39 volumio volumio[32688]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Jan 26 13:50:39 volumio volumio[32688]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Jan 26 13:50:39 volumio volumio[32688]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Jan 26 13:50:39 volumio volumio[32688]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Jan 26 13:50:39 volumio volumio[32688]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Jan 26 13:50:39 volumio volumio[32688]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Jan 26 13:50:39 volumio volumio[32688]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Jan 26 13:50:39 volumio volumio[32688]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Jan 26 13:50:39 volumio volumio[32688]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Jan 26 13:50:39 volumio volumio[32688]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Jan 26 13:50:39 volumio volumio[32688]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Jan 26 13:50:39 volumio volumio[32688]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Jan 26 13:50:39 volumio volumio[32688]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Jan 26 13:50:39 volumio volumio[32688]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Jan 26 13:50:39 volumio volumio[32688]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Jan 26 13:50:39 volumio volumio[32688]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Jan 26 13:50:39 volumio volumio[32688]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Jan 26 13:50:39 volumio volumio[32688]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Jan 26 13:50:39 volumio volumio[32688]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Jan 26 13:50:39 volumio volumio[32688]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Jan 26 13:50:39 volumio volumio[32688]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Jan 26 13:50:39 volumio volumio[32688]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Jan 26 13:50:39 volumio volumio[32688]: info: Adding plugin bluetooth to MyMusic Plugins Jan 26 13:50:39 volumio volumio[32688]: info: Adding plugin multiroom to MyMusic Plugins Jan 26 13:50:39 volumio volumio[32688]: info: Adding plugin metavolumio to MyMusic Plugins Jan 26 13:50:39 volumio volumio[32688]: info: Adding plugin cd_controller to MyMusic Plugins Jan 26 13:50:39 volumio volumio[32688]: info: Adding plugin qobuzconnect to MyMusic Plugins Jan 26 13:50:39 volumio volumio[32688]: info: Adding plugin smart_inputs to MyMusic Plugins Jan 26 13:50:39 volumio volumio[32688]: info: Adding plugin tidalconnect to MyMusic Plugins Jan 26 13:50:39 volumio volumio[32688]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Jan 26 13:50:40 volumio go-librespot[576]: time="2026-01-26T13:50:40+07:00" level=debug msg="obtained new client token: AAA8lRwpDBdf4+qEVrDsQO8YVOT3bMKCWOhkZHVWWLHhwY0xOpXFg7/BLy9KEVVJsk1I0oB3FSU9LWrJ8cG86dxW3DAUMnafuwx0uKL9/6/w3PjFQbR95b05JLDGPQmVSEKLhF4DqXOo7CkecxgkGdaGLqIpVf6tZU4j2wOsjO4TJWwheYZ7azFzobpjwJBvQkFd7ZUdKPRos46uzPnZeQxSBn1mPM6jNDqmLKlYW0PaLLYoWRtIC2rV" Jan 26 13:50:40 volumio go-librespot[576]: time="2026-01-26T13:50:40+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 26 13:50:40 volumio go-librespot[576]: time="2026-01-26T13:50:40+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Jan 26 13:50:40 volumio go-librespot[576]: time="2026-01-26T13:50:40+07:00" level=debug msg="completed keyexchange" Jan 26 13:50:40 volumio go-librespot[576]: time="2026-01-26T13:50:40+07:00" level=debug msg="completed challenge" Jan 26 13:50:40 volumio go-librespot[576]: time="2026-01-26T13:50:40+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 26 13:50:40 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 26 13:50:40 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 26 13:50:41 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 13:50:41 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 13:50:41 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 13:50:41 volumio volumio[32688]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Jan 26 13:50:41 volumio volumio[32688]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Jan 26 13:50:41 volumio volumio[32688]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 13:50:41 volumio volumio[32688]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 13:50:41 volumio volumio[32688]: info: Starting MyVolumio Remote Streaming Endpoints Jan 26 13:50:41 volumio volumio[32688]: info: MyVolumio login type: Token Jan 26 13:50:41 volumio volumio[32688]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Jan 26 13:50:41 volumio volumio[32688]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Jan 26 13:50:43 volumio volumio[32688]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Jan 26 13:50:43 volumio volumio[32688]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Jan 26 13:50:43 volumio volumio[32688]: info: Streaming services startup Jan 26 13:50:43 volumio volumio[32688]: info: Starting Streaming Daemon Jan 26 13:50:43 volumio volumio[32688]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Jan 26 13:50:43 volumio sudo[599]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jan 26 13:50:43 volumio sudo[599]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 13:50:43 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 13:50:43 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Jan 26 13:50:43 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 13:50:43 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 13:50:43 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 26 13:50:43 volumio sudo[599]: pam_unix(sudo:session): session closed for user root Jan 26 13:50:43 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 26 13:50:43 volumio volumio[32688]: info: Getting Spotify volume Jan 26 13:50:43 volumio go-librespot[608]: go-librespot daemon starting... Jan 26 13:50:43 volumio go-librespot[609]: time="2026-01-26T13:50:43+07:00" level=info msg="running go-librespot 0.4.0" Jan 26 13:50:43 volumio go-librespot[609]: time="2026-01-26T13:50:43+07:00" level=debug msg="app state loaded" Jan 26 13:50:43 volumio go-librespot[609]: time="2026-01-26T13:50:43+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 26 13:50:43 volumio volumio[32688]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 26 13:50:43 volumio volumio[32688]: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 26 13:50:43 volumio volumio[32688]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Jan 26 13:50:43 volumio volumio[32688]: errno: -111, Jan 26 13:50:43 volumio volumio[32688]: code: 'ECONNREFUSED', Jan 26 13:50:43 volumio volumio[32688]: syscall: 'connect', Jan 26 13:50:43 volumio volumio[32688]: address: '127.0.0.1', Jan 26 13:50:43 volumio volumio[32688]: port: 9879, Jan 26 13:50:43 volumio volumio[32688]: response: undefined Jan 26 13:50:43 volumio volumio[32688]: } Jan 26 13:50:43 volumio volumio[32688]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 26 13:50:44 volumio go-librespot[609]: time="2026-01-26T13:50:44+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 26 13:50:44 volumio go-librespot[609]: time="2026-01-26T13:50:44+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Jan 26 13:50:44 volumio go-librespot[609]: time="2026-01-26T13:50:44+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Jan 26 13:50:44 volumio go-librespot[609]: time="2026-01-26T13:50:44+07:00" level=info msg="zeroconf server listening on port 46629" Jan 26 13:50:44 volumio go-librespot[609]: time="2026-01-26T13:50:44+07:00" level=debug msg="obtained new client token: AADgH+Pi4v4I1/Mofc0LVkjJSxaxGkYYwdTuurN7wOLfcpLKlmWpQWPQGW58EcimHQiy23cMCe8KqYaG9DFvFiLmcEnxSm6j8ENk9sPvGb9QK+hyp3bVEBU8rgosl80ICwOmCVksS4omt2ymd+G6b6Y37AoDY2qE22jN5yYT4MeZEbmqjsBabcC9/qmXuis41cR/9o62Bgu/ERB5Cq9sxVGch+Ppq5tk3S42kMNp9Si9Veq2vXJiQDLtN3g=" Jan 26 13:50:44 volumio go-librespot[609]: time="2026-01-26T13:50:44+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 26 13:50:44 volumio go-librespot[609]: time="2026-01-26T13:50:44+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Jan 26 13:50:44 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 26 13:50:44 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 26 13:50:45 volumio sudo[635]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-01-26 13:49' Jan 26 13:50:45 volumio sudo[635]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 13:50:45 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 13:50:45 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 13:50:45 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 13:50:45 volumio sudo[635]: pam_unix(sudo:session): session closed for user root Jan 26 13:50:45 volumio volumio-remote-updater[628]: [2026-01-26 13:50:45] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Jan 26 13:50:45 volumio volumio-remote-updater[628]: [2026-01-26 13:50:45] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Jan 26 13:50:45 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Jan 26 13:50:45 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Jan 26 13:50:45 volumio systemd[1]: volumio.service: Consumed 1min 8.551s CPU time. Jan 26 13:50:45 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 26 13:50:45 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Jan 26 13:50:45 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 7046. Jan 26 13:50:45 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 26 13:50:45 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Jan 26 13:50:45 volumio systemd[1]: volumio.service: Consumed 1min 8.551s CPU time. Jan 26 13:50:46 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Jan 26 13:50:46 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Jan 26 13:50:47 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 13:50:47 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 13:50:47 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 13:50:47 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Jan 26 13:50:47 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 26 13:50:48 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 26 13:50:48 volumio go-librespot[671]: go-librespot daemon starting... Jan 26 13:50:48 volumio go-librespot[672]: time="2026-01-26T13:50:48+07:00" level=info msg="running go-librespot 0.4.0" Jan 26 13:50:48 volumio go-librespot[672]: time="2026-01-26T13:50:48+07:00" level=debug msg="app state loaded" Jan 26 13:50:48 volumio go-librespot[672]: time="2026-01-26T13:50:48+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 26 13:50:48 volumio go-librespot[672]: time="2026-01-26T13:50:48+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 26 13:50:48 volumio go-librespot[672]: time="2026-01-26T13:50:48+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 26 13:50:48 volumio go-librespot[672]: time="2026-01-26T13:50:48+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 26 13:50:48 volumio go-librespot[672]: time="2026-01-26T13:50:48+07:00" level=info msg="zeroconf server listening on port 43685" Jan 26 13:50:48 volumio go-librespot[672]: time="2026-01-26T13:50:48+07:00" level=debug msg="obtained new client token: AADiQyMJoliOzUynSX83eEPecJP0mhLrXSS4rHWlu6+jL9fRcOqDfSksx0Yqd1Acs8/oYZy9+n8dE9rrCkMq+Y++G00BiEY7rqH27FSbcyc5a0YBPC1Ze/ToTzhZx9iKgqCEEHhh9yd9qwk3RiMM4io4Gql9pWDiwi4jGGXWAOeL0G6ZHk2+k6nBzjRSa+cG6cVERePVwcHaXd1lRDUdyWXSNYpu33Sr0eBzA6BgFSyNety1IvNzIVkA9YU=" Jan 26 13:50:49 volumio go-librespot[672]: time="2026-01-26T13:50:49+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 26 13:50:49 volumio go-librespot[672]: time="2026-01-26T13:50:49+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Jan 26 13:50:49 volumio go-librespot[672]: time="2026-01-26T13:50:49+07:00" level=debug msg="completed keyexchange" Jan 26 13:50:49 volumio go-librespot[672]: time="2026-01-26T13:50:49+07:00" level=debug msg="completed challenge" Jan 26 13:50:49 volumio go-librespot[672]: time="2026-01-26T13:50:49+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 26 13:50:49 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 26 13:50:49 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 26 13:50:49 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 13:50:49 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 13:50:49 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 13:50:49 volumio volumio[648]: info: ------------------------------------------- Jan 26 13:50:49 volumio volumio[648]: info: ----- Volumio3 ---- Jan 26 13:50:49 volumio volumio[648]: info: ------------------------------------------- Jan 26 13:50:49 volumio volumio[648]: info: ----- System startup ---- Jan 26 13:50:49 volumio volumio[648]: info: ------------------------------------------- Jan 26 13:50:50 volumio volumio-remote-updater[628]: [2026-01-26 13:50:50] [connect] Successful connection Jan 26 13:50:51 volumio volumio[648]: info: MYVOLUMIO Environment detected Jan 26 13:50:51 volumio volumio[648]: info: Plugin folders cleanup Jan 26 13:50:51 volumio volumio[648]: info: Scanning into folder /volumio/app/plugins/ Jan 26 13:50:51 volumio volumio[648]: info: Scanning category audio_interface Jan 26 13:50:51 volumio volumio[648]: info: Scanning category miscellanea Jan 26 13:50:51 volumio volumio[648]: info: Scanning category music_service Jan 26 13:50:51 volumio volumio[648]: info: Scanning category plugins.json Jan 26 13:50:51 volumio volumio[648]: info: Scanning category system_controller Jan 26 13:50:51 volumio volumio[648]: info: Scanning category user_interface Jan 26 13:50:51 volumio volumio[648]: info: Scanning into folder /data/plugins/ Jan 26 13:50:51 volumio volumio[648]: info: Scanning category music_service Jan 26 13:50:51 volumio volumio[648]: info: Plugin folders cleanup completed Jan 26 13:50:51 volumio volumio[648]: info: ------------------------------------------- Jan 26 13:50:51 volumio volumio[648]: info: ----- Core plugins startup ---- Jan 26 13:50:51 volumio volumio[648]: info: ------------------------------------------- Jan 26 13:50:51 volumio volumio[648]: info: Loading plugins from folder /volumio/app/plugins/ Jan 26 13:50:51 volumio volumio[648]: info: Adding plugin upnp to MyMusic Plugins Jan 26 13:50:51 volumio volumio[648]: info: Adding plugin airplay_emulation to MyMusic Plugins Jan 26 13:50:51 volumio volumio[648]: info: Adding plugin upnp_browser to MyMusic Plugins Jan 26 13:50:51 volumio volumio[648]: info: Loading plugins from folder /data/plugins/ Jan 26 13:50:51 volumio volumio[648]: info: Loading plugin "system"... Jan 26 13:50:51 volumio volumio[648]: info: Loading plugin "appearance"... Jan 26 13:50:51 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 13:50:51 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 13:50:51 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 13:50:52 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Jan 26 13:50:52 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 26 13:50:52 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 26 13:50:52 volumio go-librespot[693]: go-librespot daemon starting... Jan 26 13:50:52 volumio go-librespot[695]: time="2026-01-26T13:50:52+07:00" level=info msg="running go-librespot 0.4.0" Jan 26 13:50:52 volumio go-librespot[695]: time="2026-01-26T13:50:52+07:00" level=debug msg="app state loaded" Jan 26 13:50:52 volumio go-librespot[695]: time="2026-01-26T13:50:52+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 26 13:50:53 volumio go-librespot[695]: time="2026-01-26T13:50:53+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 26 13:50:53 volumio go-librespot[695]: time="2026-01-26T13:50:53+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 26 13:50:53 volumio go-librespot[695]: time="2026-01-26T13:50:53+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 26 13:50:53 volumio go-librespot[695]: time="2026-01-26T13:50:53+07:00" level=info msg="zeroconf server listening on port 42151" Jan 26 13:50:53 volumio volumio[648]: info: Loading plugin "network"... Jan 26 13:50:53 volumio volumio[648]: info: Refreshing Cached IP Addresses Jan 26 13:50:53 volumio sudo[703]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 26 13:50:53 volumio sudo[703]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 13:50:53 volumio sudo[703]: pam_unix(sudo:session): session closed for user root Jan 26 13:50:53 volumio sudo[705]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 26 13:50:53 volumio volumio[648]: info: Loading plugin "services"... Jan 26 13:50:53 volumio sudo[705]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 13:50:53 volumio volumio[648]: info: Loading plugin "alsa_controller"... Jan 26 13:50:53 volumio sudo[705]: pam_unix(sudo:session): session closed for user root Jan 26 13:50:53 volumio go-librespot[695]: time="2026-01-26T13:50:53+07:00" level=debug msg="obtained new client token: AAD0w/Ov2gV5ItCZtxTqflUyxWegZjZ+t5EF0FtrrgG6WjIjz4I+CWQB2JPThVNLDdoXgAsT6bpkoQYmE9PIU+VTVH9wetFDTvjm2QrfFACFIkLlyCKfFQvm9jPC8rXtHUtnZZC84u4k3S7psKew4PB9cZl+xqE9khr3p2FeOoPA/tcFg8Cz2uWPtwiPl+5Xzl53BJWiEWMCcjxX7NQ/p5SoQivVPVrJafwEybXd+fkJT6HOqtK3XWUcMKk=" Jan 26 13:50:53 volumio sudo[713]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Jan 26 13:50:53 volumio sudo[713]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 13:50:53 volumio go-librespot[695]: time="2026-01-26T13:50:53+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 26 13:50:53 volumio volumio[648]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 26 13:50:53 volumio volumio[648]: info: Loading plugin "wizard"... Jan 26 13:50:53 volumio volumio[648]: info: Loading plugin "networkfs"... Jan 26 13:50:53 volumio go-librespot[695]: time="2026-01-26T13:50:53+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Jan 26 13:50:53 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 26 13:50:53 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 26 13:50:53 volumio volumio[648]: info: Starting Udev Watcher for removable devices Jan 26 13:50:53 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 13:50:53 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 13:50:53 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 13:50:53 volumio volumio[648]: info: Ignoring mount for partition: boot Jan 26 13:50:53 volumio volumio[648]: info: Ignoring mount for partition: volumio Jan 26 13:50:53 volumio volumio[648]: info: Ignoring mount for partition: volumio_data Jan 26 13:50:53 volumio volumio[648]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 26 13:50:53 volumio volumio[648]: info: Loading plugin "volumio_command_line_client"... Jan 26 13:50:53 volumio volumio[648]: info: Loading plugin "upnp"... Jan 26 13:50:53 volumio volumio[648]: info: [1769410253692] Starting Upmpd Daemon Jan 26 13:50:53 volumio volumio[648]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 26 13:50:53 volumio volumio[648]: info: Loading plugin "my_music"... Jan 26 13:50:53 volumio volumio[648]: info: Loading plugin "mpd"... Jan 26 13:50:54 volumio volumio[648]: info: Loading plugin "upnp_browser"... Jan 26 13:50:55 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 13:50:55 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 13:50:55 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 13:50:56 volumio sudo[713]: pam_unix(sudo:session): session closed for user root Jan 26 13:50:56 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Jan 26 13:50:56 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 26 13:50:56 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 26 13:50:56 volumio go-librespot[736]: go-librespot daemon starting... Jan 26 13:50:56 volumio go-librespot[737]: time="2026-01-26T13:50:56+07:00" level=info msg="running go-librespot 0.4.0" Jan 26 13:50:56 volumio go-librespot[737]: time="2026-01-26T13:50:56+07:00" level=debug msg="app state loaded" Jan 26 13:50:56 volumio go-librespot[737]: time="2026-01-26T13:50:56+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 26 13:50:57 volumio volumio[648]: info: Starting UPNP Browser Jan 26 13:50:57 volumio volumio[648]: info: Loading plugin "alarm-clock"... Jan 26 13:50:57 volumio go-librespot[737]: time="2026-01-26T13:50:57+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 26 13:50:57 volumio go-librespot[737]: time="2026-01-26T13:50:57+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Jan 26 13:50:57 volumio go-librespot[737]: time="2026-01-26T13:50:57+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Jan 26 13:50:57 volumio go-librespot[737]: time="2026-01-26T13:50:57+07:00" level=info msg="zeroconf server listening on port 35035" Jan 26 13:50:57 volumio go-librespot[737]: time="2026-01-26T13:50:57+07:00" level=debug msg="obtained new client token: AABv1lgoHaQPGkTfdJ0Dc2KBsG4LtOvu063LnwjSSloRk57K4/bZYBBI4Gid7g8BNFMA9QwVIMZ+mvWK81McCWpp3U0iSRddPgUzt6XdQ8l9nYhW9yuCx0UghTLTdPciQjYdA8MAxsInZU079LlyzUD2d8Q7img/PWoakKR6S8Jty7rBIizF5ZpIs1pFFjZX4VD3SOgfvSPtpU7tOeXL1IfPh5KRmibKkxWKNoQUB+dBwrn+0X8UfB7UTMA=" Jan 26 13:50:57 volumio volumio[648]: info: Loading plugin "airplay_emulation"... Jan 26 13:50:57 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 13:50:57 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 13:50:57 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 13:50:57 volumio volumio[648]: info: Starting Shairport Sync Jan 26 13:50:57 volumio volumio[648]: info: Loading plugin "last_100"... Jan 26 13:50:57 volumio volumio[648]: info: Loading plugin "webradio"... Jan 26 13:50:57 volumio go-librespot[737]: time="2026-01-26T13:50:57+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 26 13:50:57 volumio go-librespot[737]: time="2026-01-26T13:50:57+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Jan 26 13:50:57 volumio go-librespot[737]: time="2026-01-26T13:50:57+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Jan 26 13:50:57 volumio volumio[648]: info: Loading plugin "i2s_dacs"... Jan 26 13:50:57 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 26 13:50:57 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 26 13:50:57 volumio volumio[648]: info: Loading plugin "volumiodiscovery"... Jan 26 13:50:57 volumio volumio[648]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 26 13:50:57 volumio volumio[648]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 26 13:50:57 volumio volumio[648]: *** WARNING *** For more information see Jan 26 13:50:57 volumio volumio[648]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 26 13:50:57 volumio volumio[648]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 26 13:50:57 volumio volumio[648]: *** WARNING *** For more information see Jan 26 13:50:57 volumio node[648]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 26 13:50:57 volumio node[648]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 26 13:50:57 volumio node[648]: *** WARNING *** For more information see Jan 26 13:50:57 volumio node[648]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 26 13:50:57 volumio node[648]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 26 13:50:57 volumio node[648]: *** WARNING *** For more information see Jan 26 13:50:57 volumio volumio[648]: info: Applying required configuration parameters for plugin volumiodiscovery Jan 26 13:50:57 volumio volumio[648]: info: Discovery: Started advertising with name: Volumio Jan 26 13:50:58 volumio volumio[648]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 26 13:50:58 volumio volumio[648]: info: Loading plugin "spop"... Jan 26 13:50:59 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 13:50:59 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 13:50:59 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 13:50:59 volumio volumio[648]: info: Loading plugin "ytcr"... Jan 26 13:51:00 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Jan 26 13:51:00 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 26 13:51:01 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 26 13:51:01 volumio go-librespot[752]: go-librespot daemon starting... Jan 26 13:51:01 volumio go-librespot[753]: time="2026-01-26T13:51:01+07:00" level=info msg="running go-librespot 0.4.0" Jan 26 13:51:01 volumio go-librespot[753]: time="2026-01-26T13:51:01+07:00" level=debug msg="app state loaded" Jan 26 13:51:01 volumio go-librespot[753]: time="2026-01-26T13:51:01+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 26 13:51:01 volumio go-librespot[753]: time="2026-01-26T13:51:01+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 26 13:51:01 volumio go-librespot[753]: time="2026-01-26T13:51:01+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 26 13:51:01 volumio go-librespot[753]: time="2026-01-26T13:51:01+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 26 13:51:01 volumio go-librespot[753]: time="2026-01-26T13:51:01+07:00" level=info msg="zeroconf server listening on port 39543" Jan 26 13:51:01 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 13:51:01 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 13:51:01 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 13:51:01 volumio go-librespot[753]: time="2026-01-26T13:51:01+07:00" level=debug msg="obtained new client token: AADHEgLl0fAcLyvk4Nifnec13x1WNgKKIM3h+Z1NjBDQ/uSZjyAMGHdJWT7Ao3zQIkhTVR7gV2gvgz0+Tslj752GJNwrGiqrLp0rFqGbcYvywTZd+XWFwqA6f6Dzp2MYZOjVkC1DqRksBpOKVicV8Pi36ikzrxEKsVSivAIW6Pze4X+kmHt2cNGbUv2F2CCjnIv7ruQu82/zdkb5GSa+KbwuSmSQFTkoyci0OlfZu2ftZZx3H3g7eT6FCmY=" Jan 26 13:51:01 volumio go-librespot[753]: time="2026-01-26T13:51:01+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 26 13:51:02 volumio go-librespot[753]: time="2026-01-26T13:51:02+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: read tcp 192.168.1.107:40414->104.199.241.202:4070: read: connection reset by peer" Jan 26 13:51:02 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 26 13:51:02 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 26 13:51:02 volumio volumio[648]: info: Loading plugin "ytmusic"... Jan 26 13:51:03 volumio volumio-remote-updater[628]: [2026-01-26 13:51:03] [connect] Successful connection Jan 26 13:51:03 volumio volumio[648]: info: Loading plugin "outputs"... Jan 26 13:51:03 volumio volumio[648]: info: Loading plugin "albumart"... Jan 26 13:51:03 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 13:51:03 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 13:51:03 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 13:51:03 volumio volumio[648]: info: Plugin example_plugin is not enabled Jan 26 13:51:03 volumio volumio[648]: info: Loading plugin "inputs"... Jan 26 13:51:03 volumio volumio[648]: info: Loading plugin "updater_comm"... Jan 26 13:51:03 volumio volumio[648]: info: Plugin mpdemulation is not enabled Jan 26 13:51:03 volumio volumio[648]: info: Loading plugin "rest_api"... Jan 26 13:51:03 volumio volumio[648]: info: Loading plugin "websocket"... Jan 26 13:51:03 volumio volumio[648]: info: Starting Socket.io Server version 1.7.4 Jan 26 13:51:03 volumio volumio[648]: info: Loading plugin "RoonBridge"... Jan 26 13:51:04 volumio volumio[648]: info: Applying required configuration parameters for plugin RoonBridge Jan 26 13:51:04 volumio volumio[648]: info: Loading i18n strings for locale en Jan 26 13:51:04 volumio volumio[648]: Updating browse sources language Jan 26 13:51:04 volumio volumio[648]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 26 13:51:04 volumio volumio[776]: Forking 3 albumart workers Jan 26 13:51:04 volumio volumio[648]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 26 13:51:04 volumio volumio[648]: info: CoreCommandRouter::initPlayerControls Jan 26 13:51:04 volumio volumio[648]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 13:51:04 volumio volumio[648]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 13:51:04 volumio volumio[648]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 13:51:04 volumio volumio[648]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 13:51:04 volumio volumio[648]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 13:51:04 volumio volumio[648]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 13:51:04 volumio volumio[648]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 13:51:04 volumio volumio[648]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 13:51:04 volumio volumio[648]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 26 13:51:04 volumio volumio[648]: Express server listening on port 3000 Jan 26 13:51:04 volumio volumio[648]: [Metrics] WebUI: 16s 84.48ms Jan 26 13:51:04 volumio volumio[648]: info: CoreStateMachine::resetVolumioState Jan 26 13:51:04 volumio volumio[648]: info: CoreStateMachine::getcurrentVolume Jan 26 13:51:04 volumio volumio[648]: info: CoreCommandRouter::volumioRetrievevolume Jan 26 13:51:05 volumio sudo[823]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 26 13:51:05 volumio sudo[823]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 13:51:05 volumio sudo[823]: pam_unix(sudo:session): session closed for user root Jan 26 13:51:05 volumio sudo[825]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 26 13:51:05 volumio sudo[825]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 13:51:05 volumio volumio[648]: info: Volumio Network Manager: Network status updated: 1 Jan 26 13:51:05 volumio sudo[825]: pam_unix(sudo:session): session closed for user root Jan 26 13:51:05 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Jan 26 13:51:05 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 26 13:51:05 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 26 13:51:05 volumio go-librespot[833]: go-librespot daemon starting... Jan 26 13:51:05 volumio volumio[648]: info: VolumeController:: Volume=100 Mute =false Jan 26 13:51:05 volumio volumio[648]: info: CoreStateMachine::pushState Jan 26 13:51:05 volumio volumio[648]: info: CorePlayQueue::getTrack 0 Jan 26 13:51:05 volumio volumio[648]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 26 13:51:05 volumio volumio[648]: info: CoreCommandRouter::volumioPushState Jan 26 13:51:05 volumio volumio[648]: info: CoreStateMachine::updateTrackBlock Jan 26 13:51:05 volumio volumio[648]: info: CorePlayQueue::getTrackBlock Jan 26 13:51:05 volumio volumio[648]: info: CoreCommandRouter::volumioRetrievevolume Jan 26 13:51:05 volumio go-librespot[834]: time="2026-01-26T13:51:05+07:00" level=info msg="running go-librespot 0.4.0" Jan 26 13:51:05 volumio go-librespot[834]: time="2026-01-26T13:51:05+07:00" level=debug msg="app state loaded" Jan 26 13:51:05 volumio go-librespot[834]: time="2026-01-26T13:51:05+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 26 13:51:05 volumio volumio-remote-updater[628]: [2026-01-26 13:51:05] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1769410263 101 Jan 26 13:51:05 volumio volumio[648]: 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 26 13:51:05 volumio volumio[648]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 13:51:05 volumio volumio[648]: info: Reloading queue from file Jan 26 13:51:05 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 13:51:05 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 13:51:05 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 13:51:05 volumio volumio[648]: info: CoreStateMachine::setRepeat null single undefined Jan 26 13:51:05 volumio volumio[648]: info: CoreStateMachine::pushState Jan 26 13:51:05 volumio volumio[648]: info: CorePlayQueue::getTrack 0 Jan 26 13:51:05 volumio volumio[648]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 26 13:51:05 volumio volumio[648]: info: CoreCommandRouter::volumioPushState Jan 26 13:51:05 volumio volumio[648]: info: CoreStateMachine::setRandom null Jan 26 13:51:05 volumio volumio[648]: info: CoreStateMachine::pushState Jan 26 13:51:05 volumio volumio[648]: info: CorePlayQueue::getTrack 0 Jan 26 13:51:05 volumio volumio[648]: info: CoreCommandRouter::volumioPushState Jan 26 13:51:05 volumio volumio[648]: info: Setting Device type: Raspberry PI Jan 26 13:51:05 volumio volumio[648]: info: Completed loading Core Plugins Jan 26 13:51:05 volumio volumio[648]: info: Preparing to generate the ALSA configuration file Jan 26 13:51:05 volumio volumio[648]: info: VolumeController:: Volume=100 Mute =false Jan 26 13:51:05 volumio volumio[648]: info: CoreStateMachine::pushState Jan 26 13:51:05 volumio volumio[648]: info: CorePlayQueue::getTrack 0 Jan 26 13:51:05 volumio volumio[648]: info: CoreCommandRouter::volumioPushState Jan 26 13:51:05 volumio volumio[648]: info: Asound.conf file unchanged, so no further update is needed Jan 26 13:51:05 volumio volumio[648]: info: Output device has changed, restarting MPD Jan 26 13:51:06 volumio sudo[855]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 26 13:51:06 volumio sudo[855]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 13:51:06 volumio sudo[855]: pam_unix(sudo:session): session closed for user root Jan 26 13:51:06 volumio sudo[853]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Jan 26 13:51:06 volumio sudo[853]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 13:51:06 volumio volumio[648]: info: Output device has changed, restarting Shairport Sync Jan 26 13:51:06 volumio volumio[648]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 13:51:06 volumio volumio[648]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 13:51:06 volumio volumio[648]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 26 13:51:06 volumio volumio[648]: info: ___________ START PLUGINS ___________ Jan 26 13:51:06 volumio go-librespot[834]: time="2026-01-26T13:51:06+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 26 13:51:06 volumio go-librespot[834]: time="2026-01-26T13:51:06+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 26 13:51:06 volumio go-librespot[834]: time="2026-01-26T13:51:06+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 26 13:51:06 volumio sudo[859]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 26 13:51:06 volumio sudo[859]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 13:51:06 volumio go-librespot[834]: time="2026-01-26T13:51:06+07:00" level=info msg="zeroconf server listening on port 39025" Jan 26 13:51:06 volumio volumio[648]: info: ControllerMpd::onStart: Initializing MPD Jan 26 13:51:06 volumio volumio[648]: info: Creating MPD Configuration file Jan 26 13:51:06 volumio volumio[648]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 26 13:51:06 volumio sudo[853]: pam_unix(sudo:session): session closed for user root Jan 26 13:51:06 volumio volumio[648]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 26 13:51:06 volumio volumio[648]: info: [1769410266237] CoreMusicLibrary::Adding element Media Servers Jan 26 13:51:06 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Jan 26 13:51:06 volumio volumio[648]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 26 13:51:06 volumio volumio[648]: info: UPNP Browser: Client initialized successfully Jan 26 13:51:06 volumio sudo[876]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 26 13:51:06 volumio go-librespot[834]: time="2026-01-26T13:51:06+07:00" level=debug msg="obtained new client token: AAC5sA1GVd5QOTrdBVe5i72y5wKFlqYk0nqrkFdQjfIpR1BvJjHzoj3KTNvVm+D/Q/9q1JpNbo9dvteDsLw7ID+S0wlsox2YVipbSAIMgC8kKofMu+hn52RJWezyTRu8xW8CGh2RJSMaq6N7PR4K28u987BYbrJGKZPQa1w10KhP2+mHKeDDpl4bDoPPTcOvKmKt3FVwlxOlzn2nLohXRAZ1DJAPaCi6syT0BunEYcT6Az51uzPVxcORoK8=" Jan 26 13:51:06 volumio sudo[876]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 13:51:06 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 26 13:51:06 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 26 13:51:06 volumio systemd[1]: mpd.service: Consumed 7.333s CPU time. Jan 26 13:51:06 volumio sudo[874]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 26 13:51:06 volumio sudo[874]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 13:51:06 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 26 13:51:06 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 26 13:51:06 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 26 13:51:06 volumio sudo[874]: pam_unix(sudo:session): session closed for user root Jan 26 13:51:06 volumio volumio[648]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 13:51:06 volumio volumio[648]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 13:51:06 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 26 13:51:06 volumio go-librespot[834]: time="2026-01-26T13:51:06+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 26 13:51:06 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 26 13:51:06 volumio volumio[648]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 26 13:51:06 volumio volumio[648]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 13:51:06 volumio volumio[648]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 13:51:06 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 26 13:51:06 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 26 13:51:06 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 26 13:51:06 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 26 13:51:06 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 26 13:51:06 volumio volumio[648]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 26 13:51:06 volumio volumio[648]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 26 13:51:06 volumio volumio[648]: info: [1769410266667] CoreMusicLibrary::Adding element Last_100 Jan 26 13:51:06 volumio volumio[648]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 26 13:51:06 volumio volumio[648]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 26 13:51:06 volumio volumio[648]: info: [1769410266686] CoreMusicLibrary::Adding element Webradio Jan 26 13:51:06 volumio volumio[648]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 26 13:51:06 volumio volumio[648]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 26 13:51:06 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 26 13:51:06 volumio volumio[648]: info: Initializing BBC Radios Jan 26 13:51:06 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 26 13:51:06 volumio volumio[648]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 26 13:51:06 volumio volumio[648]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 13:51:06 volumio go-librespot[834]: time="2026-01-26T13:51:06+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: read tcp 192.168.1.107:37204->104.199.241.202:4070: read: connection reset by peer" Jan 26 13:51:06 volumio volumio[648]: info: Creating Spotify config file Jan 26 13:51:06 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 26 13:51:06 volumio volumio[648]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 13:51:06 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 26 13:51:07 volumio sudo[890]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 26 13:51:07 volumio sudo[890]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jan 26 13:51:07 volumio sudo[890]: pam_unix(sudo:session): session closed for user root Jan 26 13:51:07 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 13:51:07 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 13:51:07 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 13:51:08 volumio volumio[648]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 26 13:51:08 volumio volumio[648]: info: [1769410268111] CoreMusicLibrary::Adding element YouTube Music Jan 26 13:51:08 volumio volumio[648]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 26 13:51:08 volumio volumio[648]: Cannot find translation for source YouTube Music Jan 26 13:51:08 volumio volumio[648]: info: Volumio Calling Home Jan 26 13:51:08 volumio sudo[908]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Jan 26 13:51:08 volumio sudo[908]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 13:51:08 volumio sudo[908]: pam_unix(sudo:session): session closed for user root Jan 26 13:51:08 volumio volumio[786]: Starting albumart workers Jan 26 13:51:08 volumio volumio[787]: Starting albumart workers Jan 26 13:51:08 volumio volumio[788]: Starting albumart workers Jan 26 13:51:09 volumio volumio[648]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Jan 26 13:51:09 volumio volumio[648]: info: Discovery: Found device Volumio Jan 26 13:51:09 volumio volumio[648]: info: CoreCommandRouter::volumioGetState Jan 26 13:51:09 volumio volumio[648]: info: CorePlayQueue::getTrack 0 Jan 26 13:51:09 volumio volumio[648]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Jan 26 13:51:09 volumio volumio[648]: info: Discovery: Found device Volumio Jan 26 13:51:09 volumio volumio[648]: info: CoreCommandRouter::volumioGetState Jan 26 13:51:09 volumio volumio[648]: info: CorePlayQueue::getTrack 0 Jan 26 13:51:09 volumio volumio[648]: info: MPD Permissions set Jan 26 13:51:09 volumio volumio[648]: info: MPD Permissions set Jan 26 13:51:09 volumio volumio[648]: info: Upmpdcli Daemon Started Jan 26 13:51:09 volumio volumio[648]: info: Spotify config file written Jan 26 13:51:09 volumio sudo[914]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jan 26 13:51:09 volumio sudo[914]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 13:51:09 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 13:51:09 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 13:51:09 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 13:51:09 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 26 13:51:09 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 26 13:51:09 volumio go-librespot[916]: go-librespot daemon starting... Jan 26 13:51:09 volumio sudo[914]: pam_unix(sudo:session): session closed for user root Jan 26 13:51:09 volumio go-librespot[917]: time="2026-01-26T13:51:09+07:00" level=info msg="running go-librespot 0.4.0" Jan 26 13:51:09 volumio go-librespot[917]: time="2026-01-26T13:51:09+07:00" level=debug msg="app state loaded" Jan 26 13:51:09 volumio go-librespot[917]: time="2026-01-26T13:51:09+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 26 13:51:10 volumio volumio[648]: 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 26 13:51:10 volumio volumio[648]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 13:51:10 volumio volumio[648]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 13:51:10 volumio volumio[648]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 13:51:10 volumio volumio[648]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 13:51:10 volumio volumio[648]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 13:51:10 volumio volumio[648]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 13:51:10 volumio volumio[648]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 13:51:10 volumio volumio[648]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 13:51:10 volumio volumio[648]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 13:51:10 volumio volumio[648]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 13:51:10 volumio volumio[648]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 13:51:10 volumio volumio[648]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 13:51:10 volumio volumio[648]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 13:51:10 volumio volumio[648]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 13:51:10 volumio volumio[648]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 13:51:10 volumio volumio[648]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 13:51:10 volumio volumio[648]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 13:51:10 volumio volumio[648]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 13:51:10 volumio volumio[648]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 13:51:10 volumio volumio[648]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 13:51:10 volumio volumio[648]: info: No need to fix Spotify hosts Jan 26 13:51:10 volumio go-librespot[917]: time="2026-01-26T13:51: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-gew4.spotify.com:80]" Jan 26 13:51:10 volumio go-librespot[917]: time="2026-01-26T13:51:10+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 26 13:51:10 volumio go-librespot[917]: time="2026-01-26T13:51:10+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 26 13:51:10 volumio go-librespot[917]: time="2026-01-26T13:51:10+07:00" level=info msg="zeroconf server listening on port 40889" Jan 26 13:51:11 volumio go-librespot[917]: time="2026-01-26T13:51:11+07:00" level=debug msg="obtained new client token: AACHdduotuTq6igiZyOVUqoFWaSqPJXM4bjo00wNnQGhyU13q8BtRzTNTe1ehV1FsmbR9eLYGIyOJcwxXxizVzDpT702+PmCs1sJqNdaNmKoSzsvykGDdS5+dytLwihrfUI+aY6mgk9/UlslJB/i6D2OhId0yFQBWLE+P2Ybx7OYOPtDiXRXywW9TcIAwxch5kQKTs0nZThtqd01FTyMfZV2A1z4ADjtIiPSpWcfxFOCKYeK8ETyGuB51jE=" Jan 26 13:51:11 volumio go-librespot[917]: time="2026-01-26T13:51:11+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 26 13:51:11 volumio go-librespot[917]: time="2026-01-26T13:51:11+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Jan 26 13:51:11 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 26 13:51:11 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 26 13:51:11 volumio volumio[648]: info: Volumio called home Jan 26 13:51:11 volumio volumio[648]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 26 13:51:11 volumio volumio[648]: SPOTIFY: BQC0J6jqLEtqYvRmjayjWwp86IS-G8N2CfqOPV8JO4GJkec1CwQVAYqVvami1gW_cE6PhwsFC76dYhh2xGJxrqAClx2CKWy6tCHizAc-AGdxAWoJNyFoeeUcK_XzUTdAAOxuhxk5lQMkqWJ0_mtDxq79AI_GTB52T2AnctSmmItZDxI52werhIx2qsSLpfm-AF6ZN3IbXer3DR7WJG5237aa8JFNQGq59uq4oiQvHhaEYvM7xU5Cr_A4eUrySUXzmoMCB9T-ZyzgXIY2iMwHpEqyz0_b65z5ovbWl0UKCR3g-DGIjl7gqYcu Jan 26 13:51:11 volumio volumio[648]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 26 13:51:11 volumio volumio[648]: info: New Spotify access token = BQC0J6jqLEtqYvRmjayjWwp86IS-G8N2CfqOPV8JO4GJkec1CwQVAYqVvami1gW_cE6PhwsFC76dYhh2xGJxrqAClx2CKWy6tCHizAc-AGdxAWoJNyFoeeUcK_XzUTdAAOxuhxk5lQMkqWJ0_mtDxq79AI_GTB52T2AnctSmmItZDxI52werhIx2qsSLpfm-AF6ZN3IbXer3DR7WJG5237aa8JFNQGq59uq4oiQvHhaEYvM7xU5Cr_A4eUrySUXzmoMCB9T-ZyzgXIY2iMwHpEqyz0_b65z5ovbWl0UKCR3g-DGIjl7gqYcu Jan 26 13:51:11 volumio volumio[648]: info: Spotify credentials grant success - running version from March 24, 2019 Jan 26 13:51:11 volumio volumio[648]: info: Starting Shairport Sync Jan 26 13:51:11 volumio volumio[648]: info: Starting Shairport Sync Jan 26 13:51:11 volumio volumio[648]: info: Starting Shairport Sync Jan 26 13:51:11 volumio sudo[955]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 26 13:51:11 volumio sudo[955]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 13:51:11 volumio sudo[957]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 26 13:51:11 volumio sudo[957]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 13:51:11 volumio sudo[959]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 26 13:51:11 volumio sudo[959]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 13:51:11 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 13:51:11 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 13:51:11 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 13:51:11 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 26 13:51:11 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Jan 26 13:51:11 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 26 13:51:11 volumio systemd[1]: shairport-sync.service: Consumed 2.461s CPU time. Jan 26 13:51:11 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 26 13:51:11 volumio volumio[648]: info: CoreCommandRouter::volumioGetState Jan 26 13:51:11 volumio volumio[648]: info: CorePlayQueue::getTrack 0 Jan 26 13:51:11 volumio sudo[959]: pam_unix(sudo:session): session closed for user root Jan 26 13:51:11 volumio sudo[957]: pam_unix(sudo:session): session closed for user root Jan 26 13:51:11 volumio sudo[955]: pam_unix(sudo:session): session closed for user root Jan 26 13:51:12 volumio volumio[648]: info: Shairport-Sync Started Jan 26 13:51:12 volumio volumio[648]: Error adding Membership: Error: addMembership EINVAL Jan 26 13:51:12 volumio volumio[648]: info: Shairport-Sync Started Jan 26 13:51:12 volumio volumio[648]: info: Shairport-Sync Started Jan 26 13:51:12 volumio volumio[648]: 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 26 13:51:12 volumio volumio[648]: info: Spotify Successfully logged in Jan 26 13:51:12 volumio volumio[648]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 26 13:51:12 volumio volumio[648]: info: [1769410272163] CoreMusicLibrary::Adding element Spotify Jan 26 13:51:12 volumio volumio[648]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 26 13:51:12 volumio volumio[648]: Cannot find translation for source YouTube Music Jan 26 13:51:12 volumio volumio[648]: Cannot find translation for source Spotify Jan 26 13:51:12 volumio volumio[648]: info: [yt-cast-receiver] DIAL server listening on port 8098 Jan 26 13:51:12 volumio volumio[648]: info: CoreCommandRouter::volumioRetrievevolume Jan 26 13:51:13 volumio volumio[648]: info: VolumeController:: Volume=100 Mute =false Jan 26 13:51:13 volumio volumio[648]: info: CoreCommandRouter::volumioGetState Jan 26 13:51:13 volumio volumio[648]: info: CorePlayQueue::getTrack 0 Jan 26 13:51:13 volumio volumio[648]: info: CoreStateMachine::pushState Jan 26 13:51:13 volumio volumio[648]: info: CorePlayQueue::getTrack 0 Jan 26 13:51:13 volumio volumio[648]: info: CoreCommandRouter::volumioPushState Jan 26 13:51:13 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 13:51:13 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 13:51:13 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 13:51:14 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Jan 26 13:51:14 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 26 13:51:14 volumio volumio[648]: info: go-librespot daemon successfully initialized Jan 26 13:51:14 volumio go-librespot[998]: go-librespot daemon starting... Jan 26 13:51:14 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 26 13:51:14 volumio go-librespot[999]: time="2026-01-26T13:51:14+07:00" level=info msg="running go-librespot 0.4.0" Jan 26 13:51:14 volumio go-librespot[999]: time="2026-01-26T13:51:14+07:00" level=debug msg="app state loaded" Jan 26 13:51:14 volumio go-librespot[999]: time="2026-01-26T13:51:14+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 26 13:51:14 volumio mpd[906]: 2026-01-26T13:51:14 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 26 13:51:14 volumio systemd[1]: Started mpd.service - Music Player Daemon. Jan 26 13:51:14 volumio sudo[859]: pam_unix(sudo:session): session closed for user root Jan 26 13:51:14 volumio sudo[876]: pam_unix(sudo:session): session closed for user root Jan 26 13:51:14 volumio volumio[648]: error: MPD error: The expression evaluated to a falsy value: Jan 26 13:51:14 volumio volumio[648]: assert.ok(self.idling) Jan 26 13:51:14 volumio volumio[648]: error: The expression evaluated to a falsy value: Jan 26 13:51:14 volumio volumio[648]: assert.ok(self.idling) Jan 26 13:51:14 volumio volumio[648]: error: updateQueue error: null Jan 26 13:51:14 volumio volumio[648]: info: Completed starting Core Plugins Jan 26 13:51:14 volumio volumio[648]: info: ------------------------------------------- Jan 26 13:51:14 volumio volumio[648]: info: ----- MyVolumio plugins startup ---- Jan 26 13:51:14 volumio volumio[648]: info: ------------------------------------------- Jan 26 13:51:14 volumio volumio[648]: info: [MyVolumio PluginManager] Fetching plans data.... Jan 26 13:51:15 volumio volumio[648]: info: MPD running with PID906 Jan 26 13:51:15 volumio volumio[648]: ,establishing connection Jan 26 13:51:15 volumio go-librespot[999]: time="2026-01-26T13:51:15+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 26 13:51:15 volumio go-librespot[999]: time="2026-01-26T13:51:15+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 26 13:51:15 volumio go-librespot[999]: time="2026-01-26T13:51:15+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 26 13:51:15 volumio volumio[648]: error: updateQueue error: null Jan 26 13:51:15 volumio go-librespot[999]: time="2026-01-26T13:51:15+07:00" level=info msg="zeroconf server listening on port 41757" Jan 26 13:51:15 volumio go-librespot[999]: time="2026-01-26T13:51:15+07:00" level=debug msg="obtained new client token: AAC+SdCLR5NTYuNzRgk1qSmLm0A2YV4UqCJj1CVpRYDax/VQYfhcY3QMeDlXSqPPND2uGxTZvU/c7Rm6mJ2xnbV6aFLhwNUlSIULEOHBXlgc97yZ2+BQwoWnlqj56ltKEpjZM9YRnAQjncbCPBSFTYjQ43yahqkQirtFA4vna6w40E/DsqfNDKzi7H1pklHvr7gTKfZHIhZ8cyJTn7Wj43Aso4oTT/liehiWxFDdnbprvgP0ApQCZuSL" Jan 26 13:51:15 volumio go-librespot[999]: time="2026-01-26T13:51:15+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 26 13:51:15 volumio go-librespot[999]: time="2026-01-26T13:51:15+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Jan 26 13:51:15 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 26 13:51:15 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 26 13:51:15 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 13:51:15 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 13:51:15 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 13:51:17 volumio volumio[648]: info: Initializing connection to go-librespot Websocket Jan 26 13:51:17 volumio volumio[648]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 26 13:51:17 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 13:51:17 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 13:51:17 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 13:51:18 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 11. Jan 26 13:51:18 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 26 13:51:18 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 26 13:51:18 volumio go-librespot[1010]: go-librespot daemon starting... Jan 26 13:51:18 volumio go-librespot[1011]: time="2026-01-26T13:51:18+07:00" level=info msg="running go-librespot 0.4.0" Jan 26 13:51:18 volumio go-librespot[1011]: time="2026-01-26T13:51:18+07:00" level=debug msg="app state loaded" Jan 26 13:51:18 volumio go-librespot[1011]: time="2026-01-26T13:51:18+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 26 13:51:19 volumio go-librespot[1011]: time="2026-01-26T13:51: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 26 13:51:19 volumio go-librespot[1011]: time="2026-01-26T13:51: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 26 13:51:19 volumio go-librespot[1011]: time="2026-01-26T13:51: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 26 13:51:19 volumio go-librespot[1011]: time="2026-01-26T13:51:19+07:00" level=info msg="zeroconf server listening on port 42589" Jan 26 13:51:19 volumio go-librespot[1011]: time="2026-01-26T13:51:19+07:00" level=debug msg="obtained new client token: AAD3uyVaANHnnBRogOgDnqqFSh+WXYKLLQ7si6Fe5xaKJk2mTIRdC5d9x3beY1Uoyys7wL0kTktgmQfFvZkX8bn+DZZhqpbH21WEskcCOckRo+cXgOZTF6EpJZDFTrTTr8zvgTWZ2FQ+B0mPfXR/1wJ7nzuffPzXaU7C3pxArjVTDVOC5mslaUbhOIc77plch/cKs6R21h9Z7+hq57EMadtryNAtoA7zqXHbCGNP9Zon8ZKULXj3+m4kpls=" Jan 26 13:51:19 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 13:51:19 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 13:51:19 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 13:51:19 volumio go-librespot[1011]: time="2026-01-26T13:51:19+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 26 13:51:19 volumio volumio[648]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Jan 26 13:51:19 volumio go-librespot[1011]: time="2026-01-26T13:51:19+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Jan 26 13:51:19 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 26 13:51:19 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 26 13:51:20 volumio volumio[648]: info: Initializing connection to go-librespot Websocket Jan 26 13:51:20 volumio volumio[648]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 26 13:51:21 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 13:51:21 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 13:51:21 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 13:51:22 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 12. Jan 26 13:51:22 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 26 13:51:23 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 26 13:51:23 volumio go-librespot[1020]: go-librespot daemon starting... Jan 26 13:51:23 volumio go-librespot[1021]: time="2026-01-26T13:51:23+07:00" level=info msg="running go-librespot 0.4.0" Jan 26 13:51:23 volumio go-librespot[1021]: time="2026-01-26T13:51:23+07:00" level=debug msg="app state loaded" Jan 26 13:51:23 volumio go-librespot[1021]: time="2026-01-26T13:51:23+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 26 13:51:23 volumio volumio[648]: info: Initializing connection to go-librespot Websocket Jan 26 13:51:23 volumio go-librespot[1021]: time="2026-01-26T13:51:23+07:00" level=debug msg="new websocket client" Jan 26 13:51:23 volumio volumio[648]: info: Connection to go-librespot Websocket established Jan 26 13:51:23 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 13:51:23 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 13:51:23 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 13:51:23 volumio go-librespot[1021]: time="2026-01-26T13:51:23+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 26 13:51:23 volumio go-librespot[1021]: time="2026-01-26T13:51:23+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 26 13:51:23 volumio go-librespot[1021]: time="2026-01-26T13:51:23+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 26 13:51:23 volumio go-librespot[1021]: time="2026-01-26T13:51:23+07:00" level=info msg="zeroconf server listening on port 33695" Jan 26 13:51:23 volumio volumio[648]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Jan 26 13:51:23 volumio volumio[648]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Jan 26 13:51:23 volumio volumio[648]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Jan 26 13:51:23 volumio volumio[648]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Jan 26 13:51:23 volumio volumio[648]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Jan 26 13:51:23 volumio volumio[648]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Jan 26 13:51:23 volumio volumio[648]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Jan 26 13:51:23 volumio volumio[648]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Jan 26 13:51:23 volumio volumio[648]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Jan 26 13:51:23 volumio volumio[648]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Jan 26 13:51:23 volumio volumio[648]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Jan 26 13:51:23 volumio volumio[648]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Jan 26 13:51:23 volumio volumio[648]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Jan 26 13:51:23 volumio volumio[648]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Jan 26 13:51:23 volumio volumio[648]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Jan 26 13:51:23 volumio volumio[648]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Jan 26 13:51:23 volumio volumio[648]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Jan 26 13:51:23 volumio volumio[648]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Jan 26 13:51:23 volumio volumio[648]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Jan 26 13:51:23 volumio volumio[648]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Jan 26 13:51:23 volumio volumio[648]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Jan 26 13:51:23 volumio volumio[648]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Jan 26 13:51:23 volumio volumio[648]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Jan 26 13:51:23 volumio volumio[648]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Jan 26 13:51:23 volumio volumio[648]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Jan 26 13:51:23 volumio volumio[648]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Jan 26 13:51:23 volumio volumio[648]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Jan 26 13:51:23 volumio volumio[648]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Jan 26 13:51:23 volumio volumio[648]: info: Adding plugin bluetooth to MyMusic Plugins Jan 26 13:51:23 volumio volumio[648]: info: Adding plugin multiroom to MyMusic Plugins Jan 26 13:51:23 volumio volumio[648]: info: Adding plugin metavolumio to MyMusic Plugins Jan 26 13:51:23 volumio volumio[648]: info: Adding plugin cd_controller to MyMusic Plugins Jan 26 13:51:23 volumio volumio[648]: info: Adding plugin qobuzconnect to MyMusic Plugins Jan 26 13:51:23 volumio volumio[648]: info: Adding plugin smart_inputs to MyMusic Plugins Jan 26 13:51:23 volumio volumio[648]: info: Adding plugin tidalconnect to MyMusic Plugins Jan 26 13:51:23 volumio volumio[648]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Jan 26 13:51:23 volumio go-librespot[1021]: time="2026-01-26T13:51:23+07:00" level=debug msg="obtained new client token: AADuF2mPPfM8KgfYoLqgKqvOi9prIUEcx8Jhe1uTWsEBtNR9fnviexhptfXnj63BrdYOT+UFvtYZmVMA3n5DaSfzwLqB2t3w4GDJksn6z4nN1kH06ckroH4FbAseEcmDRYX3TzGCj7PE4M0AUT3H4nJCJ2ZXCGRxxairxhjm+HJO0522Cu1+XU0J/dD1Lp2tCW/uv75mjWiRPFuRzwhvZYYKi8MeIl+PSnRrW2rn0DdnMHF5F7HwWMCGp2Y=" Jan 26 13:51:24 volumio go-librespot[1021]: time="2026-01-26T13:51:24+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 26 13:51:24 volumio go-librespot[1021]: time="2026-01-26T13:51:24+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Jan 26 13:51:24 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 26 13:51:24 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 26 13:51:25 volumio volumio[648]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Jan 26 13:51:25 volumio volumio[648]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Jan 26 13:51:25 volumio volumio[648]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 13:51:25 volumio volumio[648]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 26 13:51:25 volumio volumio[648]: info: Starting MyVolumio Remote Streaming Endpoints Jan 26 13:51:25 volumio volumio[648]: info: MyVolumio login type: Token Jan 26 13:51:25 volumio volumio[648]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Jan 26 13:51:25 volumio volumio[648]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Jan 26 13:51:25 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 13:51:25 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 13:51:25 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 13:51:27 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 13. Jan 26 13:51:27 volumio volumio[648]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Jan 26 13:51:27 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 26 13:51:27 volumio volumio[648]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Jan 26 13:51:27 volumio volumio[648]: info: Streaming services startup Jan 26 13:51:27 volumio volumio[648]: info: Starting Streaming Daemon Jan 26 13:51:27 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 26 13:51:27 volumio go-librespot[1047]: go-librespot daemon starting... Jan 26 13:51:27 volumio sudo[1050]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jan 26 13:51:27 volumio sudo[1050]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 13:51:27 volumio volumio[648]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Jan 26 13:51:27 volumio go-librespot[1052]: time="2026-01-26T13:51:27+07:00" level=info msg="running go-librespot 0.4.0" Jan 26 13:51:27 volumio go-librespot[1052]: time="2026-01-26T13:51:27+07:00" level=debug msg="app state loaded" Jan 26 13:51:27 volumio go-librespot[1052]: time="2026-01-26T13:51:27+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 26 13:51:27 volumio sudo[1050]: pam_unix(sudo:session): session closed for user root Jan 26 13:51:27 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 13:51:27 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 13:51:27 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 13:51:27 volumio volumio[648]: info: Getting Spotify volume Jan 26 13:51:27 volumio volumio[648]: info: Connection to go-librespot Websocket closed Jan 26 13:51:27 volumio volumio[648]: error: Cannot start Volumio Streaming Daemon Jan 26 13:51:27 volumio volumio[648]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Jan 26 13:51:27 volumio volumio[648]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Jan 26 13:51:27 volumio volumio[648]: 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 26 13:51:27 volumio go-librespot[1052]: time="2026-01-26T13:51:27+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 26 13:51:27 volumio go-librespot[1052]: time="2026-01-26T13:51:27+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Jan 26 13:51:27 volumio go-librespot[1052]: time="2026-01-26T13:51:27+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Jan 26 13:51:27 volumio go-librespot[1052]: time="2026-01-26T13:51:27+07:00" level=info msg="zeroconf server listening on port 46541" Jan 26 13:51:28 volumio volumio[648]: info: CoreCommandRouter::volumioGetState Jan 26 13:51:28 volumio volumio[648]: info: CorePlayQueue::getTrack 0 Jan 26 13:51:28 volumio volumio[648]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jan 26 13:51:28 volumio volumio[648]: SPOTIFY: SPOTIFY VOLUME undefined Jan 26 13:51:28 volumio volumio[648]: SPOTIFY: VOLUMIO VOLUME 100 Jan 26 13:51:28 volumio volumio[648]: info: Aligning Spotify Volume to Volumio Volume Jan 26 13:51:28 volumio volumio[648]: info: CoreCommandRouter::volumioGetState Jan 26 13:51:28 volumio volumio[648]: info: CorePlayQueue::getTrack 0 Jan 26 13:51:28 volumio volumio[648]: info: Setting Spotify Volume from Volumio: 100 Jan 26 13:51:28 volumio go-librespot[1052]: time="2026-01-26T13:51:28+07:00" level=debug msg="obtained new client token: AAC1XhR6G5GwkBwV+7AxGERXkTTGlkFWsIeo1JcEWMOGHYCd/tVXqhHAsueOl0p0nUOKHb4yqnet34KPc2P8l6sUAMwM72AaZdHCUoP/8J4bK2bMFdHT93aq2WuMnP0SWTHKRUv/HjTmradDCV0+fgwxkC+xp2Y7yTJUSY2lII32xCZpjtNzgaITUNq2gh3YpWgKHvAU9LXlqUBqld9SyXkz5OoedeZ938IbYEJC97H2YdL8JQtNrhA7" Jan 26 13:51:28 volumio go-librespot[1052]: time="2026-01-26T13:51:28+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 26 13:51:28 volumio go-librespot[1052]: time="2026-01-26T13:51:28+07:00" level=debug msg="completed keyexchange" Jan 26 13:51:28 volumio go-librespot[1052]: time="2026-01-26T13:51:28+07:00" level=debug msg="completed challenge" Jan 26 13:51:28 volumio go-librespot[1052]: time="2026-01-26T13:51:28+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 26 13:51:28 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 26 13:51:28 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 26 13:51:28 volumio volumio[648]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 26 13:51:28 volumio volumio[648]: Error: socket hang up Jan 26 13:51:28 volumio volumio[648]: at connResetException (node:internal/errors:720:14) Jan 26 13:51:28 volumio volumio[648]: at Socket.socketOnEnd (node:_http_client:519:23) Jan 26 13:51:28 volumio volumio[648]: at Socket.emit (node:events:526:35) Jan 26 13:51:28 volumio volumio[648]: at endReadableNT (node:internal/streams/readable:1376:12) Jan 26 13:51:28 volumio volumio[648]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Jan 26 13:51:28 volumio volumio[648]: code: 'ECONNRESET', Jan 26 13:51:28 volumio volumio[648]: response: undefined Jan 26 13:51:28 volumio volumio[648]: } Jan 26 13:51:28 volumio volumio[648]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 26 13:51:29 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 26 13:51:29 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 26 13:51:29 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 26 13:51:30 volumio sudo[1078]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-01-26 13:50' Jan 26 13:51:30 volumio sudo[1078]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) PRETTY_NAME="Raspbian GNU/Linux 12 (bookworm)" NAME="Raspbian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="b05a530ca81d05eb9a84d0acf82089f0a60b8ee6" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="4ad85e2147d972f0b838d33c21382d2d813b2ae8" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu Dec 25 09:13:19 UTC 2025" VOLUMIO_VERSION="4.084" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="792f09af7488531aecd1aadcaa9b175e"