Jan 28 16:06:00 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 28 16:06:00 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Jan 28 16:06:00 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 10356. Jan 28 16:06:00 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 28 16:06:00 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Jan 28 16:06:00 volumio systemd[1]: volumio.service: Consumed 59.069s CPU time. Jan 28 16:06:00 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Jan 28 16:06:00 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Jan 28 16:06:00 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 16:06:00 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 16:06:00 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 16:06:00 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 15. Jan 28 16:06:00 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 16:06:01 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 16:06:01 volumio go-librespot[14024]: go-librespot daemon starting... Jan 28 16:06:01 volumio go-librespot[14025]: time="2026-01-28T16:06:01+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 16:06:01 volumio go-librespot[14025]: time="2026-01-28T16:06:01+07:00" level=debug msg="app state loaded" Jan 28 16:06:01 volumio go-librespot[14025]: time="2026-01-28T16:06:01+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 16:06:01 volumio go-librespot[14025]: time="2026-01-28T16:06: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 28 16:06:01 volumio go-librespot[14025]: time="2026-01-28T16:06: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 28 16:06:01 volumio go-librespot[14025]: time="2026-01-28T16:06: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 28 16:06:01 volumio go-librespot[14025]: time="2026-01-28T16:06:01+07:00" level=info msg="zeroconf server listening on port 34659" Jan 28 16:06:01 volumio go-librespot[14025]: time="2026-01-28T16:06:01+07:00" level=debug msg="obtained new client token: AADeawrJJhwkubHtdSc5NkpjHhvsvIjWLoofEDzOKRS/TtTFvDWZSBWjhriNmDurn5TGcb4JtKq/ExqIKJtVeKq7fP/Sac9Lcshtv7J5ep/SGAHvkit4gPxBDT0B67BptrBfhO1Xit5Pu9xAN/JOHZ5HOIKENdnDxFBIgupmZtSgsBwdw8fz0sQOXQr9yJCxSagLqoo404phW0VeY33/R2WqVXMRRsCMiPGgVsjx0ODJA+Ub1qzFyrlp87I=" Jan 28 16:06:01 volumio go-librespot[14025]: time="2026-01-28T16:06:01+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 16:06:01 volumio go-librespot[14025]: time="2026-01-28T16:06:01+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Jan 28 16:06:01 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 16:06:01 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 16:06:02 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 16:06:02 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 16:06:02 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 16:06:03 volumio volumio[14009]: info: ------------------------------------------- Jan 28 16:06:03 volumio volumio[14009]: info: ----- Volumio3 ---- Jan 28 16:06:03 volumio volumio[14009]: info: ------------------------------------------- Jan 28 16:06:03 volumio volumio[14009]: info: ----- System startup ---- Jan 28 16:06:03 volumio volumio[14009]: info: ------------------------------------------- Jan 28 16:06:04 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 16:06:04 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 16:06:04 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 16:06:04 volumio volumio-remote-updater[628]: [2026-01-28 16:06:04] [connect] Successful connection Jan 28 16:06:05 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 16. Jan 28 16:06:05 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 16:06:05 volumio volumio[14009]: info: MYVOLUMIO Environment detected Jan 28 16:06:05 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 16:06:05 volumio go-librespot[14039]: go-librespot daemon starting... Jan 28 16:06:05 volumio go-librespot[14043]: time="2026-01-28T16:06:05+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 16:06:05 volumio go-librespot[14043]: time="2026-01-28T16:06:05+07:00" level=debug msg="app state loaded" Jan 28 16:06:05 volumio go-librespot[14043]: time="2026-01-28T16:06:05+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 16:06:05 volumio volumio[14009]: info: Plugin folders cleanup Jan 28 16:06:05 volumio volumio[14009]: info: Scanning into folder /volumio/app/plugins/ Jan 28 16:06:05 volumio volumio[14009]: info: Scanning category audio_interface Jan 28 16:06:05 volumio volumio[14009]: info: Scanning category miscellanea Jan 28 16:06:05 volumio volumio[14009]: info: Scanning category music_service Jan 28 16:06:05 volumio volumio[14009]: info: Scanning category plugins.json Jan 28 16:06:05 volumio volumio[14009]: info: Scanning category system_controller Jan 28 16:06:05 volumio volumio[14009]: info: Scanning category user_interface Jan 28 16:06:05 volumio volumio[14009]: info: Scanning into folder /data/plugins/ Jan 28 16:06:05 volumio volumio[14009]: info: Scanning category music_service Jan 28 16:06:05 volumio volumio[14009]: info: Plugin folders cleanup completed Jan 28 16:06:05 volumio volumio[14009]: info: ------------------------------------------- Jan 28 16:06:05 volumio volumio[14009]: info: ----- Core plugins startup ---- Jan 28 16:06:05 volumio volumio[14009]: info: ------------------------------------------- Jan 28 16:06:05 volumio volumio[14009]: info: Loading plugins from folder /volumio/app/plugins/ Jan 28 16:06:05 volumio volumio[14009]: info: Adding plugin upnp to MyMusic Plugins Jan 28 16:06:05 volumio volumio[14009]: info: Adding plugin airplay_emulation to MyMusic Plugins Jan 28 16:06:05 volumio volumio[14009]: info: Adding plugin upnp_browser to MyMusic Plugins Jan 28 16:06:05 volumio volumio[14009]: info: Loading plugins from folder /data/plugins/ Jan 28 16:06:05 volumio volumio[14009]: info: Loading plugin "system"... Jan 28 16:06:05 volumio volumio[14009]: info: Loading plugin "appearance"... Jan 28 16:06:05 volumio go-librespot[14043]: time="2026-01-28T16:06:05+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 16:06:05 volumio go-librespot[14043]: time="2026-01-28T16:06:05+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 28 16:06:05 volumio go-librespot[14043]: time="2026-01-28T16:06:05+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 28 16:06:05 volumio go-librespot[14043]: time="2026-01-28T16:06:05+07:00" level=info msg="zeroconf server listening on port 35593" Jan 28 16:06:06 volumio go-librespot[14043]: time="2026-01-28T16:06:06+07:00" level=debug msg="obtained new client token: AADmxe8AZ29Jg3cU4NvfEMkKCIZ1mgWcSBMLpVF6A7raUy5DhG9kbCx0eCYJ/iLmbdJLQfsN8AkaybjhoytHjTb2I/v8WKUiZDedcSnRuEKihXXygZDCrItpjvaSBf1/UxLoMsm+/leJC2KTckN9pMz5zfo936SV8bGJIg4LAvCtSPzrr4/SeFtPQOr/8IgRBjmT9fhOG2a8q28e1EsLgiWXGJN/mE9UujJjKIbCIfRTmFb1yhyeT/lU" Jan 28 16:06:06 volumio go-librespot[14043]: time="2026-01-28T16:06:06+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 16:06:06 volumio go-librespot[14043]: time="2026-01-28T16:06:06+07:00" level=debug msg="completed keyexchange" Jan 28 16:06:06 volumio go-librespot[14043]: time="2026-01-28T16:06:06+07:00" level=debug msg="completed challenge" Jan 28 16:06:06 volumio go-librespot[14043]: time="2026-01-28T16:06:06+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 16:06:06 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 16:06:06 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 16:06:06 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 16:06:06 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 16:06:06 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 16:06:07 volumio volumio[14009]: info: Loading plugin "network"... Jan 28 16:06:07 volumio volumio[14009]: info: Refreshing Cached IP Addresses Jan 28 16:06:07 volumio sudo[14057]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 28 16:06:07 volumio sudo[14057]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 16:06:07 volumio sudo[14057]: pam_unix(sudo:session): session closed for user root Jan 28 16:06:07 volumio volumio[14009]: info: Loading plugin "services"... Jan 28 16:06:07 volumio sudo[14059]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 28 16:06:07 volumio sudo[14059]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 16:06:07 volumio volumio[14009]: info: Loading plugin "alsa_controller"... Jan 28 16:06:07 volumio sudo[14059]: pam_unix(sudo:session): session closed for user root Jan 28 16:06:07 volumio sudo[14067]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Jan 28 16:06:07 volumio sudo[14067]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 16:06:07 volumio volumio[14009]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 28 16:06:07 volumio volumio[14009]: info: Loading plugin "wizard"... Jan 28 16:06:07 volumio volumio[14009]: info: Loading plugin "networkfs"... Jan 28 16:06:07 volumio volumio[14009]: info: Starting Udev Watcher for removable devices Jan 28 16:06:07 volumio volumio[14009]: info: Ignoring mount for partition: boot Jan 28 16:06:07 volumio volumio[14009]: info: Ignoring mount for partition: volumio Jan 28 16:06:07 volumio volumio[14009]: info: Ignoring mount for partition: volumio_data Jan 28 16:06:07 volumio volumio[14009]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 28 16:06:07 volumio volumio[14009]: info: Loading plugin "volumio_command_line_client"... Jan 28 16:06:07 volumio volumio[14009]: info: Loading plugin "upnp"... Jan 28 16:06:07 volumio volumio[14009]: info: [1769591167916] Starting Upmpd Daemon Jan 28 16:06:07 volumio volumio[14009]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 28 16:06:07 volumio volumio[14009]: info: Loading plugin "my_music"... Jan 28 16:06:07 volumio volumio[14009]: info: Loading plugin "mpd"... Jan 28 16:06:08 volumio volumio[14009]: info: Loading plugin "upnp_browser"... Jan 28 16:06:08 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 16:06:08 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 16:06:08 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 16:06:09 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 17. Jan 28 16:06:09 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 16:06:09 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 16:06:09 volumio go-librespot[14090]: go-librespot daemon starting... Jan 28 16:06:09 volumio go-librespot[14091]: time="2026-01-28T16:06:09+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 16:06:09 volumio go-librespot[14091]: time="2026-01-28T16:06:09+07:00" level=debug msg="app state loaded" Jan 28 16:06:09 volumio go-librespot[14091]: time="2026-01-28T16:06:09+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 16:06:10 volumio go-librespot[14091]: time="2026-01-28T16:06:10+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 28 16:06:10 volumio go-librespot[14091]: time="2026-01-28T16:06:10+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Jan 28 16:06:10 volumio go-librespot[14091]: time="2026-01-28T16:06:10+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Jan 28 16:06:10 volumio go-librespot[14091]: time="2026-01-28T16:06:10+07:00" level=info msg="zeroconf server listening on port 44491" Jan 28 16:06:10 volumio go-librespot[14091]: time="2026-01-28T16:06:10+07:00" level=debug msg="obtained new client token: AAC8ngTKtlLCo1hBbW3saLYGKfv+3EuqREw9mNGnwcH3BIGnbn0HQSfA3i2Jh4qHMP5zvDYioJUyxBG2MdL10xiE7U9ZaZO0w22WN7fPo2RK0rq7OEiYtEl6wygkdA2w6W/tbvhQN9hzhdP/X6M60e+UM4/UUm4DliCMoZe0KHi7ZPWIhUUW1QB+ljpFzDwzK5qE8vVQByykG040J0Q1xjIssxKPOHJO7i0ab+qAfj5h/9qBidWfbHvPrTM=" Jan 28 16:06:10 volumio go-librespot[14091]: time="2026-01-28T16:06:10+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 16:06:10 volumio sudo[14067]: pam_unix(sudo:session): session closed for user root Jan 28 16:06:10 volumio go-librespot[14091]: time="2026-01-28T16:06:10+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Jan 28 16:06:10 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 16:06:10 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 16:06:10 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 16:06:10 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 16:06:10 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 16:06:11 volumio volumio[14009]: info: Starting UPNP Browser Jan 28 16:06:11 volumio volumio[14009]: info: Loading plugin "alarm-clock"... Jan 28 16:06:11 volumio volumio[14009]: info: Loading plugin "airplay_emulation"... Jan 28 16:06:11 volumio volumio[14009]: info: Starting Shairport Sync Jan 28 16:06:11 volumio volumio[14009]: info: Loading plugin "last_100"... Jan 28 16:06:11 volumio volumio[14009]: info: Loading plugin "webradio"... Jan 28 16:06:12 volumio volumio[14009]: info: Loading plugin "i2s_dacs"... Jan 28 16:06:12 volumio volumio[14009]: info: Loading plugin "volumiodiscovery"... Jan 28 16:06:12 volumio volumio[14009]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 28 16:06:12 volumio volumio[14009]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 16:06:12 volumio volumio[14009]: *** WARNING *** For more information see Jan 28 16:06:12 volumio volumio[14009]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 28 16:06:12 volumio volumio[14009]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 16:06:12 volumio volumio[14009]: *** WARNING *** For more information see Jan 28 16:06:12 volumio node[14009]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 28 16:06:12 volumio node[14009]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 16:06:12 volumio node[14009]: *** WARNING *** For more information see Jan 28 16:06:12 volumio node[14009]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 28 16:06:12 volumio node[14009]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 16:06:12 volumio node[14009]: *** WARNING *** For more information see Jan 28 16:06:12 volumio volumio[14009]: info: Applying required configuration parameters for plugin volumiodiscovery Jan 28 16:06:12 volumio volumio[14009]: info: Discovery: Started advertising with name: Volumio Jan 28 16:06:12 volumio volumio[14009]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 28 16:06:12 volumio volumio[14009]: info: Loading plugin "spop"... Jan 28 16:06:12 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 16:06:12 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 16:06:12 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 16:06:13 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 18. Jan 28 16:06:13 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 16:06:13 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 16:06:13 volumio go-librespot[14100]: go-librespot daemon starting... Jan 28 16:06:13 volumio go-librespot[14101]: time="2026-01-28T16:06:13+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 16:06:13 volumio go-librespot[14101]: time="2026-01-28T16:06:13+07:00" level=debug msg="app state loaded" Jan 28 16:06:13 volumio go-librespot[14101]: time="2026-01-28T16:06:13+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 16:06:14 volumio volumio[14009]: info: Loading plugin "ytcr"... Jan 28 16:06:14 volumio go-librespot[14101]: time="2026-01-28T16:06:14+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 16:06:14 volumio go-librespot[14101]: time="2026-01-28T16:06:14+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 28 16:06:14 volumio go-librespot[14101]: time="2026-01-28T16:06:14+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 28 16:06:14 volumio go-librespot[14101]: time="2026-01-28T16:06:14+07:00" level=info msg="zeroconf server listening on port 46529" Jan 28 16:06:14 volumio go-librespot[14101]: time="2026-01-28T16:06:14+07:00" level=debug msg="obtained new client token: AABOnEAwEEThAqGXQUV+vkIiuPYpDvweHdBaJnY3HW2MGdfAyg66ILygi17Ooipj+Jz8h4Jux0FymPhYsmPYycjILOdaP3/1KHWGsdrtiWGJhFjeF5NIgBWtv3pog5BGeRML5nrnTzTQeu7USewthy8UkQzYHp3U4je6v1ASsC/Aa/oGnIFLTLnbfRcTlDaLgrrqvBEdLRWePbEYTXcHP8oR+VG1FQMxhr72QYUlNtL9lFA9e9xlg1oZM0M=" Jan 28 16:06:14 volumio go-librespot[14101]: time="2026-01-28T16:06:14+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 16:06:14 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 16:06:14 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 16:06:14 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 16:06:14 volumio go-librespot[14101]: time="2026-01-28T16:06:14+07:00" level=debug msg="completed keyexchange" Jan 28 16:06:14 volumio go-librespot[14101]: time="2026-01-28T16:06:14+07:00" level=debug msg="completed challenge" Jan 28 16:06:14 volumio go-librespot[14101]: time="2026-01-28T16:06:14+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 16:06:14 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 16:06:14 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 16:06:16 volumio volumio[14009]: info: Loading plugin "ytmusic"... Jan 28 16:06:16 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 16:06:16 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 16:06:16 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 16:06:17 volumio volumio-remote-updater[628]: [2026-01-28 16:06:17] [connect] Successful connection Jan 28 16:06:17 volumio volumio[14009]: info: Loading plugin "outputs"... Jan 28 16:06:17 volumio volumio[14009]: info: Loading plugin "albumart"... Jan 28 16:06:17 volumio volumio[14009]: info: Plugin example_plugin is not enabled Jan 28 16:06:17 volumio volumio[14009]: info: Loading plugin "inputs"... Jan 28 16:06:17 volumio volumio[14009]: info: Loading plugin "updater_comm"... Jan 28 16:06:17 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 19. Jan 28 16:06:17 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 16:06:18 volumio volumio[14009]: info: Plugin mpdemulation is not enabled Jan 28 16:06:18 volumio volumio[14009]: info: Loading plugin "rest_api"... Jan 28 16:06:18 volumio volumio[14009]: info: Loading plugin "websocket"... Jan 28 16:06:18 volumio volumio[14009]: info: Starting Socket.io Server version 1.7.4 Jan 28 16:06:18 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 16:06:18 volumio volumio[14009]: info: Loading plugin "RoonBridge"... Jan 28 16:06:18 volumio go-librespot[14132]: go-librespot daemon starting... Jan 28 16:06:18 volumio go-librespot[14134]: time="2026-01-28T16:06:18+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 16:06:18 volumio go-librespot[14134]: time="2026-01-28T16:06:18+07:00" level=debug msg="app state loaded" Jan 28 16:06:18 volumio go-librespot[14134]: time="2026-01-28T16:06:18+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 16:06:18 volumio volumio[14009]: info: Applying required configuration parameters for plugin RoonBridge Jan 28 16:06:18 volumio volumio[14009]: info: Loading i18n strings for locale en Jan 28 16:06:18 volumio volumio[14009]: Updating browse sources language Jan 28 16:06:18 volumio volumio[14009]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 16:06:18 volumio go-librespot[14134]: time="2026-01-28T16:06:18+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 28 16:06:18 volumio go-librespot[14134]: time="2026-01-28T16:06:18+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Jan 28 16:06:18 volumio go-librespot[14134]: time="2026-01-28T16:06:18+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Jan 28 16:06:18 volumio go-librespot[14134]: time="2026-01-28T16:06:18+07:00" level=info msg="zeroconf server listening on port 46083" Jan 28 16:06:18 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 16:06:18 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 16:06:18 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 16:06:19 volumio volumio[14009]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 28 16:06:19 volumio volumio[14009]: info: CoreCommandRouter::initPlayerControls Jan 28 16:06:19 volumio volumio[14009]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 16:06:19 volumio volumio[14009]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 16:06:19 volumio volumio[14009]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 16:06:19 volumio volumio[14009]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 16:06:19 volumio volumio[14009]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 16:06:19 volumio volumio[14009]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 16:06:19 volumio volumio[14009]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 16:06:19 volumio volumio[14009]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 16:06:19 volumio go-librespot[14134]: time="2026-01-28T16:06:19+07:00" level=debug msg="obtained new client token: AAAhWMVQakntS0KuOBJug9QRKpBw9ODLkDhJj8t/bhHF7PHtGj/mQEKK53peiKNInKHID1nzPhBfILnZ2x1Ahg5l7qfmFHjttPZxe10XjaHX71faUlC0kyy6dWcX51cyGmUl8V9dGKJZJn3LVuDaIG8HLj4MPLL3Iib+nK9+4xUh6xRNSZ9zI2yR6PPj0RYxnYhoYgJvrIEtJb1eKhhGuakkfwtfJyH2CU/rgGbH1dkSzioFJyI4aKJq2Rs=" Jan 28 16:06:19 volumio volumio[14009]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 28 16:06:19 volumio volumio[14123]: Forking 3 albumart workers Jan 28 16:06:19 volumio volumio[14009]: Express server listening on port 3000 Jan 28 16:06:19 volumio volumio[14009]: [Metrics] WebUI: 16s 18.24ms Jan 28 16:06:19 volumio volumio[14009]: info: CoreStateMachine::resetVolumioState Jan 28 16:06:19 volumio volumio[14009]: info: CoreStateMachine::getcurrentVolume Jan 28 16:06:19 volumio volumio[14009]: info: CoreCommandRouter::volumioRetrievevolume Jan 28 16:06:19 volumio go-librespot[14134]: time="2026-01-28T16:06:19+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 16:06:19 volumio go-librespot[14134]: time="2026-01-28T16:06:19+07:00" level=debug msg="completed keyexchange" Jan 28 16:06:19 volumio go-librespot[14134]: time="2026-01-28T16:06:19+07:00" level=debug msg="completed challenge" Jan 28 16:06:19 volumio sudo[14173]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 28 16:06:19 volumio sudo[14173]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 16:06:19 volumio sudo[14173]: pam_unix(sudo:session): session closed for user root Jan 28 16:06:19 volumio sudo[14175]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 28 16:06:19 volumio go-librespot[14134]: time="2026-01-28T16:06:19+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 16:06:19 volumio sudo[14175]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 16:06:19 volumio volumio[14009]: info: Volumio Network Manager: Network status updated: 1 Jan 28 16:06:19 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 16:06:19 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 16:06:19 volumio sudo[14175]: pam_unix(sudo:session): session closed for user root Jan 28 16:06:19 volumio volumio[14009]: info: VolumeController:: Volume=100 Mute =false Jan 28 16:06:19 volumio volumio[14009]: info: CoreStateMachine::pushState Jan 28 16:06:19 volumio volumio[14009]: info: CorePlayQueue::getTrack 0 Jan 28 16:06:19 volumio volumio[14009]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 28 16:06:19 volumio volumio[14009]: info: CoreCommandRouter::volumioPushState Jan 28 16:06:19 volumio volumio[14009]: info: CoreStateMachine::updateTrackBlock Jan 28 16:06:19 volumio volumio[14009]: info: CorePlayQueue::getTrackBlock Jan 28 16:06:19 volumio volumio[14009]: info: CoreCommandRouter::volumioRetrievevolume Jan 28 16:06:19 volumio volumio-remote-updater[628]: [2026-01-28 16:06:19] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1769591177 101 Jan 28 16:06:19 volumio volumio[14009]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 1 Jan 28 16:06:19 volumio volumio[14009]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 16:06:19 volumio volumio[14009]: info: Reloading queue from file Jan 28 16:06:19 volumio volumio[14009]: info: CoreStateMachine::setRepeat null single undefined Jan 28 16:06:19 volumio volumio[14009]: info: CoreStateMachine::pushState Jan 28 16:06:19 volumio volumio[14009]: info: CorePlayQueue::getTrack 0 Jan 28 16:06:19 volumio volumio[14009]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 28 16:06:19 volumio volumio[14009]: info: CoreCommandRouter::volumioPushState Jan 28 16:06:19 volumio volumio[14009]: info: CoreStateMachine::setRandom null Jan 28 16:06:19 volumio volumio[14009]: info: CoreStateMachine::pushState Jan 28 16:06:19 volumio volumio[14009]: info: CorePlayQueue::getTrack 0 Jan 28 16:06:19 volumio volumio[14009]: info: CoreCommandRouter::volumioPushState Jan 28 16:06:19 volumio volumio[14009]: info: Setting Device type: Raspberry PI Jan 28 16:06:19 volumio volumio[14009]: info: Completed loading Core Plugins Jan 28 16:06:19 volumio volumio[14009]: info: Preparing to generate the ALSA configuration file Jan 28 16:06:20 volumio volumio[14009]: info: VolumeController:: Volume=100 Mute =false Jan 28 16:06:20 volumio volumio[14009]: info: CoreStateMachine::pushState Jan 28 16:06:20 volumio volumio[14009]: info: CorePlayQueue::getTrack 0 Jan 28 16:06:20 volumio volumio[14009]: info: CoreCommandRouter::volumioPushState Jan 28 16:06:20 volumio volumio[14009]: info: Asound.conf file unchanged, so no further update is needed Jan 28 16:06:20 volumio volumio[14009]: info: Output device has changed, restarting MPD Jan 28 16:06:20 volumio volumio[14009]: info: Output device has changed, restarting Shairport Sync Jan 28 16:06:20 volumio volumio[14009]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 16:06:20 volumio volumio[14009]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 16:06:20 volumio sudo[14192]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Jan 28 16:06:20 volumio sudo[14192]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 16:06:20 volumio sudo[14194]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 28 16:06:20 volumio volumio[14009]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 28 16:06:20 volumio sudo[14194]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 16:06:20 volumio volumio[14009]: info: ___________ START PLUGINS ___________ Jan 28 16:06:20 volumio sudo[14196]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 28 16:06:20 volumio sudo[14196]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 16:06:20 volumio sudo[14194]: pam_unix(sudo:session): session closed for user root Jan 28 16:06:20 volumio volumio[14009]: info: ControllerMpd::onStart: Initializing MPD Jan 28 16:06:20 volumio volumio[14009]: info: Creating MPD Configuration file Jan 28 16:06:20 volumio sudo[14192]: pam_unix(sudo:session): session closed for user root Jan 28 16:06:20 volumio volumio[14009]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 28 16:06:20 volumio volumio[14009]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 16:06:20 volumio volumio[14009]: info: [1769591180402] CoreMusicLibrary::Adding element Media Servers Jan 28 16:06:20 volumio volumio[14009]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 16:06:20 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Jan 28 16:06:20 volumio volumio[14009]: info: UPNP Browser: Client initialized successfully Jan 28 16:06:20 volumio sudo[14205]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 28 16:06:20 volumio sudo[14205]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 16:06:20 volumio sudo[14207]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 28 16:06:20 volumio sudo[14207]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 16:06:20 volumio sudo[14205]: pam_unix(sudo:session): session closed for user root Jan 28 16:06:20 volumio volumio[14009]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 16:06:20 volumio volumio[14009]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 16:06:20 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 28 16:06:20 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 28 16:06:20 volumio systemd[1]: mpd.service: Consumed 7.555s CPU time. Jan 28 16:06:20 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 28 16:06:20 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 28 16:06:20 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 28 16:06:20 volumio volumio[14009]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 28 16:06:20 volumio volumio[14009]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 16:06:20 volumio volumio[14009]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 16:06:20 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 28 16:06:20 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 28 16:06:20 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 28 16:06:20 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 28 16:06:20 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 28 16:06:20 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 28 16:06:20 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 28 16:06:20 volumio volumio[14009]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 28 16:06:20 volumio volumio[14009]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 16:06:20 volumio volumio[14009]: info: [1769591180760] CoreMusicLibrary::Adding element Last_100 Jan 28 16:06:20 volumio volumio[14009]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 16:06:20 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 28 16:06:20 volumio volumio[14009]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 16:06:20 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 28 16:06:20 volumio volumio[14009]: info: [1769591180781] CoreMusicLibrary::Adding element Webradio Jan 28 16:06:20 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 16:06:20 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 16:06:20 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 16:06:20 volumio volumio[14009]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 16:06:20 volumio volumio[14009]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 28 16:06:20 volumio volumio[14009]: info: Initializing BBC Radios Jan 28 16:06:20 volumio volumio[14009]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 28 16:06:20 volumio volumio[14009]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 16:06:21 volumio volumio[14009]: info: Creating Spotify config file Jan 28 16:06:21 volumio volumio[14009]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 16:06:21 volumio sudo[14221]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 28 16:06:21 volumio sudo[14221]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jan 28 16:06:21 volumio sudo[14221]: pam_unix(sudo:session): session closed for user root Jan 28 16:06:22 volumio volumio[14009]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 16:06:22 volumio volumio[14009]: info: [1769591182166] CoreMusicLibrary::Adding element YouTube Music Jan 28 16:06:22 volumio volumio[14009]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 16:06:22 volumio volumio[14009]: Cannot find translation for source YouTube Music Jan 28 16:06:22 volumio volumio[14009]: info: Volumio Calling Home Jan 28 16:06:22 volumio volumio[14142]: Starting albumart workers Jan 28 16:06:22 volumio sudo[14238]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Jan 28 16:06:22 volumio sudo[14238]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 16:06:22 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 20. Jan 28 16:06:22 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 16:06:22 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 16:06:22 volumio go-librespot[14243]: go-librespot daemon starting... Jan 28 16:06:22 volumio sudo[14238]: pam_unix(sudo:session): session closed for user root Jan 28 16:06:22 volumio go-librespot[14244]: time="2026-01-28T16:06:22+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 16:06:22 volumio volumio[14146]: Starting albumart workers Jan 28 16:06:22 volumio volumio[14145]: Starting albumart workers Jan 28 16:06:22 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 16:06:22 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 16:06:22 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 16:06:23 volumio volumio[14009]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Jan 28 16:06:23 volumio volumio[14009]: info: Discovery: Found device Volumio Jan 28 16:06:23 volumio volumio[14009]: info: CoreCommandRouter::volumioGetState Jan 28 16:06:23 volumio volumio[14009]: info: CorePlayQueue::getTrack 0 Jan 28 16:06:23 volumio volumio[14009]: info: MPD Permissions set Jan 28 16:06:23 volumio volumio[14009]: info: MPD Permissions set Jan 28 16:06:23 volumio volumio[14009]: info: Upmpdcli Daemon Started Jan 28 16:06:23 volumio volumio[14009]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Jan 28 16:06:23 volumio volumio[14009]: info: Discovery: Found device Volumio Jan 28 16:06:23 volumio volumio[14009]: info: CoreCommandRouter::volumioGetState Jan 28 16:06:23 volumio volumio[14009]: info: CorePlayQueue::getTrack 0 Jan 28 16:06:23 volumio volumio[14009]: info: Spotify config file written Jan 28 16:06:23 volumio go-librespot[14244]: time="2026-01-28T16:06:23+07:00" level=info msg="zeroconf server listening on port 43983" Jan 28 16:06:23 volumio sudo[14254]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jan 28 16:06:23 volumio sudo[14254]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 16:06:23 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Jan 28 16:06:23 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Jan 28 16:06:23 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 16:06:23 volumio volumio[14009]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Jan 28 16:06:23 volumio volumio[14009]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 16:06:23 volumio volumio[14009]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 16:06:23 volumio volumio[14009]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 16:06:23 volumio volumio[14009]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 16:06:23 volumio volumio[14009]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 16:06:23 volumio volumio[14009]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 16:06:23 volumio volumio[14009]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 16:06:23 volumio volumio[14009]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 16:06:23 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 16:06:23 volumio go-librespot[14256]: go-librespot daemon starting... Jan 28 16:06:23 volumio sudo[14254]: pam_unix(sudo:session): session closed for user root Jan 28 16:06:23 volumio volumio[14009]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 16:06:23 volumio volumio[14009]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 16:06:23 volumio go-librespot[14262]: time="2026-01-28T16:06:23+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 16:06:23 volumio go-librespot[14262]: time="2026-01-28T16:06:23+07:00" level=debug msg="app state loaded" Jan 28 16:06:23 volumio go-librespot[14262]: time="2026-01-28T16:06:23+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 16:06:23 volumio volumio[14009]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 16:06:23 volumio volumio[14009]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 16:06:23 volumio volumio[14009]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 16:06:23 volumio volumio[14009]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 16:06:23 volumio volumio[14009]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 16:06:23 volumio volumio[14009]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 16:06:23 volumio volumio[14009]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 16:06:23 volumio volumio[14009]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 16:06:23 volumio volumio[14009]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 16:06:23 volumio volumio[14009]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 16:06:23 volumio volumio[14009]: info: No need to fix Spotify hosts Jan 28 16:06:24 volumio go-librespot[14262]: time="2026-01-28T16:06:24+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 16:06:24 volumio go-librespot[14262]: time="2026-01-28T16:06:24+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 28 16:06:24 volumio go-librespot[14262]: time="2026-01-28T16:06:24+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 28 16:06:24 volumio go-librespot[14262]: time="2026-01-28T16:06:24+07:00" level=info msg="zeroconf server listening on port 38785" Jan 28 16:06:24 volumio go-librespot[14262]: time="2026-01-28T16:06:24+07:00" level=debug msg="obtained new client token: AAAxUoAOlYnrvK46yC4nGA7I7DSCAwdNNGb66fZfx5yvRBl9q77w5jvNjbu+qbBgqJVrD6QaPEH6qsMClPzrwLlnCFwc19GiJDA3mrhRM9N5FveNkZqdSXEhQNoQC3BRxDvyNDpia7Asu0oWePS3P51mTMKZi8Hw3xX0RKSSypkKBqfemDdYsHauQHGs5qCbD/nhx5SFjG+2Ca/IG6es91T2uvdqRvuFFXUmiye1+wJBIJHWAnwHDCTYPTw=" Jan 28 16:06:24 volumio go-librespot[14262]: time="2026-01-28T16:06:24+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 16:06:24 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 16:06:24 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 16:06:24 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 16:06:24 volumio go-librespot[14262]: time="2026-01-28T16:06:24+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Jan 28 16:06:24 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 16:06:24 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 16:06:24 volumio volumio[14009]: info: Volumio called home Jan 28 16:06:25 volumio volumio[14009]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 28 16:06:25 volumio volumio[14009]: SPOTIFY: BQBtIuyn8pzcgskn0oIHI2kj3RLVgy9d2836HqgNBCvmvylNTSYqKkTPBdLlxlzusH8z8X4Asi6jf-_Aqxl_Ag-xK6mH3sk6p4QrQSiwufdBXRE4RweWT3kQBOAGh8jOpQFMwKtd68GlsrapwM03ykAoH67663R24rJLOHRGVKg5I-ecGWhujJpwYMlbh4ngTg_jp6n8PZ0ZFfeP45Q7bPsk_7HtdxaOk0CZe2Lzhxake76itvK6zHEHKgcM_sXT_xO8tnu1oZKQz6GRjj04ZBiSCTlJFt5zufj5nhUf2iDARcphE5ZJzuBN Jan 28 16:06:25 volumio volumio[14009]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 28 16:06:25 volumio volumio[14009]: info: New Spotify access token = BQBtIuyn8pzcgskn0oIHI2kj3RLVgy9d2836HqgNBCvmvylNTSYqKkTPBdLlxlzusH8z8X4Asi6jf-_Aqxl_Ag-xK6mH3sk6p4QrQSiwufdBXRE4RweWT3kQBOAGh8jOpQFMwKtd68GlsrapwM03ykAoH67663R24rJLOHRGVKg5I-ecGWhujJpwYMlbh4ngTg_jp6n8PZ0ZFfeP45Q7bPsk_7HtdxaOk0CZe2Lzhxake76itvK6zHEHKgcM_sXT_xO8tnu1oZKQz6GRjj04ZBiSCTlJFt5zufj5nhUf2iDARcphE5ZJzuBN Jan 28 16:06:25 volumio volumio[14009]: info: Spotify credentials grant success - running version from March 24, 2019 Jan 28 16:06:25 volumio volumio[14009]: info: Starting Shairport Sync Jan 28 16:06:25 volumio volumio[14009]: info: Starting Shairport Sync Jan 28 16:06:25 volumio volumio[14009]: info: Starting Shairport Sync Jan 28 16:06:25 volumio sudo[14296]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 28 16:06:25 volumio sudo[14296]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 16:06:25 volumio sudo[14298]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 28 16:06:25 volumio sudo[14301]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 28 16:06:25 volumio sudo[14298]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 16:06:25 volumio sudo[14301]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 16:06:25 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 28 16:06:25 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Jan 28 16:06:25 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 28 16:06:25 volumio systemd[1]: shairport-sync.service: Consumed 2.370s CPU time. Jan 28 16:06:25 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 28 16:06:25 volumio sudo[14298]: pam_unix(sudo:session): session closed for user root Jan 28 16:06:25 volumio sudo[14296]: pam_unix(sudo:session): session closed for user root Jan 28 16:06:25 volumio sudo[14301]: pam_unix(sudo:session): session closed for user root Jan 28 16:06:25 volumio volumio[14009]: info: Shairport-Sync Started Jan 28 16:06:25 volumio volumio[14009]: Error adding Membership: Error: addMembership EINVAL Jan 28 16:06:25 volumio volumio[14009]: info: Shairport-Sync Started Jan 28 16:06:25 volumio volumio[14009]: info: Shairport-Sync Started Jan 28 16:06:25 volumio volumio[14009]: info: CoreCommandRouter::volumioGetState Jan 28 16:06:25 volumio volumio[14009]: info: CorePlayQueue::getTrack 0 Jan 28 16:06:26 volumio volumio[14009]: SPOTIFY: User informations: {"country":"PK","display_name":"215mmgea6kss3jxeqsqdquvji","email":"linh.ngotran@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/215mmgea6kss3jxeqsqdquvji"},"followers":{"href":null,"total":1},"href":"https://api.spotify.com/v1/users/215mmgea6kss3jxeqsqdquvji","id":"215mmgea6kss3jxeqsqdquvji","images":[],"product":"premium","type":"user","uri":"spotify:user:215mmgea6kss3jxeqsqdquvji"} Jan 28 16:06:26 volumio volumio[14009]: info: Spotify Successfully logged in Jan 28 16:06:26 volumio volumio[14009]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 16:06:26 volumio volumio[14009]: info: [1769591186159] CoreMusicLibrary::Adding element Spotify Jan 28 16:06:26 volumio volumio[14009]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 16:06:26 volumio volumio[14009]: Cannot find translation for source YouTube Music Jan 28 16:06:26 volumio volumio[14009]: Cannot find translation for source Spotify Jan 28 16:06:26 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 16:06:26 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 16:06:26 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 16:06:26 volumio volumio[14009]: info: [yt-cast-receiver] DIAL server listening on port 8098 Jan 28 16:06:26 volumio volumio[14009]: info: CoreCommandRouter::volumioRetrievevolume Jan 28 16:06:27 volumio volumio[14009]: info: VolumeController:: Volume=100 Mute =false Jan 28 16:06:27 volumio volumio[14009]: info: CoreCommandRouter::volumioGetState Jan 28 16:06:27 volumio volumio[14009]: info: CorePlayQueue::getTrack 0 Jan 28 16:06:27 volumio volumio[14009]: info: CoreStateMachine::pushState Jan 28 16:06:27 volumio volumio[14009]: info: CorePlayQueue::getTrack 0 Jan 28 16:06:27 volumio volumio[14009]: info: CoreCommandRouter::volumioPushState Jan 28 16:06:27 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Jan 28 16:06:27 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 16:06:28 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 16:06:28 volumio go-librespot[14336]: go-librespot daemon starting... Jan 28 16:06:28 volumio go-librespot[14337]: time="2026-01-28T16:06:28+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 16:06:28 volumio go-librespot[14337]: time="2026-01-28T16:06:28+07:00" level=debug msg="app state loaded" Jan 28 16:06:28 volumio go-librespot[14337]: time="2026-01-28T16:06:28+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 16:06:28 volumio volumio[14009]: info: go-librespot daemon successfully initialized Jan 28 16:06:28 volumio mpd[14236]: 2026-01-28T16:06:28 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 28 16:06:28 volumio systemd[1]: Started mpd.service - Music Player Daemon. Jan 28 16:06:28 volumio sudo[14196]: pam_unix(sudo:session): session closed for user root Jan 28 16:06:28 volumio sudo[14207]: pam_unix(sudo:session): session closed for user root Jan 28 16:06:28 volumio go-librespot[14337]: time="2026-01-28T16:06:28+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 16:06:28 volumio go-librespot[14337]: time="2026-01-28T16:06:28+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 28 16:06:28 volumio go-librespot[14337]: time="2026-01-28T16:06:28+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 28 16:06:28 volumio go-librespot[14337]: time="2026-01-28T16:06:28+07:00" level=info msg="zeroconf server listening on port 38745" Jan 28 16:06:28 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 16:06:28 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 16:06:28 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 16:06:28 volumio volumio[14009]: error: MPD error: The expression evaluated to a falsy value: Jan 28 16:06:28 volumio volumio[14009]: assert.ok(self.idling) Jan 28 16:06:28 volumio volumio[14009]: error: The expression evaluated to a falsy value: Jan 28 16:06:28 volumio volumio[14009]: assert.ok(self.idling) Jan 28 16:06:29 volumio go-librespot[14337]: time="2026-01-28T16:06:29+07:00" level=debug msg="obtained new client token: AADOAZET/zcsxBcbc99yStE9l9YEmkhJbJDBFVwCkzVi4Lj8R75Y+SdwCYeqftWrCh9muxEJvc3kL2bEFfUu8QhSk9wmSJsD1meTiO+HpxRywV0bhxXpB8npl15TC5gw7P3aYryajG8UvkX6d2cm/kMRRLS4ThzhJgZqtrFpk6X/z43catfTziXd9QuEbL50AaW1zfhKIu00EemMHQ0Sc2R7VbaIb29ybP5HlK3IbMFpqqVY4jkSZ/2Dha0=" Jan 28 16:06:29 volumio volumio[14009]: info: MPD running with PID14236 Jan 28 16:06:29 volumio volumio[14009]: ,establishing connection Jan 28 16:06:29 volumio volumio[14009]: error: updateQueue error: null Jan 28 16:06:29 volumio volumio[14009]: info: Completed starting Core Plugins Jan 28 16:06:29 volumio volumio[14009]: info: ------------------------------------------- Jan 28 16:06:29 volumio volumio[14009]: info: ----- MyVolumio plugins startup ---- Jan 28 16:06:29 volumio volumio[14009]: info: ------------------------------------------- Jan 28 16:06:29 volumio volumio[14009]: info: [MyVolumio PluginManager] Fetching plans data.... Jan 28 16:06:29 volumio go-librespot[14337]: time="2026-01-28T16:06:29+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 16:06:29 volumio volumio[14009]: error: updateQueue error: null Jan 28 16:06:29 volumio go-librespot[14337]: time="2026-01-28T16:06:29+07:00" level=debug msg="completed keyexchange" Jan 28 16:06:29 volumio go-librespot[14337]: time="2026-01-28T16:06:29+07:00" level=debug msg="completed challenge" Jan 28 16:06:29 volumio go-librespot[14337]: time="2026-01-28T16:06:29+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 16:06:29 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 16:06:29 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 16:06:30 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 16:06:30 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 16:06:30 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 16:06:31 volumio volumio[14009]: info: Initializing connection to go-librespot Websocket Jan 28 16:06:31 volumio volumio[14009]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 28 16:06:32 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Jan 28 16:06:32 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 16:06:32 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 16:06:32 volumio go-librespot[14349]: go-librespot daemon starting... Jan 28 16:06:32 volumio go-librespot[14350]: time="2026-01-28T16:06:32+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 16:06:32 volumio go-librespot[14350]: time="2026-01-28T16:06:32+07:00" level=debug msg="app state loaded" Jan 28 16:06:32 volumio go-librespot[14350]: time="2026-01-28T16:06:32+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 16:06:32 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 16:06:32 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 16:06:32 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 16:06:33 volumio go-librespot[14350]: time="2026-01-28T16:06:33+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 28 16:06:33 volumio go-librespot[14350]: time="2026-01-28T16:06:33+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Jan 28 16:06:33 volumio go-librespot[14350]: time="2026-01-28T16:06:33+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Jan 28 16:06:33 volumio go-librespot[14350]: time="2026-01-28T16:06:33+07:00" level=info msg="zeroconf server listening on port 38757" Jan 28 16:06:33 volumio go-librespot[14350]: time="2026-01-28T16:06:33+07:00" level=debug msg="obtained new client token: AAAezpPLHM7Bu9VAlt0kKwvgGvY8NOeVK6NfSYN4lF0CYreMG+qIhUFsIL/xCtTK1kxF0UeFKt26g/a9EVAU62jXnUL7KMnXwhx+EtD87uaAL0mYVL0b+fIvHigcf9gWY77vfH0Qw29F8C5Az9ip4pXhezuLR+4Ou0iO2q99hZKufOEGRpSeUhWRCBHsdZprWSCS6YteAsA0K/L3ACc13CM8FaTbSGBTy8AcjIuPbKqe9Bq8ktBcbWwMPK8=" Jan 28 16:06:33 volumio go-librespot[14350]: time="2026-01-28T16:06:33+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 16:06:33 volumio go-librespot[14350]: time="2026-01-28T16:06:33+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Jan 28 16:06:33 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 16:06:33 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 16:06:33 volumio volumio[14009]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Jan 28 16:06:34 volumio volumio[14009]: info: Initializing connection to go-librespot Websocket Jan 28 16:06:34 volumio volumio[14009]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 28 16:06:34 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 16:06:34 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 16:06:34 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 16:06:36 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Jan 28 16:06:36 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 16:06:36 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 16:06:36 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 16:06:36 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 16:06:36 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 16:06:36 volumio go-librespot[14358]: go-librespot daemon starting... Jan 28 16:06:36 volumio go-librespot[14359]: time="2026-01-28T16:06:36+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 16:06:36 volumio go-librespot[14359]: time="2026-01-28T16:06:36+07:00" level=debug msg="app state loaded" Jan 28 16:06:36 volumio go-librespot[14359]: time="2026-01-28T16:06:36+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 16:06:37 volumio volumio[14009]: info: Initializing connection to go-librespot Websocket Jan 28 16:06:37 volumio go-librespot[14359]: time="2026-01-28T16:06:37+07:00" level=debug msg="new websocket client" Jan 28 16:06:37 volumio volumio[14009]: info: Connection to go-librespot Websocket established Jan 28 16:06:37 volumio go-librespot[14359]: time="2026-01-28T16:06:37+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 16:06:37 volumio go-librespot[14359]: time="2026-01-28T16:06:37+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 28 16:06:37 volumio go-librespot[14359]: time="2026-01-28T16:06:37+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 28 16:06:37 volumio go-librespot[14359]: time="2026-01-28T16:06:37+07:00" level=info msg="zeroconf server listening on port 36773" Jan 28 16:06:37 volumio go-librespot[14359]: time="2026-01-28T16:06:37+07:00" level=debug msg="obtained new client token: AABBHdNbQZmUZ8Fy9VyjbeleS66Ueb+AIA2gP+cJa3SLBRpqX8NOXzKWTrCArFa6FBvTmmztWaXJqu9EjI9j8RF+kMdBf8ddpWyYIUaZUMqRuKOCIS3ym3+G3JfoNDSMHl7aouIGtnMUAuYjnVRX7o0k5XmVxDJfwV4sH4nyc99H2UtavYMdSsnpNUAlmYypcb9NBk2PaIoZ7/aDqb4f0zJwa9U0720KG4fdlHLc74LEY8UrZ6UgumsfyiE=" Jan 28 16:06:37 volumio go-librespot[14359]: time="2026-01-28T16:06:37+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 16:06:37 volumio go-librespot[14359]: time="2026-01-28T16:06:37+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Jan 28 16:06:37 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 16:06:37 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 16:06:37 volumio volumio[14009]: info: Connection to go-librespot Websocket closed Jan 28 16:06:37 volumio volumio[14009]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Jan 28 16:06:37 volumio volumio[14009]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Jan 28 16:06:37 volumio volumio[14009]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Jan 28 16:06:37 volumio volumio[14009]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Jan 28 16:06:37 volumio volumio[14009]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Jan 28 16:06:37 volumio volumio[14009]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Jan 28 16:06:37 volumio volumio[14009]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Jan 28 16:06:37 volumio volumio[14009]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Jan 28 16:06:37 volumio volumio[14009]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Jan 28 16:06:37 volumio volumio[14009]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Jan 28 16:06:37 volumio volumio[14009]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Jan 28 16:06:37 volumio volumio[14009]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Jan 28 16:06:37 volumio volumio[14009]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Jan 28 16:06:37 volumio volumio[14009]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Jan 28 16:06:37 volumio volumio[14009]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Jan 28 16:06:37 volumio volumio[14009]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Jan 28 16:06:37 volumio volumio[14009]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Jan 28 16:06:37 volumio volumio[14009]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Jan 28 16:06:37 volumio volumio[14009]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Jan 28 16:06:37 volumio volumio[14009]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Jan 28 16:06:37 volumio volumio[14009]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Jan 28 16:06:37 volumio volumio[14009]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Jan 28 16:06:37 volumio volumio[14009]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Jan 28 16:06:37 volumio volumio[14009]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Jan 28 16:06:37 volumio volumio[14009]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Jan 28 16:06:37 volumio volumio[14009]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Jan 28 16:06:37 volumio volumio[14009]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Jan 28 16:06:37 volumio volumio[14009]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Jan 28 16:06:37 volumio volumio[14009]: info: Adding plugin bluetooth to MyMusic Plugins Jan 28 16:06:37 volumio volumio[14009]: info: Adding plugin multiroom to MyMusic Plugins Jan 28 16:06:37 volumio volumio[14009]: info: Adding plugin metavolumio to MyMusic Plugins Jan 28 16:06:37 volumio volumio[14009]: info: Adding plugin cd_controller to MyMusic Plugins Jan 28 16:06:37 volumio volumio[14009]: info: Adding plugin qobuzconnect to MyMusic Plugins Jan 28 16:06:37 volumio volumio[14009]: info: Adding plugin smart_inputs to MyMusic Plugins Jan 28 16:06:37 volumio volumio[14009]: info: Adding plugin tidalconnect to MyMusic Plugins Jan 28 16:06:37 volumio volumio[14009]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Jan 28 16:06:38 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 16:06:38 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 16:06:38 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 16:06:39 volumio volumio[14009]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Jan 28 16:06:39 volumio volumio[14009]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Jan 28 16:06:39 volumio volumio[14009]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 16:06:39 volumio volumio[14009]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 16:06:39 volumio volumio[14009]: info: Starting MyVolumio Remote Streaming Endpoints Jan 28 16:06:39 volumio volumio[14009]: info: MyVolumio login type: Token Jan 28 16:06:39 volumio volumio[14009]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Jan 28 16:06:39 volumio volumio[14009]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Jan 28 16:06:40 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 16:06:40 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 16:06:40 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 16:06:40 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Jan 28 16:06:40 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 16:06:41 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 16:06:41 volumio go-librespot[14380]: go-librespot daemon starting... Jan 28 16:06:41 volumio go-librespot[14381]: time="2026-01-28T16:06:41+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 16:06:41 volumio go-librespot[14381]: time="2026-01-28T16:06:41+07:00" level=debug msg="app state loaded" Jan 28 16:06:41 volumio go-librespot[14381]: time="2026-01-28T16:06:41+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 16:06:41 volumio volumio[14009]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Jan 28 16:06:41 volumio volumio[14009]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Jan 28 16:06:41 volumio volumio[14009]: info: Streaming services startup Jan 28 16:06:41 volumio volumio[14009]: info: Starting Streaming Daemon Jan 28 16:06:41 volumio go-librespot[14381]: time="2026-01-28T16:06:41+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 16:06:41 volumio go-librespot[14381]: time="2026-01-28T16:06:41+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 28 16:06:41 volumio go-librespot[14381]: time="2026-01-28T16:06:41+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 28 16:06:41 volumio go-librespot[14381]: time="2026-01-28T16:06:41+07:00" level=info msg="zeroconf server listening on port 35969" Jan 28 16:06:41 volumio sudo[14390]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jan 28 16:06:41 volumio volumio[14009]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Jan 28 16:06:41 volumio sudo[14390]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 16:06:41 volumio sudo[14390]: pam_unix(sudo:session): session closed for user root Jan 28 16:06:41 volumio volumio[14009]: info: Getting Spotify volume Jan 28 16:06:41 volumio volumio[14009]: info: Initializing connection to go-librespot Websocket Jan 28 16:06:41 volumio volumio[14009]: error: Cannot start Volumio Streaming Daemon Jan 28 16:06:41 volumio volumio[14009]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Jan 28 16:06:41 volumio volumio[14009]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Jan 28 16:06:41 volumio go-librespot[14381]: time="2026-01-28T16:06:41+07:00" level=debug msg="obtained new client token: AAANHeFLdcXgpINvo3bYuT6gPUOdDhSIGZpaJvfc0vVuHWfY/LmmhPLRD8f2i8BtvwFdfa+FOvHfRmOZ+y5YjZ0B66yZ5loObFIyQ8pWZX1euUPjtaZmg3pxUdFOpBQbYReXlDJPXV6Yh4J61Hf4zlL0vnVWeP6s8ZN6if3L3KQueTxEfqYfoqL6y1XeVXs1gIvsHmxuWR19eyg0ijVCNQ6Bn1VzA4TNgNtQd61Ky2PIN0qOGAcgkXXofhg=" Jan 28 16:06:41 volumio go-librespot[14381]: time="2026-01-28T16:06:41+07:00" level=debug msg="new websocket client" Jan 28 16:06:41 volumio volumio[14009]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Jan 28 16:06:41 volumio volumio[14009]: info: Connection to go-librespot Websocket established Jan 28 16:06:41 volumio go-librespot[14381]: time="2026-01-28T16:06:41+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 16:06:42 volumio go-librespot[14381]: time="2026-01-28T16:06:42+07:00" level=debug msg="completed keyexchange" Jan 28 16:06:42 volumio go-librespot[14381]: time="2026-01-28T16:06:42+07:00" level=debug msg="completed challenge" Jan 28 16:06:42 volumio volumio[14009]: info: CoreCommandRouter::volumioGetState Jan 28 16:06:42 volumio volumio[14009]: info: CorePlayQueue::getTrack 0 Jan 28 16:06:42 volumio volumio[14009]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jan 28 16:06:42 volumio volumio[14009]: SPOTIFY: SPOTIFY VOLUME undefined Jan 28 16:06:42 volumio volumio[14009]: SPOTIFY: VOLUMIO VOLUME 100 Jan 28 16:06:42 volumio volumio[14009]: info: Aligning Spotify Volume to Volumio Volume Jan 28 16:06:42 volumio volumio[14009]: info: CoreCommandRouter::volumioGetState Jan 28 16:06:42 volumio volumio[14009]: info: CorePlayQueue::getTrack 0 Jan 28 16:06:42 volumio volumio[14009]: info: Setting Spotify Volume from Volumio: 100 Jan 28 16:06:42 volumio go-librespot[14381]: time="2026-01-28T16:06:42+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 16:06:42 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 16:06:42 volumio volumio[14009]: info: Connection to go-librespot Websocket closed Jan 28 16:06:42 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 16:06:42 volumio volumio[14009]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 28 16:06:42 volumio volumio[14009]: Error: socket hang up Jan 28 16:06:42 volumio volumio[14009]: at connResetException (node:internal/errors:720:14) Jan 28 16:06:42 volumio volumio[14009]: at Socket.socketOnEnd (node:_http_client:519:23) Jan 28 16:06:42 volumio volumio[14009]: at Socket.emit (node:events:526:35) Jan 28 16:06:42 volumio volumio[14009]: at endReadableNT (node:internal/streams/readable:1376:12) Jan 28 16:06:42 volumio volumio[14009]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Jan 28 16:06:42 volumio volumio[14009]: code: 'ECONNRESET', Jan 28 16:06:42 volumio volumio[14009]: response: undefined Jan 28 16:06:42 volumio volumio[14009]: } Jan 28 16:06:42 volumio volumio[14009]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 28 16:06:42 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 16:06:42 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 16:06:42 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 16:06:43 volumio sudo[14411]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-01-28 16:05' Jan 28 16:06:43 volumio sudo[14411]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 16:06:44 volumio sudo[14411]: pam_unix(sudo:session): session closed for user root Jan 28 16:06:44 volumio volumio-remote-updater[628]: [2026-01-28 16:06:44] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Jan 28 16:06:44 volumio volumio-remote-updater[628]: [2026-01-28 16:06:44] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Jan 28 16:06:44 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Jan 28 16:06:44 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Jan 28 16:06:44 volumio systemd[1]: volumio.service: Consumed 58.881s CPU time. Jan 28 16:06:44 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 28 16:06:44 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Jan 28 16:06:44 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 10357. Jan 28 16:06:44 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 28 16:06:44 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Jan 28 16:06:44 volumio systemd[1]: volumio.service: Consumed 58.881s CPU time. Jan 28 16:06:44 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Jan 28 16:06:44 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Jan 28 16:06:44 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 16:06:44 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 16:06:44 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 16:06:45 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Jan 28 16:06:45 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 16:06:45 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 16:06:45 volumio go-librespot[14441]: go-librespot daemon starting... Jan 28 16:06:45 volumio go-librespot[14442]: time="2026-01-28T16:06:45+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 16:06:45 volumio go-librespot[14442]: time="2026-01-28T16:06:45+07:00" level=debug msg="app state loaded" Jan 28 16:06:45 volumio go-librespot[14442]: time="2026-01-28T16:06:45+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 16:06:45 volumio go-librespot[14442]: time="2026-01-28T16:06:45+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 16:06:45 volumio go-librespot[14442]: time="2026-01-28T16:06:45+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 28 16:06:45 volumio go-librespot[14442]: time="2026-01-28T16:06:45+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 28 16:06:45 volumio go-librespot[14442]: time="2026-01-28T16:06:45+07:00" level=info msg="zeroconf server listening on port 33683" Jan 28 16:06:46 volumio go-librespot[14442]: time="2026-01-28T16:06:46+07:00" level=debug msg="obtained new client token: AAB5y3X9KHXCSk7E3iWC/8A92ezsjBDeltsp6BViTa3OrDDfLsIRYGmSfGrrMMmlmd3ax9Wve275W0NKyGlwmWLEVhEcLD8HpamNE2GlRvTmD/HJ4V8DbVF4N6ycPFXaiD82kuemh9wbyvLhhGmaEgVYhz9E2jNfwjmN3+TuFTHkeyvM83zYltu7HHKvKC4Q+ENrmWSH/dFBT9y7umOvZZd40xj0SN77jVEFWmZuUKKhHvque7SwZVNgGHU=" Jan 28 16:06:46 volumio go-librespot[14442]: time="2026-01-28T16:06:46+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 16:06:46 volumio go-librespot[14442]: time="2026-01-28T16:06:46+07:00" level=debug msg="completed keyexchange" Jan 28 16:06:46 volumio go-librespot[14442]: time="2026-01-28T16:06:46+07:00" level=debug msg="completed challenge" Jan 28 16:06:46 volumio go-librespot[14442]: time="2026-01-28T16:06:46+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 16:06:46 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 16:06:46 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 16:06:46 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 16:06:46 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 16:06:46 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 16:06:47 volumio volumio[14426]: info: ------------------------------------------- Jan 28 16:06:47 volumio volumio[14426]: info: ----- Volumio3 ---- Jan 28 16:06:47 volumio volumio[14426]: info: ------------------------------------------- Jan 28 16:06:47 volumio volumio[14426]: info: ----- System startup ---- Jan 28 16:06:47 volumio volumio[14426]: info: ------------------------------------------- Jan 28 16:06:48 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 16:06:48 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 16:06:48 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 16:06:49 volumio volumio-remote-updater[628]: [2026-01-28 16:06:49] [connect] Successful connection Jan 28 16:06:49 volumio volumio[14426]: info: MYVOLUMIO Environment detected Jan 28 16:06:49 volumio volumio[14426]: info: Plugin folders cleanup Jan 28 16:06:49 volumio volumio[14426]: info: Scanning into folder /volumio/app/plugins/ Jan 28 16:06:49 volumio volumio[14426]: info: Scanning category audio_interface Jan 28 16:06:49 volumio volumio[14426]: info: Scanning category miscellanea Jan 28 16:06:49 volumio volumio[14426]: info: Scanning category music_service Jan 28 16:06:49 volumio volumio[14426]: info: Scanning category plugins.json Jan 28 16:06:49 volumio volumio[14426]: info: Scanning category system_controller Jan 28 16:06:49 volumio volumio[14426]: info: Scanning category user_interface Jan 28 16:06:49 volumio volumio[14426]: info: Scanning into folder /data/plugins/ Jan 28 16:06:49 volumio volumio[14426]: info: Scanning category music_service Jan 28 16:06:49 volumio volumio[14426]: info: Plugin folders cleanup completed Jan 28 16:06:49 volumio volumio[14426]: info: ------------------------------------------- Jan 28 16:06:49 volumio volumio[14426]: info: ----- Core plugins startup ---- Jan 28 16:06:49 volumio volumio[14426]: info: ------------------------------------------- Jan 28 16:06:49 volumio volumio[14426]: info: Loading plugins from folder /volumio/app/plugins/ Jan 28 16:06:49 volumio volumio[14426]: info: Adding plugin upnp to MyMusic Plugins Jan 28 16:06:49 volumio volumio[14426]: info: Adding plugin airplay_emulation to MyMusic Plugins Jan 28 16:06:49 volumio volumio[14426]: info: Adding plugin upnp_browser to MyMusic Plugins Jan 28 16:06:49 volumio volumio[14426]: info: Loading plugins from folder /data/plugins/ Jan 28 16:06:49 volumio volumio[14426]: info: Loading plugin "system"... Jan 28 16:06:49 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Jan 28 16:06:49 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 16:06:49 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 16:06:49 volumio go-librespot[14459]: go-librespot daemon starting... Jan 28 16:06:49 volumio volumio[14426]: info: Loading plugin "appearance"... Jan 28 16:06:49 volumio go-librespot[14461]: time="2026-01-28T16:06:49+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 16:06:49 volumio go-librespot[14461]: time="2026-01-28T16:06:49+07:00" level=debug msg="app state loaded" Jan 28 16:06:49 volumio go-librespot[14461]: time="2026-01-28T16:06:49+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 16:06:50 volumio go-librespot[14461]: time="2026-01-28T16:06:50+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 16:06:50 volumio go-librespot[14461]: time="2026-01-28T16:06:50+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 28 16:06:50 volumio go-librespot[14461]: time="2026-01-28T16:06:50+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 28 16:06:50 volumio go-librespot[14461]: time="2026-01-28T16:06:50+07:00" level=info msg="zeroconf server listening on port 39031" Jan 28 16:06:50 volumio go-librespot[14461]: time="2026-01-28T16:06:50+07:00" level=debug msg="obtained new client token: AAC6jNm5nNebzgbVm5akWZ4hVBkIAHsPf6/PVqswx4jQ//ZXd0CqGFQiZiuL34EEDkFe706SqBMQc6gJZ01DahnRQdleZZK8QQ0ahGtHV+DZ7rJPnguWAQXJqkrI28cibVmbgluhGXKMrGfZBPeuwfWrP0iI4TxozsDKUYo1/rXUVrzf6gUZsTcqBRZFoYuO/wno9/UTwQjQ/bPYVskcE0NxLtDcOAJznszRsfeQrUDrVhXgUH7adkc9hYE=" Jan 28 16:06:50 volumio go-librespot[14461]: time="2026-01-28T16:06:50+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 16:06:50 volumio go-librespot[14461]: time="2026-01-28T16:06:50+07:00" level=debug msg="completed keyexchange" Jan 28 16:06:50 volumio go-librespot[14461]: time="2026-01-28T16:06:50+07:00" level=debug msg="completed challenge" Jan 28 16:06:50 volumio go-librespot[14461]: time="2026-01-28T16:06:50+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 16:06:50 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 16:06:50 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 16:06:50 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 16:06:50 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 16:06:50 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 16:06:51 volumio volumio[14426]: info: Loading plugin "network"... Jan 28 16:06:51 volumio volumio[14426]: info: Refreshing Cached IP Addresses Jan 28 16:06:51 volumio sudo[14471]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 28 16:06:51 volumio sudo[14471]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 16:06:51 volumio volumio[14426]: info: Loading plugin "services"... Jan 28 16:06:51 volumio sudo[14471]: pam_unix(sudo:session): session closed for user root Jan 28 16:06:51 volumio sudo[14473]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 28 16:06:51 volumio sudo[14473]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 16:06:51 volumio volumio[14426]: info: Loading plugin "alsa_controller"... Jan 28 16:06:51 volumio sudo[14473]: pam_unix(sudo:session): session closed for user root Jan 28 16:06:51 volumio sudo[14481]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Jan 28 16:06:51 volumio sudo[14481]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 16:06:51 volumio volumio[14426]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 28 16:06:51 volumio volumio[14426]: info: Loading plugin "wizard"... Jan 28 16:06:51 volumio volumio[14426]: info: Loading plugin "networkfs"... Jan 28 16:06:51 volumio volumio[14426]: info: Starting Udev Watcher for removable devices Jan 28 16:06:51 volumio volumio[14426]: info: Ignoring mount for partition: boot Jan 28 16:06:51 volumio volumio[14426]: info: Ignoring mount for partition: volumio Jan 28 16:06:51 volumio volumio[14426]: info: Ignoring mount for partition: volumio_data Jan 28 16:06:51 volumio volumio[14426]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 28 16:06:51 volumio volumio[14426]: info: Loading plugin "volumio_command_line_client"... Jan 28 16:06:51 volumio volumio[14426]: info: Loading plugin "upnp"... Jan 28 16:06:51 volumio volumio[14426]: info: [1769591211888] Starting Upmpd Daemon Jan 28 16:06:51 volumio volumio[14426]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 28 16:06:51 volumio volumio[14426]: info: Loading plugin "my_music"... Jan 28 16:06:51 volumio volumio[14426]: info: Loading plugin "mpd"... Jan 28 16:06:52 volumio volumio[14426]: info: Loading plugin "upnp_browser"... Jan 28 16:06:52 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 16:06:52 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 16:06:52 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 16:06:53 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Jan 28 16:06:53 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 16:06:53 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 16:06:53 volumio go-librespot[14504]: go-librespot daemon starting... Jan 28 16:06:53 volumio go-librespot[14505]: time="2026-01-28T16:06:53+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 16:06:53 volumio go-librespot[14505]: time="2026-01-28T16:06:53+07:00" level=debug msg="app state loaded" Jan 28 16:06:53 volumio go-librespot[14505]: time="2026-01-28T16:06:53+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 16:06:54 volumio go-librespot[14505]: time="2026-01-28T16:06:54+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 16:06:54 volumio go-librespot[14505]: time="2026-01-28T16:06:54+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 28 16:06:54 volumio go-librespot[14505]: time="2026-01-28T16:06:54+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 28 16:06:54 volumio go-librespot[14505]: time="2026-01-28T16:06:54+07:00" level=info msg="zeroconf server listening on port 37879" Jan 28 16:06:54 volumio sudo[14481]: pam_unix(sudo:session): session closed for user root Jan 28 16:06:54 volumio go-librespot[14505]: time="2026-01-28T16:06:54+07:00" level=debug msg="obtained new client token: AACSoAAmaXPHaLgMz0gekM1eqiF48+hMvODxhOACEfX7WN5nECbLu+8t1ALdy6ijPic9QDruFxnLpWKsFJbT+SrFV2RwrHu67hZqZsUsN4B7H65Yeuce6q+c9JX9dFRWF4K9fn7C7WGYtiq4r6k885Mn/hwJwMfcSghnYxF3dti07s1gzW/B4PgpNHfn28KgaWt1mA5REH65SwkIDv6kTDlEf+kl/LXcqZ+Y6YXE6a4O0MU52eLOgGgT9BE=" Jan 28 16:06:54 volumio go-librespot[14505]: time="2026-01-28T16:06:54+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 16:06:54 volumio go-librespot[14505]: time="2026-01-28T16:06:54+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Jan 28 16:06:54 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 16:06:54 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 16:06:54 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 16:06:54 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 16:06:54 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 16:06:55 volumio volumio[14426]: info: Starting UPNP Browser Jan 28 16:06:55 volumio volumio[14426]: info: Loading plugin "alarm-clock"... Jan 28 16:06:55 volumio volumio[14426]: info: Loading plugin "airplay_emulation"... Jan 28 16:06:55 volumio volumio[14426]: info: Starting Shairport Sync Jan 28 16:06:55 volumio volumio[14426]: info: Loading plugin "last_100"... Jan 28 16:06:55 volumio volumio[14426]: info: Loading plugin "webradio"... Jan 28 16:06:56 volumio volumio[14426]: info: Loading plugin "i2s_dacs"... Jan 28 16:06:56 volumio volumio[14426]: info: Loading plugin "volumiodiscovery"... Jan 28 16:06:56 volumio volumio[14426]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 28 16:06:56 volumio volumio[14426]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 16:06:56 volumio node[14426]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 28 16:06:56 volumio volumio[14426]: *** WARNING *** For more information see Jan 28 16:06:56 volumio volumio[14426]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 28 16:06:56 volumio volumio[14426]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 16:06:56 volumio volumio[14426]: *** WARNING *** For more information see Jan 28 16:06:56 volumio node[14426]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 16:06:56 volumio node[14426]: *** WARNING *** For more information see Jan 28 16:06:56 volumio node[14426]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 28 16:06:56 volumio node[14426]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 16:06:56 volumio node[14426]: *** WARNING *** For more information see Jan 28 16:06:56 volumio volumio[14426]: info: Applying required configuration parameters for plugin volumiodiscovery Jan 28 16:06:56 volumio volumio[14426]: info: Discovery: Started advertising with name: Volumio Jan 28 16:06:56 volumio volumio[14426]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 28 16:06:56 volumio volumio[14426]: info: Loading plugin "spop"... Jan 28 16:06:56 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 16:06:56 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 16:06:56 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 16:06:57 volumio volumio[14426]: info: Loading plugin "ytcr"... Jan 28 16:06:57 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Jan 28 16:06:57 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 16:06:58 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 16:06:58 volumio go-librespot[14514]: go-librespot daemon starting... Jan 28 16:06:58 volumio go-librespot[14515]: time="2026-01-28T16:06:58+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 16:06:58 volumio go-librespot[14515]: time="2026-01-28T16:06:58+07:00" level=debug msg="app state loaded" Jan 28 16:06:58 volumio go-librespot[14515]: time="2026-01-28T16:06:58+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 16:06:58 volumio go-librespot[14515]: time="2026-01-28T16:06:58+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 16:06:58 volumio go-librespot[14515]: time="2026-01-28T16:06:58+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 28 16:06:58 volumio go-librespot[14515]: time="2026-01-28T16:06:58+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 28 16:06:58 volumio go-librespot[14515]: time="2026-01-28T16:06:58+07:00" level=info msg="zeroconf server listening on port 33219" Jan 28 16:06:58 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 16:06:58 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 16:06:58 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 16:06:58 volumio go-librespot[14515]: time="2026-01-28T16:06:58+07:00" level=debug msg="obtained new client token: AABldtVpXJDda7QYDMMNPddFlYdEdvQailgRvvmbsh/mEG5Lcsse3mHQUTu4B3i7+q5XiLqq8LnI46xatgigYkIQQywUG4V0VmJo8sIlmR1ffrh2pEI7oMgsNatzFEZI32zvia0nUHCPOAftfklr47fiJV+iAcW2HxBeJdCr1+1n9P25Fai8zEuwUNcxdEH6WejcjVHuH7Oc4Fz67+cQ2uxu7UQ3L60OPdiy+IkJ4z9I/lo3TZsdyGpbBXw=" Jan 28 16:06:59 volumio go-librespot[14515]: time="2026-01-28T16:06:59+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 16:06:59 volumio go-librespot[14515]: time="2026-01-28T16:06:59+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Jan 28 16:06:59 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 16:06:59 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 16:07:00 volumio volumio[14426]: info: Loading plugin "ytmusic"... Jan 28 16:07:00 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 16:07:00 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 16:07:00 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 16:07:01 volumio volumio-remote-updater[628]: [2026-01-28 16:07:01] [connect] Successful connection Jan 28 16:07:01 volumio volumio[14426]: info: Loading plugin "outputs"... Jan 28 16:07:01 volumio volumio[14426]: info: Loading plugin "albumart"... Jan 28 16:07:01 volumio volumio[14426]: info: Plugin example_plugin is not enabled Jan 28 16:07:01 volumio volumio[14426]: info: Loading plugin "inputs"... Jan 28 16:07:01 volumio volumio[14426]: info: Loading plugin "updater_comm"... Jan 28 16:07:01 volumio volumio[14426]: info: Plugin mpdemulation is not enabled Jan 28 16:07:01 volumio volumio[14426]: info: Loading plugin "rest_api"... Jan 28 16:07:02 volumio volumio[14426]: info: Loading plugin "websocket"... Jan 28 16:07:02 volumio volumio[14426]: info: Starting Socket.io Server version 1.7.4 Jan 28 16:07:02 volumio volumio[14426]: info: Loading plugin "RoonBridge"... Jan 28 16:07:02 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Jan 28 16:07:02 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 16:07:02 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 16:07:02 volumio go-librespot[14547]: go-librespot daemon starting... Jan 28 16:07:02 volumio go-librespot[14548]: time="2026-01-28T16:07:02+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 16:07:02 volumio go-librespot[14548]: time="2026-01-28T16:07:02+07:00" level=debug msg="app state loaded" Jan 28 16:07:02 volumio go-librespot[14548]: time="2026-01-28T16:07:02+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 16:07:02 volumio volumio[14426]: info: Applying required configuration parameters for plugin RoonBridge Jan 28 16:07:02 volumio volumio[14426]: info: Loading i18n strings for locale en Jan 28 16:07:02 volumio volumio[14426]: Updating browse sources language Jan 28 16:07:02 volumio volumio[14426]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 16:07:02 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 16:07:02 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 16:07:02 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 16:07:02 volumio volumio[14537]: Forking 3 albumart workers Jan 28 16:07:02 volumio go-librespot[14548]: time="2026-01-28T16:07:02+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 16:07:02 volumio go-librespot[14548]: time="2026-01-28T16:07:02+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 28 16:07:02 volumio go-librespot[14548]: time="2026-01-28T16:07:02+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 28 16:07:02 volumio volumio[14426]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 28 16:07:02 volumio volumio[14426]: info: CoreCommandRouter::initPlayerControls Jan 28 16:07:02 volumio volumio[14426]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 16:07:02 volumio volumio[14426]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 16:07:02 volumio volumio[14426]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 16:07:02 volumio volumio[14426]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 16:07:02 volumio volumio[14426]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 16:07:02 volumio volumio[14426]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 16:07:02 volumio volumio[14426]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 16:07:02 volumio volumio[14426]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 16:07:02 volumio go-librespot[14548]: time="2026-01-28T16:07:02+07:00" level=info msg="zeroconf server listening on port 37103" Jan 28 16:07:03 volumio volumio[14426]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 28 16:07:03 volumio volumio[14426]: Express server listening on port 3000 Jan 28 16:07:03 volumio volumio[14426]: [Metrics] WebUI: 16s 12.44ms Jan 28 16:07:03 volumio volumio[14426]: info: CoreStateMachine::resetVolumioState Jan 28 16:07:03 volumio volumio[14426]: info: CoreStateMachine::getcurrentVolume Jan 28 16:07:03 volumio volumio[14426]: info: CoreCommandRouter::volumioRetrievevolume Jan 28 16:07:03 volumio go-librespot[14548]: time="2026-01-28T16:07:03+07:00" level=debug msg="obtained new client token: AAB5PNGFc0y4FIHXh8L0LPzkA0NF8S1VffsjUTk5s2Z9XvBwiQAddPOw4GOjjF3jgh3LnCviRoa+HDSwVpNqthsAzEGQRL8bZAG67mcDQwiWs84pgAeAcaW0Y6mQyXUFuUV843aMo8mEu2J+yDSm/OHgeJj4XbSlKVCQywzrijSVnruW92m0kvHVqV12INWA1483gs+SVn46kFWx8ZPcJuBt//dwlxRk5/52G2LNhwWIkhO6U8DHLNi7" Jan 28 16:07:03 volumio sudo[14590]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 28 16:07:03 volumio sudo[14590]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 16:07:03 volumio sudo[14592]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 28 16:07:03 volumio sudo[14592]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 16:07:03 volumio go-librespot[14548]: time="2026-01-28T16:07:03+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 16:07:03 volumio sudo[14590]: pam_unix(sudo:session): session closed for user root Jan 28 16:07:03 volumio volumio[14426]: info: Volumio Network Manager: Network status updated: 1 Jan 28 16:07:03 volumio sudo[14592]: pam_unix(sudo:session): session closed for user root Jan 28 16:07:03 volumio go-librespot[14548]: time="2026-01-28T16:07:03+07:00" level=debug msg="completed keyexchange" Jan 28 16:07:03 volumio go-librespot[14548]: time="2026-01-28T16:07:03+07:00" level=debug msg="completed challenge" Jan 28 16:07:03 volumio go-librespot[14548]: time="2026-01-28T16:07:03+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 16:07:03 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 16:07:03 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 16:07:03 volumio volumio-remote-updater[628]: [2026-01-28 16:07:03] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1769591221 101 Jan 28 16:07:03 volumio volumio[14426]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 1 Jan 28 16:07:03 volumio volumio[14426]: info: VolumeController:: Volume=100 Mute =false Jan 28 16:07:03 volumio volumio[14426]: info: CoreStateMachine::pushState Jan 28 16:07:03 volumio volumio[14426]: info: CorePlayQueue::getTrack 0 Jan 28 16:07:03 volumio volumio[14426]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 28 16:07:03 volumio volumio[14426]: info: CoreCommandRouter::volumioPushState Jan 28 16:07:03 volumio volumio[14426]: info: CoreStateMachine::updateTrackBlock Jan 28 16:07:03 volumio volumio[14426]: info: CorePlayQueue::getTrackBlock Jan 28 16:07:03 volumio volumio[14426]: info: CoreCommandRouter::volumioRetrievevolume Jan 28 16:07:03 volumio volumio[14426]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 16:07:03 volumio volumio[14426]: info: Reloading queue from file Jan 28 16:07:03 volumio volumio[14426]: info: CoreStateMachine::setRepeat null single undefined Jan 28 16:07:03 volumio volumio[14426]: info: CoreStateMachine::pushState Jan 28 16:07:03 volumio volumio[14426]: info: CorePlayQueue::getTrack 0 Jan 28 16:07:03 volumio volumio[14426]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 28 16:07:03 volumio volumio[14426]: info: CoreCommandRouter::volumioPushState Jan 28 16:07:03 volumio volumio[14426]: info: CoreStateMachine::setRandom null Jan 28 16:07:03 volumio volumio[14426]: info: CoreStateMachine::pushState Jan 28 16:07:03 volumio volumio[14426]: info: CorePlayQueue::getTrack 0 Jan 28 16:07:03 volumio volumio[14426]: info: CoreCommandRouter::volumioPushState Jan 28 16:07:03 volumio volumio[14426]: info: Setting Device type: Raspberry PI Jan 28 16:07:03 volumio volumio[14426]: info: Completed loading Core Plugins Jan 28 16:07:04 volumio volumio[14426]: info: Preparing to generate the ALSA configuration file Jan 28 16:07:04 volumio volumio[14426]: info: VolumeController:: Volume=100 Mute =false Jan 28 16:07:04 volumio volumio[14426]: info: CoreStateMachine::pushState Jan 28 16:07:04 volumio volumio[14426]: info: CorePlayQueue::getTrack 0 Jan 28 16:07:04 volumio volumio[14426]: info: CoreCommandRouter::volumioPushState Jan 28 16:07:04 volumio volumio[14426]: info: Asound.conf file unchanged, so no further update is needed Jan 28 16:07:04 volumio volumio[14426]: info: Output device has changed, restarting MPD Jan 28 16:07:04 volumio volumio[14426]: info: Output device has changed, restarting Shairport Sync Jan 28 16:07:04 volumio sudo[14607]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Jan 28 16:07:04 volumio volumio[14426]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 16:07:04 volumio volumio[14426]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 16:07:04 volumio sudo[14607]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 16:07:04 volumio sudo[14609]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 28 16:07:04 volumio sudo[14609]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 16:07:04 volumio sudo[14611]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 28 16:07:04 volumio sudo[14611]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 16:07:04 volumio sudo[14609]: pam_unix(sudo:session): session closed for user root Jan 28 16:07:04 volumio volumio[14426]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 28 16:07:04 volumio sudo[14607]: pam_unix(sudo:session): session closed for user root Jan 28 16:07:04 volumio volumio[14426]: info: ___________ START PLUGINS ___________ Jan 28 16:07:04 volumio volumio[14426]: info: ControllerMpd::onStart: Initializing MPD Jan 28 16:07:04 volumio volumio[14426]: info: Creating MPD Configuration file Jan 28 16:07:04 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Jan 28 16:07:04 volumio volumio[14426]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 28 16:07:04 volumio volumio[14426]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 16:07:04 volumio sudo[14620]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 28 16:07:04 volumio volumio[14426]: info: [1769591224510] CoreMusicLibrary::Adding element Media Servers Jan 28 16:07:04 volumio volumio[14426]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 16:07:04 volumio sudo[14620]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 16:07:04 volumio sudo[14622]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 28 16:07:04 volumio sudo[14622]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 16:07:04 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 28 16:07:04 volumio sudo[14620]: pam_unix(sudo:session): session closed for user root Jan 28 16:07:04 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 28 16:07:04 volumio systemd[1]: mpd.service: Consumed 7.545s CPU time. Jan 28 16:07:04 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 28 16:07:04 volumio volumio[14426]: info: UPNP Browser: Client initialized successfully Jan 28 16:07:04 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 28 16:07:04 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 28 16:07:04 volumio volumio[14426]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 16:07:04 volumio volumio[14426]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 16:07:04 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 28 16:07:04 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 28 16:07:04 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 28 16:07:04 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 28 16:07:04 volumio volumio[14426]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 28 16:07:04 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 28 16:07:04 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 28 16:07:04 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 28 16:07:04 volumio volumio[14426]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 16:07:04 volumio volumio[14426]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 16:07:04 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 16:07:04 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 16:07:04 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 16:07:04 volumio volumio[14426]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 28 16:07:04 volumio volumio[14426]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 16:07:04 volumio volumio[14426]: info: [1769591224866] CoreMusicLibrary::Adding element Last_100 Jan 28 16:07:04 volumio volumio[14426]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 16:07:04 volumio volumio[14426]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 16:07:04 volumio volumio[14426]: info: [1769591224878] CoreMusicLibrary::Adding element Webradio Jan 28 16:07:04 volumio volumio[14426]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 16:07:04 volumio volumio[14426]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 28 16:07:04 volumio volumio[14426]: info: Initializing BBC Radios Jan 28 16:07:04 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 28 16:07:04 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 28 16:07:05 volumio volumio[14426]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 28 16:07:05 volumio volumio[14426]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 16:07:05 volumio volumio[14426]: info: Creating Spotify config file Jan 28 16:07:05 volumio volumio[14426]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 16:07:05 volumio sudo[14636]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 28 16:07:05 volumio sudo[14636]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jan 28 16:07:05 volumio sudo[14636]: pam_unix(sudo:session): session closed for user root Jan 28 16:07:06 volumio volumio[14558]: Starting albumart workers Jan 28 16:07:06 volumio volumio[14559]: Starting albumart workers Jan 28 16:07:06 volumio volumio[14557]: Starting albumart workers Jan 28 16:07:06 volumio volumio[14426]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 16:07:06 volumio volumio[14426]: info: [1769591226566] CoreMusicLibrary::Adding element YouTube Music Jan 28 16:07:06 volumio volumio[14426]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 16:07:06 volumio volumio[14426]: Cannot find translation for source YouTube Music Jan 28 16:07:06 volumio volumio[14426]: info: Volumio Calling Home Jan 28 16:07:06 volumio sudo[14653]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Jan 28 16:07:06 volumio sudo[14653]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 16:07:06 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Jan 28 16:07:06 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 16:07:06 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 16:07:06 volumio go-librespot[14657]: go-librespot daemon starting... Jan 28 16:07:06 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 16:07:06 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 16:07:06 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 16:07:06 volumio sudo[14653]: pam_unix(sudo:session): session closed for user root Jan 28 16:07:06 volumio go-librespot[14660]: time="2026-01-28T16:07:06+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 16:07:07 volumio go-librespot[14660]: time="2026-01-28T16:07:07+07:00" level=info msg="zeroconf server listening on port 36571" Jan 28 16:07:07 volumio volumio[14426]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Jan 28 16:07:07 volumio volumio[14426]: info: Discovery: Found device Volumio Jan 28 16:07:07 volumio volumio[14426]: info: CoreCommandRouter::volumioGetState Jan 28 16:07:07 volumio volumio[14426]: info: CorePlayQueue::getTrack 0 Jan 28 16:07:07 volumio volumio[14426]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Jan 28 16:07:07 volumio volumio[14426]: info: Discovery: Found device Volumio Jan 28 16:07:07 volumio volumio[14426]: info: CoreCommandRouter::volumioGetState Jan 28 16:07:07 volumio volumio[14426]: info: CorePlayQueue::getTrack 0 Jan 28 16:07:08 volumio volumio[14426]: info: MPD Permissions set Jan 28 16:07:08 volumio volumio[14426]: info: MPD Permissions set Jan 28 16:07:08 volumio volumio[14426]: info: Upmpdcli Daemon Started Jan 28 16:07:08 volumio volumio[14426]: info: Volumio called home Jan 28 16:07:08 volumio volumio[14426]: info: Spotify config file written Jan 28 16:07:08 volumio sudo[14681]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jan 28 16:07:08 volumio sudo[14681]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 16:07:08 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Jan 28 16:07:08 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Jan 28 16:07:08 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 16:07:08 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 16:07:08 volumio go-librespot[14689]: go-librespot daemon starting... Jan 28 16:07:08 volumio sudo[14681]: pam_unix(sudo:session): session closed for user root Jan 28 16:07:08 volumio go-librespot[14690]: time="2026-01-28T16:07:08+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 16:07:08 volumio go-librespot[14690]: time="2026-01-28T16:07:08+07:00" level=debug msg="app state loaded" Jan 28 16:07:08 volumio go-librespot[14690]: time="2026-01-28T16:07:08+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 16:07:08 volumio volumio[14426]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Jan 28 16:07:08 volumio volumio[14426]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 16:07:08 volumio volumio[14426]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 16:07:08 volumio volumio[14426]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 16:07:08 volumio volumio[14426]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 16:07:08 volumio volumio[14426]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 16:07:08 volumio volumio[14426]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 16:07:08 volumio volumio[14426]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 16:07:08 volumio volumio[14426]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 16:07:08 volumio volumio[14426]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 16:07:08 volumio volumio[14426]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 16:07:08 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 16:07:08 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 16:07:08 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 16:07:08 volumio volumio[14426]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 16:07:08 volumio volumio[14426]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 16:07:08 volumio volumio[14426]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 16:07:08 volumio volumio[14426]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 16:07:08 volumio volumio[14426]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 16:07:08 volumio volumio[14426]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 16:07:08 volumio volumio[14426]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 16:07:08 volumio volumio[14426]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 16:07:08 volumio volumio[14426]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 16:07:08 volumio volumio[14426]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 16:07:08 volumio volumio[14426]: info: No need to fix Spotify hosts Jan 28 16:07:09 volumio go-librespot[14690]: time="2026-01-28T16:07:09+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 16:07:09 volumio go-librespot[14690]: time="2026-01-28T16:07:09+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 28 16:07:09 volumio go-librespot[14690]: time="2026-01-28T16:07:09+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 28 16:07:09 volumio go-librespot[14690]: time="2026-01-28T16:07:09+07:00" level=info msg="zeroconf server listening on port 37235" Jan 28 16:07:09 volumio go-librespot[14690]: time="2026-01-28T16:07:09+07:00" level=debug msg="obtained new client token: AACawg4sk6vtfYwm0saGSbO1O36qXrCIa9KN2cQOlCR0Qg5ES64uKJAp8E9ETk/t0oDl8/hFa0KfRcEUWm9HSZTwN2Bpa/6iYpM51mQedaZkcjNFIrymI9UOjtR9LCAypr2MGrf3/zU8w1ak7DghnT/x330yj3LPPUXTTHhjuM/EQ0ywyftDUkqf3uEuDrQzujKjzp0yPoMIJ9xWKGRhIdjkOs1EeYrUwOFErfXTzFBcdoAM5TsfvT5ksvQ=" Jan 28 16:07:09 volumio volumio[14426]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 28 16:07:09 volumio volumio[14426]: SPOTIFY: BQDX7G6R3jfK9AJZl75lCgk2IWz8TjK-3Z_Fe7Mxb3Q2OFvfB2gfrCnlQm8M882g-1d2_TW3ageyCk1OxlNwvnClSHxmPQbmYgAxgVROzh8Bmtkss06Jl1ft5OHQAdLKtId1ORVKS5pC060-gmlnktrx8CIFVDcs6DycnP62dn5kuXUt3TI8fK7EKAV_D3mrBOo5F3Z_n7NhomnbWGkBo_CJEhCZsxeobStK3V66fOOnk6-vLG6_8BsnqJhz1diszyZeUI527we2zpZ7brYDPtFKdSb6w9ntPSp3DZIfeZbErVyilYJVDFXj Jan 28 16:07:09 volumio volumio[14426]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 28 16:07:09 volumio volumio[14426]: info: New Spotify access token = BQDX7G6R3jfK9AJZl75lCgk2IWz8TjK-3Z_Fe7Mxb3Q2OFvfB2gfrCnlQm8M882g-1d2_TW3ageyCk1OxlNwvnClSHxmPQbmYgAxgVROzh8Bmtkss06Jl1ft5OHQAdLKtId1ORVKS5pC060-gmlnktrx8CIFVDcs6DycnP62dn5kuXUt3TI8fK7EKAV_D3mrBOo5F3Z_n7NhomnbWGkBo_CJEhCZsxeobStK3V66fOOnk6-vLG6_8BsnqJhz1diszyZeUI527we2zpZ7brYDPtFKdSb6w9ntPSp3DZIfeZbErVyilYJVDFXj Jan 28 16:07:09 volumio volumio[14426]: info: Spotify credentials grant success - running version from March 24, 2019 Jan 28 16:07:09 volumio volumio[14426]: info: Starting Shairport Sync Jan 28 16:07:09 volumio volumio[14426]: info: Starting Shairport Sync Jan 28 16:07:09 volumio go-librespot[14690]: time="2026-01-28T16:07:09+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 16:07:09 volumio volumio[14426]: info: Starting Shairport Sync Jan 28 16:07:09 volumio sudo[14709]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 28 16:07:09 volumio sudo[14709]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 16:07:09 volumio go-librespot[14690]: time="2026-01-28T16:07:09+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Jan 28 16:07:09 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 16:07:09 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 16:07:09 volumio sudo[14711]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 28 16:07:09 volumio sudo[14711]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 16:07:09 volumio sudo[14713]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 28 16:07:09 volumio sudo[14713]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 16:07:09 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 28 16:07:09 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Jan 28 16:07:09 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 28 16:07:09 volumio systemd[1]: shairport-sync.service: Consumed 2.345s CPU time. Jan 28 16:07:09 volumio volumio[14426]: info: CoreCommandRouter::volumioGetState Jan 28 16:07:09 volumio volumio[14426]: info: CorePlayQueue::getTrack 0 Jan 28 16:07:09 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 28 16:07:09 volumio sudo[14709]: pam_unix(sudo:session): session closed for user root Jan 28 16:07:09 volumio sudo[14711]: pam_unix(sudo:session): session closed for user root Jan 28 16:07:09 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 28 16:07:09 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Jan 28 16:07:09 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 28 16:07:10 volumio volumio[14426]: info: Shairport-Sync Started Jan 28 16:07:10 volumio volumio[14426]: Error adding Membership: Error: addMembership EINVAL Jan 28 16:07:10 volumio volumio[14426]: info: Shairport-Sync Started Jan 28 16:07:10 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 28 16:07:10 volumio sudo[14713]: pam_unix(sudo:session): session closed for user root Jan 28 16:07:10 volumio volumio[14426]: info: Shairport-Sync Started Jan 28 16:07:10 volumio volumio[14426]: SPOTIFY: User informations: {"country":"PK","display_name":"215mmgea6kss3jxeqsqdquvji","email":"linh.ngotran@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/215mmgea6kss3jxeqsqdquvji"},"followers":{"href":null,"total":1},"href":"https://api.spotify.com/v1/users/215mmgea6kss3jxeqsqdquvji","id":"215mmgea6kss3jxeqsqdquvji","images":[],"product":"premium","type":"user","uri":"spotify:user:215mmgea6kss3jxeqsqdquvji"} Jan 28 16:07:10 volumio volumio[14426]: info: Spotify Successfully logged in Jan 28 16:07:10 volumio volumio[14426]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 16:07:10 volumio volumio[14426]: info: [1769591230209] CoreMusicLibrary::Adding element Spotify Jan 28 16:07:10 volumio volumio[14426]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 16:07:10 volumio volumio[14426]: Cannot find translation for source YouTube Music Jan 28 16:07:10 volumio volumio[14426]: Cannot find translation for source Spotify Jan 28 16:07:10 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 16:07:10 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 16:07:10 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 16:07:10 volumio volumio[14426]: info: [yt-cast-receiver] DIAL server listening on port 8098 Jan 28 16:07:10 volumio volumio[14426]: info: CoreCommandRouter::volumioRetrievevolume Jan 28 16:07:11 volumio volumio[14426]: info: VolumeController:: Volume=100 Mute =false Jan 28 16:07:11 volumio volumio[14426]: info: CoreCommandRouter::volumioGetState Jan 28 16:07:11 volumio volumio[14426]: info: CorePlayQueue::getTrack 0 Jan 28 16:07:11 volumio volumio[14426]: info: CoreStateMachine::pushState Jan 28 16:07:11 volumio volumio[14426]: info: CorePlayQueue::getTrack 0 Jan 28 16:07:11 volumio volumio[14426]: info: CoreCommandRouter::volumioPushState Jan 28 16:07:12 volumio volumio[14426]: info: go-librespot daemon successfully initialized Jan 28 16:07:12 volumio mpd[14651]: 2026-01-28T16:07:12 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 28 16:07:12 volumio systemd[1]: Started mpd.service - Music Player Daemon. Jan 28 16:07:12 volumio sudo[14611]: pam_unix(sudo:session): session closed for user root Jan 28 16:07:12 volumio sudo[14622]: pam_unix(sudo:session): session closed for user root Jan 28 16:07:12 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Jan 28 16:07:12 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 16:07:12 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 16:07:12 volumio go-librespot[14754]: go-librespot daemon starting... Jan 28 16:07:12 volumio volumio[14426]: error: MPD error: The expression evaluated to a falsy value: Jan 28 16:07:12 volumio volumio[14426]: assert.ok(self.idling) Jan 28 16:07:12 volumio volumio[14426]: error: The expression evaluated to a falsy value: Jan 28 16:07:12 volumio volumio[14426]: assert.ok(self.idling) Jan 28 16:07:12 volumio go-librespot[14755]: time="2026-01-28T16:07:12+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 16:07:12 volumio go-librespot[14755]: time="2026-01-28T16:07:12+07:00" level=debug msg="app state loaded" Jan 28 16:07:12 volumio go-librespot[14755]: time="2026-01-28T16:07:12+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 16:07:12 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 16:07:12 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 16:07:12 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 16:07:12 volumio volumio[14426]: info: Completed starting Core Plugins Jan 28 16:07:12 volumio volumio[14426]: info: ------------------------------------------- Jan 28 16:07:12 volumio volumio[14426]: info: ----- MyVolumio plugins startup ---- Jan 28 16:07:12 volumio volumio[14426]: info: ------------------------------------------- Jan 28 16:07:12 volumio volumio[14426]: info: [MyVolumio PluginManager] Fetching plans data.... Jan 28 16:07:12 volumio volumio[14426]: info: MPD running with PID14651 Jan 28 16:07:12 volumio volumio[14426]: ,establishing connection Jan 28 16:07:12 volumio volumio[14426]: error: updateQueue error: null Jan 28 16:07:12 volumio volumio[14426]: error: updateQueue error: null Jan 28 16:07:13 volumio go-librespot[14755]: time="2026-01-28T16:07:13+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 28 16:07:13 volumio go-librespot[14755]: time="2026-01-28T16:07:13+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Jan 28 16:07:13 volumio go-librespot[14755]: time="2026-01-28T16:07:13+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Jan 28 16:07:13 volumio go-librespot[14755]: time="2026-01-28T16:07:13+07:00" level=info msg="zeroconf server listening on port 36923" Jan 28 16:07:13 volumio go-librespot[14755]: time="2026-01-28T16:07:13+07:00" level=debug msg="obtained new client token: AAAAfcZlxPjItFLpBdbIggqUKn47gAO2A9r/fpzYW9JlhgpS8gqfwD8tW1BB0niyGeOQzJeUJEbvsbrfkN19EIe4YMKwwBCRyW0nWTPdmtPhnImXLb5EBmoOeOQcsvqdiN/xK72c44G0wFVFZSyZQ5sHet3luAEyA8I84slMo+egIzwhpqWO8VBM/k6O8XfDs/wYx616SZc0KA9ZJ9784iys4DY9q6EYeyRHaELegWgod0xctagzR616uRM=" Jan 28 16:07:13 volumio go-librespot[14755]: time="2026-01-28T16:07:13+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 16:07:13 volumio go-librespot[14755]: time="2026-01-28T16:07:13+07:00" level=debug msg="completed keyexchange" Jan 28 16:07:13 volumio go-librespot[14755]: time="2026-01-28T16:07:13+07:00" level=debug msg="completed challenge" Jan 28 16:07:14 volumio go-librespot[14755]: time="2026-01-28T16:07:14+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 16:07:14 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 16:07:14 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 16:07:14 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 16:07:14 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 16:07:14 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 16:07:15 volumio volumio[14426]: info: Initializing connection to go-librespot Websocket Jan 28 16:07:15 volumio volumio[14426]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 28 16:07:16 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 16:07:16 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 16:07:16 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 16:07:17 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Jan 28 16:07:17 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 16:07:17 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 16:07:17 volumio go-librespot[14763]: go-librespot daemon starting... Jan 28 16:07:17 volumio go-librespot[14764]: time="2026-01-28T16:07:17+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 16:07:17 volumio go-librespot[14764]: time="2026-01-28T16:07:17+07:00" level=debug msg="app state loaded" Jan 28 16:07:17 volumio go-librespot[14764]: time="2026-01-28T16:07:17+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 16:07:17 volumio volumio[14426]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Jan 28 16:07:17 volumio go-librespot[14764]: time="2026-01-28T16:07: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 28 16:07:17 volumio go-librespot[14764]: time="2026-01-28T16:07: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 28 16:07:17 volumio go-librespot[14764]: time="2026-01-28T16:07: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 28 16:07:17 volumio go-librespot[14764]: time="2026-01-28T16:07:17+07:00" level=info msg="zeroconf server listening on port 36145" Jan 28 16:07:18 volumio go-librespot[14764]: time="2026-01-28T16:07:18+07:00" level=debug msg="obtained new client token: AAC+tbGrF2uMaD07KFAoyWZKzerXFbPcP2icTcqxG/mkoFAgcq1OinapRfsgZK0ziu1Bg81gsev1zRxkJH8FZRohgQKx1HkhaFim1kqx2y856FmCW6lfvV+QmjeONjL7raCgoV3iFsNU/xfS7vVVycdBvgoa0GELxYVQ6hyuWVayKi262u8sBfi6ArmkQDAwGLX/5y44PLNh1d5nJLbrWvwJAYFnIURHfV4xjf2OrAHTXDU1yVWwBC2Q" Jan 28 16:07:18 volumio go-librespot[14764]: time="2026-01-28T16:07:18+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 16:07:18 volumio go-librespot[14764]: time="2026-01-28T16:07:18+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Jan 28 16:07:18 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 16:07:18 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 16:07:18 volumio volumio[14426]: info: Initializing connection to go-librespot Websocket Jan 28 16:07:18 volumio volumio[14426]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 28 16:07:18 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 16:07:18 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 16:07:18 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 16:07:20 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 16:07:20 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 16:07:20 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 16:07:21 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Jan 28 16:07:21 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 16:07:21 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 16:07:21 volumio go-librespot[14771]: go-librespot daemon starting... Jan 28 16:07:21 volumio go-librespot[14772]: time="2026-01-28T16:07:21+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 16:07:21 volumio go-librespot[14772]: time="2026-01-28T16:07:21+07:00" level=debug msg="app state loaded" Jan 28 16:07:21 volumio go-librespot[14772]: time="2026-01-28T16:07:21+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 16:07:21 volumio volumio[14426]: info: Initializing connection to go-librespot Websocket Jan 28 16:07:21 volumio go-librespot[14772]: time="2026-01-28T16:07:21+07:00" level=debug msg="new websocket client" Jan 28 16:07:21 volumio volumio[14426]: info: Connection to go-librespot Websocket established Jan 28 16:07:21 volumio volumio[14426]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Jan 28 16:07:21 volumio volumio[14426]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Jan 28 16:07:21 volumio volumio[14426]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Jan 28 16:07:21 volumio volumio[14426]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Jan 28 16:07:21 volumio volumio[14426]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Jan 28 16:07:21 volumio volumio[14426]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Jan 28 16:07:21 volumio volumio[14426]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Jan 28 16:07:21 volumio volumio[14426]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Jan 28 16:07:21 volumio volumio[14426]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Jan 28 16:07:21 volumio volumio[14426]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Jan 28 16:07:21 volumio volumio[14426]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Jan 28 16:07:21 volumio volumio[14426]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Jan 28 16:07:21 volumio volumio[14426]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Jan 28 16:07:21 volumio volumio[14426]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Jan 28 16:07:21 volumio volumio[14426]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Jan 28 16:07:21 volumio volumio[14426]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Jan 28 16:07:21 volumio volumio[14426]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Jan 28 16:07:21 volumio volumio[14426]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Jan 28 16:07:21 volumio volumio[14426]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Jan 28 16:07:21 volumio volumio[14426]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Jan 28 16:07:21 volumio volumio[14426]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Jan 28 16:07:21 volumio volumio[14426]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Jan 28 16:07:21 volumio volumio[14426]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Jan 28 16:07:21 volumio volumio[14426]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Jan 28 16:07:21 volumio volumio[14426]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Jan 28 16:07:21 volumio volumio[14426]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Jan 28 16:07:21 volumio volumio[14426]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Jan 28 16:07:21 volumio volumio[14426]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Jan 28 16:07:21 volumio volumio[14426]: info: Adding plugin bluetooth to MyMusic Plugins Jan 28 16:07:21 volumio volumio[14426]: info: Adding plugin multiroom to MyMusic Plugins Jan 28 16:07:21 volumio volumio[14426]: info: Adding plugin metavolumio to MyMusic Plugins Jan 28 16:07:21 volumio volumio[14426]: info: Adding plugin cd_controller to MyMusic Plugins Jan 28 16:07:21 volumio volumio[14426]: info: Adding plugin qobuzconnect to MyMusic Plugins Jan 28 16:07:21 volumio volumio[14426]: info: Adding plugin smart_inputs to MyMusic Plugins Jan 28 16:07:21 volumio volumio[14426]: info: Adding plugin tidalconnect to MyMusic Plugins Jan 28 16:07:21 volumio volumio[14426]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Jan 28 16:07:21 volumio go-librespot[14772]: time="2026-01-28T16:07:21+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 16:07:21 volumio go-librespot[14772]: time="2026-01-28T16:07:21+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 28 16:07:21 volumio go-librespot[14772]: time="2026-01-28T16:07:21+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 28 16:07:21 volumio go-librespot[14772]: time="2026-01-28T16:07:21+07:00" level=info msg="zeroconf server listening on port 41389" Jan 28 16:07:22 volumio go-librespot[14772]: time="2026-01-28T16:07:22+07:00" level=debug msg="obtained new client token: AADdI1ou6NQDl3sKYsYf1ZFNmqs+RFR4I4xI1PbPOEgmncXBY7KOpdlXfzVZSEO6BBd2u42WWVPY5HePn4BrFUePGWxyhd49IjImBOrJw3E22DeapHT18Z7PPpPVU8IxgbrhOgnNxmmkEvzN2axmd6J1hsDGKdrHqqz9mvv/Wo98eXl3ToSJKgNJKBSl61QBKL6ItfsrHXeswuVvIt30Ggqark9maixEadudajxRQsRDxdEubmK2r4TR" Jan 28 16:07:22 volumio go-librespot[14772]: time="2026-01-28T16:07:22+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 16:07:22 volumio go-librespot[14772]: time="2026-01-28T16:07:22+07:00" level=debug msg="completed keyexchange" Jan 28 16:07:22 volumio go-librespot[14772]: time="2026-01-28T16:07:22+07:00" level=debug msg="completed challenge" Jan 28 16:07:22 volumio go-librespot[14772]: time="2026-01-28T16:07:22+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 16:07:22 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 16:07:22 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 16:07:22 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 16:07:22 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 16:07:22 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 16:07:23 volumio volumio[14426]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Jan 28 16:07:23 volumio volumio[14426]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Jan 28 16:07:23 volumio volumio[14426]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 16:07:23 volumio volumio[14426]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 16:07:23 volumio volumio[14426]: info: Starting MyVolumio Remote Streaming Endpoints Jan 28 16:07:23 volumio volumio[14426]: info: MyVolumio login type: Token Jan 28 16:07:23 volumio volumio[14426]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Jan 28 16:07:23 volumio volumio[14426]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Jan 28 16:07:24 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 16:07:24 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 16:07:24 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 16:07:25 volumio volumio[14426]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Jan 28 16:07:25 volumio volumio[14426]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Jan 28 16:07:25 volumio volumio[14426]: info: Streaming services startup Jan 28 16:07:25 volumio volumio[14426]: info: Starting Streaming Daemon Jan 28 16:07:25 volumio sudo[14795]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jan 28 16:07:25 volumio sudo[14795]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 16:07:25 volumio volumio[14426]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Jan 28 16:07:25 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Jan 28 16:07:25 volumio sudo[14795]: pam_unix(sudo:session): session closed for user root Jan 28 16:07:25 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 16:07:25 volumio volumio[14426]: info: Getting Spotify volume Jan 28 16:07:25 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 16:07:25 volumio go-librespot[14801]: go-librespot daemon starting... Jan 28 16:07:25 volumio volumio[14426]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 28 16:07:25 volumio volumio[14426]: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 28 16:07:25 volumio volumio[14426]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Jan 28 16:07:25 volumio volumio[14426]: errno: -111, Jan 28 16:07:25 volumio volumio[14426]: code: 'ECONNREFUSED', Jan 28 16:07:25 volumio volumio[14426]: syscall: 'connect', Jan 28 16:07:25 volumio volumio[14426]: address: '127.0.0.1', Jan 28 16:07:25 volumio volumio[14426]: port: 9879, Jan 28 16:07:25 volumio volumio[14426]: response: undefined Jan 28 16:07:25 volumio volumio[14426]: } Jan 28 16:07:25 volumio volumio[14426]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 28 16:07:25 volumio go-librespot[14802]: time="2026-01-28T16:07:25+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 16:07:25 volumio go-librespot[14802]: time="2026-01-28T16:07:25+07:00" level=debug msg="app state loaded" Jan 28 16:07:25 volumio go-librespot[14802]: time="2026-01-28T16:07:25+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 16:07:26 volumio go-librespot[14802]: time="2026-01-28T16:07: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 28 16:07:26 volumio go-librespot[14802]: time="2026-01-28T16:07: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 28 16:07:26 volumio go-librespot[14802]: time="2026-01-28T16:07: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 28 16:07:26 volumio go-librespot[14802]: time="2026-01-28T16:07:26+07:00" level=info msg="zeroconf server listening on port 35771" Jan 28 16:07:26 volumio go-librespot[14802]: time="2026-01-28T16:07:26+07:00" level=debug msg="obtained new client token: AABYBey9qy8Onn0c4JNKuOPQOentWr3h/oEpEjrUhmiv3d6cI83WGFvn+mQIkbziZBHBbRpXC4frJuxBqKBh2rtPfR+QLa0ha/uZVDgPGD6h3lpvJuHLIJ5CIEZVCMh2VUH6y0lg0BbZyziDM18LJpa7DOTL2Vv8AxTVF9HQCLbGLej+31NXiVlFZ+UZB0QpndnwF24JZQOnuHQqItzECuJZVNsC/etlbRcJfShg7IdQAwAzpLteY0OeN3M=" Jan 28 16:07:26 volumio go-librespot[14802]: time="2026-01-28T16:07:26+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 16:07:26 volumio go-librespot[14802]: time="2026-01-28T16:07:26+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Jan 28 16:07:26 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 16:07:26 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 16:07:26 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 16:07:26 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 16:07:26 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 16:07:27 volumio sudo[14823]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-01-28 16:06' Jan 28 16:07:27 volumio sudo[14823]: 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"