Jan 25 21:42:00 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Jan 25 21:42:00 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 25 21:42:00 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 25 21:42:00 volumio go-librespot[31418]: go-librespot daemon starting... Jan 25 21:42:00 volumio go-librespot[31419]: time="2026-01-25T21:42:00+07:00" level=info msg="running go-librespot 0.4.0" Jan 25 21:42:00 volumio go-librespot[31419]: time="2026-01-25T21:42:00+07:00" level=debug msg="app state loaded" Jan 25 21:42:00 volumio go-librespot[31419]: time="2026-01-25T21:42:00+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 25 21:42:00 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 25 21:42:00 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 25 21:42:00 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 25 21:42:01 volumio go-librespot[31419]: time="2026-01-25T21:42: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 25 21:42:01 volumio go-librespot[31419]: time="2026-01-25T21:42: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 25 21:42:01 volumio go-librespot[31419]: time="2026-01-25T21:42: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 25 21:42:01 volumio go-librespot[31419]: time="2026-01-25T21:42:01+07:00" level=info msg="zeroconf server listening on port 38749" Jan 25 21:42:01 volumio go-librespot[31419]: time="2026-01-25T21:42:01+07:00" level=debug msg="obtained new client token: AAA3VCqq7Ylr1q35pNGvG1JKNvJTG49hSFAE9ml9IwRFhhourttR/jptPWFYmiLRVbbHcTkNW7ITUhbSzxLkOuk54zEeQ7/oYlV5AUdvAX4ua7oNenrLMA0bvb9ZP0wYHjz/CFoXvxLwHZhQJ6Bam3j09HRV+Wx+a6tc59CIZnRXwt+HoQ+Qna0tHFFHM23I9IOmydMCX1LlnctVmMveyiUFYfn4HKd9tHXzgZCs+O0r2L023yUVnyxklv8=" Jan 25 21:42:01 volumio go-librespot[31419]: time="2026-01-25T21:42:01+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 25 21:42:01 volumio go-librespot[31419]: time="2026-01-25T21:42:01+07:00" level=debug msg="completed keyexchange" Jan 25 21:42:01 volumio go-librespot[31419]: time="2026-01-25T21:42:01+07:00" level=debug msg="completed challenge" Jan 25 21:42:01 volumio go-librespot[31419]: time="2026-01-25T21:42:01+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 25 21:42:01 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 25 21:42:01 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 25 21:42:02 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 25 21:42:02 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 25 21:42:02 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 25 21:42:03 volumio volumio[31402]: info: ------------------------------------------- Jan 25 21:42:03 volumio volumio[31402]: info: ----- Volumio3 ---- Jan 25 21:42:03 volumio volumio[31402]: info: ------------------------------------------- Jan 25 21:42:03 volumio volumio[31402]: info: ----- System startup ---- Jan 25 21:42:03 volumio volumio[31402]: info: ------------------------------------------- Jan 25 21:42:04 volumio volumio-remote-updater[628]: [2026-01-25 21:42:04] [connect] Successful connection Jan 25 21:42:04 volumio volumio[31402]: info: MYVOLUMIO Environment detected Jan 25 21:42:04 volumio volumio[31402]: info: Plugin folders cleanup Jan 25 21:42:04 volumio volumio[31402]: info: Scanning into folder /volumio/app/plugins/ Jan 25 21:42:04 volumio volumio[31402]: info: Scanning category audio_interface Jan 25 21:42:04 volumio volumio[31402]: info: Scanning category miscellanea Jan 25 21:42:04 volumio volumio[31402]: info: Scanning category music_service Jan 25 21:42:04 volumio volumio[31402]: info: Scanning category plugins.json Jan 25 21:42:04 volumio volumio[31402]: info: Scanning category system_controller Jan 25 21:42:04 volumio volumio[31402]: info: Scanning category user_interface Jan 25 21:42:04 volumio volumio[31402]: info: Scanning into folder /data/plugins/ Jan 25 21:42:04 volumio volumio[31402]: info: Scanning category music_service Jan 25 21:42:04 volumio volumio[31402]: info: Plugin folders cleanup completed Jan 25 21:42:04 volumio volumio[31402]: info: ------------------------------------------- Jan 25 21:42:04 volumio volumio[31402]: info: ----- Core plugins startup ---- Jan 25 21:42:04 volumio volumio[31402]: info: ------------------------------------------- Jan 25 21:42:04 volumio volumio[31402]: info: Loading plugins from folder /volumio/app/plugins/ Jan 25 21:42:04 volumio volumio[31402]: info: Adding plugin upnp to MyMusic Plugins Jan 25 21:42:04 volumio volumio[31402]: info: Adding plugin airplay_emulation to MyMusic Plugins Jan 25 21:42:04 volumio volumio[31402]: info: Adding plugin upnp_browser to MyMusic Plugins Jan 25 21:42:04 volumio volumio[31402]: info: Loading plugins from folder /data/plugins/ Jan 25 21:42:04 volumio volumio[31402]: info: Loading plugin "system"... Jan 25 21:42:04 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 25 21:42:04 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 25 21:42:04 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 25 21:42:04 volumio volumio[31402]: info: Loading plugin "appearance"... Jan 25 21:42:04 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Jan 25 21:42:04 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 25 21:42:05 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 25 21:42:05 volumio go-librespot[31439]: go-librespot daemon starting... Jan 25 21:42:05 volumio go-librespot[31440]: time="2026-01-25T21:42:05+07:00" level=info msg="running go-librespot 0.4.0" Jan 25 21:42:05 volumio go-librespot[31440]: time="2026-01-25T21:42:05+07:00" level=debug msg="app state loaded" Jan 25 21:42:05 volumio go-librespot[31440]: time="2026-01-25T21:42:05+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 25 21:42:05 volumio go-librespot[31440]: time="2026-01-25T21:42:05+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 25 21:42:05 volumio go-librespot[31440]: time="2026-01-25T21:42:05+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 25 21:42:05 volumio go-librespot[31440]: time="2026-01-25T21:42:05+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 25 21:42:05 volumio go-librespot[31440]: time="2026-01-25T21:42:05+07:00" level=info msg="zeroconf server listening on port 41465" Jan 25 21:42:05 volumio go-librespot[31440]: time="2026-01-25T21:42:05+07:00" level=debug msg="obtained new client token: AABiWISgIzZDO1Ssn3eebmcmC6RPuLIJrIhFQvUg+FycCVz5ar6hRdM3lq0WNNHERamQopV4428I2O1ZCUuYklEpgJFPrZwR46ftdM17Ub6HwJPZdtmv/9xtaVPzL7MhkK4YLiIHUr6//KEBnkzjvKH4S3VwG5aElDScDdjrwUE4pcTU7Nc2qUwHXvQbO/tYlFGNK/odYP/+osj0Vt+lNGdivcOImJ1qUgA9U5Sxs84rpE2AJh/G9tn+j6Y=" Jan 25 21:42:05 volumio go-librespot[31440]: time="2026-01-25T21:42:05+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 25 21:42:06 volumio go-librespot[31440]: time="2026-01-25T21:42:06+07:00" level=debug msg="completed keyexchange" Jan 25 21:42:06 volumio go-librespot[31440]: time="2026-01-25T21:42:06+07:00" level=debug msg="completed challenge" Jan 25 21:42:06 volumio go-librespot[31440]: time="2026-01-25T21:42: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 25 21:42:06 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 25 21:42:06 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 25 21:42:06 volumio volumio[31402]: info: Loading plugin "network"... Jan 25 21:42:06 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 25 21:42:06 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 25 21:42:06 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 25 21:42:06 volumio volumio[31402]: info: Refreshing Cached IP Addresses Jan 25 21:42:06 volumio sudo[31448]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 25 21:42:06 volumio sudo[31448]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 21:42:06 volumio volumio[31402]: info: Loading plugin "services"... Jan 25 21:42:06 volumio sudo[31450]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 25 21:42:06 volumio sudo[31450]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 21:42:06 volumio volumio[31402]: info: Loading plugin "alsa_controller"... Jan 25 21:42:06 volumio sudo[31448]: pam_unix(sudo:session): session closed for user root Jan 25 21:42:07 volumio sudo[31450]: pam_unix(sudo:session): session closed for user root Jan 25 21:42:07 volumio sudo[31458]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Jan 25 21:42:07 volumio sudo[31458]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 21:42:07 volumio volumio[31402]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 25 21:42:07 volumio volumio[31402]: info: Loading plugin "wizard"... Jan 25 21:42:07 volumio volumio[31402]: info: Loading plugin "networkfs"... Jan 25 21:42:07 volumio volumio[31402]: info: Starting Udev Watcher for removable devices Jan 25 21:42:07 volumio volumio[31402]: info: Ignoring mount for partition: boot Jan 25 21:42:07 volumio volumio[31402]: info: Ignoring mount for partition: volumio Jan 25 21:42:07 volumio volumio[31402]: info: Ignoring mount for partition: volumio_data Jan 25 21:42:07 volumio volumio[31402]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 25 21:42:07 volumio volumio[31402]: info: Loading plugin "volumio_command_line_client"... Jan 25 21:42:07 volumio volumio[31402]: info: Loading plugin "upnp"... Jan 25 21:42:07 volumio volumio[31402]: info: [1769352127307] Starting Upmpd Daemon Jan 25 21:42:07 volumio volumio[31402]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 25 21:42:07 volumio volumio[31402]: info: Loading plugin "my_music"... Jan 25 21:42:07 volumio volumio[31402]: info: Loading plugin "mpd"... Jan 25 21:42:07 volumio volumio[31402]: info: Loading plugin "upnp_browser"... Jan 25 21:42:08 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 25 21:42:08 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 25 21:42:08 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 25 21:42:09 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Jan 25 21:42:09 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 25 21:42:09 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 25 21:42:09 volumio go-librespot[31481]: go-librespot daemon starting... Jan 25 21:42:09 volumio go-librespot[31482]: time="2026-01-25T21:42:09+07:00" level=info msg="running go-librespot 0.4.0" Jan 25 21:42:09 volumio go-librespot[31482]: time="2026-01-25T21:42:09+07:00" level=debug msg="app state loaded" Jan 25 21:42:09 volumio go-librespot[31482]: time="2026-01-25T21:42:09+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 25 21:42:09 volumio go-librespot[31482]: time="2026-01-25T21:42:09+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 25 21:42:09 volumio go-librespot[31482]: time="2026-01-25T21:42:09+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 25 21:42:09 volumio go-librespot[31482]: time="2026-01-25T21:42:09+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 25 21:42:09 volumio go-librespot[31482]: time="2026-01-25T21:42:09+07:00" level=info msg="zeroconf server listening on port 33869" Jan 25 21:42:09 volumio sudo[31458]: pam_unix(sudo:session): session closed for user root Jan 25 21:42:10 volumio go-librespot[31482]: time="2026-01-25T21:42:10+07:00" level=debug msg="obtained new client token: AAAk/cVuxH5U6wfCTvF2LElTh8Qsv5jwGXyeKWerh8MPLqR/qDer6sU2w6Dkpqdcza7wWfYgsJH2wuRcGdCQrfhXj5sdZynZ/Syb+p0XiVmt06andi0skKsujpUoq2JRWcMlhw64RXpi52yHIhNJyivES3JzzekKUPbL6HnK7fzLPbbr93F+P4lM5eoAcCOCWiSeHO1fpHs+vNhVgnnn0UdOGe77zQMfiVggTYQV7FmcbDTPBdWF1N9F" Jan 25 21:42:10 volumio go-librespot[31482]: time="2026-01-25T21:42:10+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 25 21:42:10 volumio go-librespot[31482]: time="2026-01-25T21:42: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 25 21:42:10 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 25 21:42:10 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 25 21:42:10 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 25 21:42:10 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 25 21:42:10 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 25 21:42:10 volumio volumio[31402]: info: Starting UPNP Browser Jan 25 21:42:10 volumio volumio[31402]: info: Loading plugin "alarm-clock"... Jan 25 21:42:11 volumio volumio[31402]: info: Loading plugin "airplay_emulation"... Jan 25 21:42:11 volumio volumio[31402]: info: Starting Shairport Sync Jan 25 21:42:11 volumio volumio[31402]: info: Loading plugin "last_100"... Jan 25 21:42:11 volumio volumio[31402]: info: Loading plugin "webradio"... Jan 25 21:42:11 volumio volumio[31402]: info: Loading plugin "i2s_dacs"... Jan 25 21:42:11 volumio volumio[31402]: info: Loading plugin "volumiodiscovery"... Jan 25 21:42:11 volumio volumio[31402]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 25 21:42:11 volumio volumio[31402]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 25 21:42:11 volumio node[31402]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 25 21:42:11 volumio volumio[31402]: *** WARNING *** For more information see Jan 25 21:42:11 volumio volumio[31402]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 25 21:42:11 volumio volumio[31402]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 25 21:42:11 volumio volumio[31402]: *** WARNING *** For more information see Jan 25 21:42:11 volumio node[31402]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 25 21:42:11 volumio node[31402]: *** WARNING *** For more information see Jan 25 21:42:11 volumio node[31402]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 25 21:42:11 volumio node[31402]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 25 21:42:11 volumio node[31402]: *** WARNING *** For more information see Jan 25 21:42:11 volumio volumio[31402]: info: Applying required configuration parameters for plugin volumiodiscovery Jan 25 21:42:11 volumio volumio[31402]: info: Discovery: Started advertising with name: Volumio Jan 25 21:42:11 volumio volumio[31402]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 25 21:42:11 volumio volumio[31402]: info: Loading plugin "spop"... Jan 25 21:42:12 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 25 21:42:12 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 25 21:42:12 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 25 21:42:13 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Jan 25 21:42:13 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 25 21:42:13 volumio volumio[31402]: info: Loading plugin "ytcr"... Jan 25 21:42:13 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 25 21:42:13 volumio go-librespot[31491]: go-librespot daemon starting... Jan 25 21:42:13 volumio go-librespot[31492]: time="2026-01-25T21:42:13+07:00" level=info msg="running go-librespot 0.4.0" Jan 25 21:42:13 volumio go-librespot[31492]: time="2026-01-25T21:42:13+07:00" level=debug msg="app state loaded" Jan 25 21:42:13 volumio go-librespot[31492]: time="2026-01-25T21:42:13+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 25 21:42:14 volumio go-librespot[31492]: time="2026-01-25T21:42: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 25 21:42:14 volumio go-librespot[31492]: time="2026-01-25T21:42:14+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 25 21:42:14 volumio go-librespot[31492]: time="2026-01-25T21:42:14+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 25 21:42:14 volumio go-librespot[31492]: time="2026-01-25T21:42:14+07:00" level=info msg="zeroconf server listening on port 40201" Jan 25 21:42:14 volumio go-librespot[31492]: time="2026-01-25T21:42:14+07:00" level=debug msg="obtained new client token: AACMzW4fg4b/xqnFVVORh6dWETusxLb+1O2SgiY89rvVSmr8/vLFqugm3e0S4tRARBLDvlxJ9rGTx2oJiR8gts9em7Ia59DIvi1I7henGDCZzueBa9/D9svoOK9s3qaAerdKenlUxElgxKhshOXlNBJt8q3OkF5DjKw72382gbT+VNaFNLmqrL8SAFAQ1V/fRwbsJh08WGk374PIkXrswHmsx1FfyWA5DU8uRK4DuRe+wKKzQm7xpKDUCho=" Jan 25 21:42:14 volumio go-librespot[31492]: time="2026-01-25T21:42:14+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 25 21:42:14 volumio go-librespot[31492]: time="2026-01-25T21:42:14+07:00" level=debug msg="completed keyexchange" Jan 25 21:42:14 volumio go-librespot[31492]: time="2026-01-25T21:42:14+07:00" level=debug msg="completed challenge" Jan 25 21:42:14 volumio go-librespot[31492]: time="2026-01-25T21:42: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 25 21:42:14 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 25 21:42:14 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 25 21:42:14 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 25 21:42:14 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 25 21:42:14 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 25 21:42:16 volumio volumio[31402]: info: Loading plugin "ytmusic"... Jan 25 21:42:16 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 25 21:42:16 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 25 21:42:16 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 25 21:42:16 volumio volumio-remote-updater[628]: [2026-01-25 21:42:16] [connect] Successful connection Jan 25 21:42:17 volumio volumio[31402]: info: Loading plugin "outputs"... Jan 25 21:42:17 volumio volumio[31402]: info: Loading plugin "albumart"... Jan 25 21:42:17 volumio volumio[31402]: info: Plugin example_plugin is not enabled Jan 25 21:42:17 volumio volumio[31402]: info: Loading plugin "inputs"... Jan 25 21:42:17 volumio volumio[31402]: info: Loading plugin "updater_comm"... Jan 25 21:42:17 volumio volumio[31402]: info: Plugin mpdemulation is not enabled Jan 25 21:42:17 volumio volumio[31402]: info: Loading plugin "rest_api"... Jan 25 21:42:17 volumio volumio[31402]: info: Loading plugin "websocket"... Jan 25 21:42:17 volumio volumio[31402]: info: Starting Socket.io Server version 1.7.4 Jan 25 21:42:17 volumio volumio[31402]: info: Loading plugin "RoonBridge"... Jan 25 21:42:17 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Jan 25 21:42:17 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 25 21:42:17 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 25 21:42:17 volumio go-librespot[31524]: go-librespot daemon starting... Jan 25 21:42:17 volumio go-librespot[31525]: time="2026-01-25T21:42:17+07:00" level=info msg="running go-librespot 0.4.0" Jan 25 21:42:17 volumio go-librespot[31525]: time="2026-01-25T21:42:17+07:00" level=debug msg="app state loaded" Jan 25 21:42:17 volumio go-librespot[31525]: time="2026-01-25T21:42:17+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 25 21:42:18 volumio volumio[31402]: info: Applying required configuration parameters for plugin RoonBridge Jan 25 21:42:18 volumio volumio[31402]: info: Loading i18n strings for locale en Jan 25 21:42:18 volumio volumio[31402]: Updating browse sources language Jan 25 21:42:18 volumio volumio[31402]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 25 21:42:18 volumio go-librespot[31525]: time="2026-01-25T21:42:18+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 25 21:42:18 volumio go-librespot[31525]: time="2026-01-25T21:42:18+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 25 21:42:18 volumio go-librespot[31525]: time="2026-01-25T21:42:18+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 25 21:42:18 volumio go-librespot[31525]: time="2026-01-25T21:42:18+07:00" level=info msg="zeroconf server listening on port 36283" Jan 25 21:42:18 volumio volumio[31402]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 25 21:42:18 volumio volumio[31402]: info: CoreCommandRouter::initPlayerControls Jan 25 21:42:18 volumio volumio[31402]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 21:42:18 volumio volumio[31402]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 21:42:18 volumio volumio[31402]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 21:42:18 volumio volumio[31402]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 21:42:18 volumio volumio[31402]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 21:42:18 volumio volumio[31402]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 21:42:18 volumio volumio[31402]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 21:42:18 volumio volumio[31402]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 21:42:18 volumio volumio[31402]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 25 21:42:18 volumio volumio[31402]: Express server listening on port 3000 Jan 25 21:42:18 volumio volumio[31402]: [Metrics] WebUI: 16s 180.41ms Jan 25 21:42:18 volumio volumio[31402]: info: CoreStateMachine::resetVolumioState Jan 25 21:42:18 volumio volumio[31402]: info: CoreStateMachine::getcurrentVolume Jan 25 21:42:18 volumio volumio[31402]: info: CoreCommandRouter::volumioRetrievevolume Jan 25 21:42:18 volumio volumio[31514]: Forking 3 albumart workers Jan 25 21:42:18 volumio go-librespot[31525]: time="2026-01-25T21:42:18+07:00" level=debug msg="obtained new client token: AADriPaK1likZH/3bPMYWr6OCnkBDbateouSwxq3NHVQo1RHM9aHEFIeBKgUQ5k1mYO7IHzQIyUnv7FtF2Le3mlvXSxQingYqi0AHpn6FC7CBhXaGn3QMClTM7DGkN3QDDDc5lIG3q1Wp+9/wHvYTprvf7OD0ALeXnShk3zhP9Ny2NHFt0p3BKoHI4P+EtLmv/7xLZsYSLKqN6flz/Fga4+IvMWkKXnxQuvhuUt+1vflO2wKIQPXGb1R7wI=" Jan 25 21:42:18 volumio sudo[31542]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 25 21:42:18 volumio sudo[31542]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 21:42:18 volumio volumio[31402]: info: Volumio Network Manager: Network status updated: 1 Jan 25 21:42:18 volumio go-librespot[31525]: time="2026-01-25T21:42:18+07:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:4070, retrying with a different AP" error="dial tcp 104.199.241.202:4070: connect: connection refused" Jan 25 21:42:18 volumio sudo[31542]: pam_unix(sudo:session): session closed for user root Jan 25 21:42:18 volumio sudo[31538]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 25 21:42:18 volumio sudo[31538]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 21:42:18 volumio sudo[31538]: pam_unix(sudo:session): session closed for user root Jan 25 21:42:18 volumio go-librespot[31525]: time="2026-01-25T21:42:18+07:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:443, retrying with a different AP" error="dial tcp 104.199.241.202:443: connect: connection refused" Jan 25 21:42:18 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 25 21:42:18 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 25 21:42:18 volumio go-librespot[31525]: time="2026-01-25T21:42:18+07:00" level=debug msg="connected to ap-gae2.spotify.com:80" Jan 25 21:42:18 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 25 21:42:18 volumio go-librespot[31525]: time="2026-01-25T21:42: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 25 21:42:18 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 25 21:42:18 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 25 21:42:19 volumio volumio-remote-updater[628]: [2026-01-25 21:42:19] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1769352136 101 Jan 25 21:42:19 volumio volumio[31402]: 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 25 21:42:19 volumio volumio[31402]: info: VolumeController:: Volume=100 Mute =false Jan 25 21:42:19 volumio volumio[31402]: info: CoreStateMachine::pushState Jan 25 21:42:19 volumio volumio[31402]: info: CorePlayQueue::getTrack 0 Jan 25 21:42:19 volumio volumio[31402]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 25 21:42:19 volumio volumio[31402]: info: CoreCommandRouter::volumioPushState Jan 25 21:42:19 volumio volumio[31402]: info: CoreStateMachine::updateTrackBlock Jan 25 21:42:19 volumio volumio[31402]: info: CorePlayQueue::getTrackBlock Jan 25 21:42:19 volumio volumio[31402]: info: CoreCommandRouter::volumioRetrievevolume Jan 25 21:42:19 volumio volumio[31402]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 25 21:42:19 volumio volumio[31402]: info: Reloading queue from file Jan 25 21:42:19 volumio volumio[31402]: info: CoreStateMachine::setRepeat null single undefined Jan 25 21:42:19 volumio volumio[31402]: info: CoreStateMachine::pushState Jan 25 21:42:19 volumio volumio[31402]: info: CorePlayQueue::getTrack 0 Jan 25 21:42:19 volumio volumio[31402]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 25 21:42:19 volumio volumio[31402]: info: CoreCommandRouter::volumioPushState Jan 25 21:42:19 volumio volumio[31402]: info: CoreStateMachine::setRandom null Jan 25 21:42:19 volumio volumio[31402]: info: CoreStateMachine::pushState Jan 25 21:42:19 volumio volumio[31402]: info: CorePlayQueue::getTrack 0 Jan 25 21:42:19 volumio volumio[31402]: info: CoreCommandRouter::volumioPushState Jan 25 21:42:19 volumio volumio[31402]: info: Setting Device type: Raspberry PI Jan 25 21:42:19 volumio volumio[31402]: info: Completed loading Core Plugins Jan 25 21:42:19 volumio volumio[31402]: info: Preparing to generate the ALSA configuration file Jan 25 21:42:19 volumio volumio[31402]: info: VolumeController:: Volume=100 Mute =false Jan 25 21:42:19 volumio volumio[31402]: info: CoreStateMachine::pushState Jan 25 21:42:19 volumio volumio[31402]: info: CorePlayQueue::getTrack 0 Jan 25 21:42:19 volumio volumio[31402]: info: CoreCommandRouter::volumioPushState Jan 25 21:42:19 volumio volumio[31402]: info: Asound.conf file unchanged, so no further update is needed Jan 25 21:42:19 volumio volumio[31402]: info: Output device has changed, restarting MPD Jan 25 21:42:19 volumio volumio[31402]: info: Output device has changed, restarting Shairport Sync Jan 25 21:42:19 volumio volumio[31402]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 21:42:19 volumio sudo[31584]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Jan 25 21:42:19 volumio sudo[31584]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 21:42:19 volumio volumio[31402]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 25 21:42:19 volumio volumio[31402]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 25 21:42:19 volumio volumio[31402]: info: ___________ START PLUGINS ___________ Jan 25 21:42:19 volumio volumio[31402]: info: ControllerMpd::onStart: Initializing MPD Jan 25 21:42:19 volumio volumio[31402]: info: Creating MPD Configuration file Jan 25 21:42:19 volumio sudo[31586]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 25 21:42:19 volumio sudo[31586]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 21:42:19 volumio sudo[31588]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 25 21:42:19 volumio sudo[31588]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 21:42:19 volumio sudo[31584]: pam_unix(sudo:session): session closed for user root Jan 25 21:42:19 volumio volumio[31402]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 25 21:42:19 volumio volumio[31402]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 25 21:42:19 volumio sudo[31586]: pam_unix(sudo:session): session closed for user root Jan 25 21:42:19 volumio volumio[31402]: info: [1769352139790] CoreMusicLibrary::Adding element Media Servers Jan 25 21:42:19 volumio volumio[31402]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 25 21:42:19 volumio sudo[31595]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 25 21:42:19 volumio sudo[31595]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 21:42:19 volumio volumio[31402]: info: UPNP Browser: Client initialized successfully Jan 25 21:42:19 volumio sudo[31599]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 25 21:42:19 volumio sudo[31599]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 21:42:19 volumio sudo[31595]: pam_unix(sudo:session): session closed for user root Jan 25 21:42:19 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Jan 25 21:42:19 volumio volumio[31402]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 21:42:19 volumio volumio[31402]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 25 21:42:19 volumio volumio[31402]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 25 21:42:19 volumio volumio[31402]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 21:42:19 volumio volumio[31402]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 25 21:42:20 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 25 21:42:20 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 25 21:42:20 volumio systemd[1]: mpd.service: Consumed 7.352s CPU time. Jan 25 21:42:20 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 25 21:42:20 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 25 21:42:20 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 25 21:42:20 volumio volumio[31402]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 25 21:42:20 volumio volumio[31402]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 25 21:42:20 volumio volumio[31402]: info: [1769352140104] CoreMusicLibrary::Adding element Last_100 Jan 25 21:42:20 volumio volumio[31402]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 25 21:42:20 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 25 21:42:20 volumio volumio[31402]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 25 21:42:20 volumio volumio[31402]: info: [1769352140129] CoreMusicLibrary::Adding element Webradio Jan 25 21:42:20 volumio volumio[31402]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 25 21:42:20 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 25 21:42:20 volumio volumio[31402]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 25 21:42:20 volumio volumio[31402]: info: Initializing BBC Radios Jan 25 21:42:20 volumio volumio[31402]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 25 21:42:20 volumio volumio[31402]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 25 21:42:20 volumio volumio[31402]: info: Creating Spotify config file Jan 25 21:42:20 volumio volumio[31402]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 21:42:20 volumio sudo[31611]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 25 21:42:20 volumio sudo[31611]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jan 25 21:42:20 volumio sudo[31611]: pam_unix(sudo:session): session closed for user root Jan 25 21:42:20 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 25 21:42:20 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 25 21:42:20 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 25 21:42:21 volumio volumio[31402]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 25 21:42:21 volumio volumio[31402]: info: [1769352141487] CoreMusicLibrary::Adding element YouTube Music Jan 25 21:42:21 volumio volumio[31402]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 25 21:42:21 volumio volumio[31402]: Cannot find translation for source YouTube Music Jan 25 21:42:21 volumio volumio[31402]: info: Volumio Calling Home Jan 25 21:42:21 volumio sudo[31628]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Jan 25 21:42:21 volumio sudo[31628]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 21:42:21 volumio sudo[31628]: pam_unix(sudo:session): session closed for user root Jan 25 21:42:21 volumio volumio[31536]: Starting albumart workers Jan 25 21:42:21 volumio volumio[31539]: Starting albumart workers Jan 25 21:42:22 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Jan 25 21:42:22 volumio volumio[31402]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Jan 25 21:42:22 volumio volumio[31402]: info: Discovery: Found device Volumio Jan 25 21:42:22 volumio volumio[31402]: info: CoreCommandRouter::volumioGetState Jan 25 21:42:22 volumio volumio[31402]: info: CorePlayQueue::getTrack 0 Jan 25 21:42:22 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 25 21:42:22 volumio volumio[31541]: Starting albumart workers Jan 25 21:42:22 volumio volumio[31402]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Jan 25 21:42:22 volumio volumio[31402]: info: Discovery: Found device Volumio Jan 25 21:42:22 volumio volumio[31402]: info: CoreCommandRouter::volumioGetState Jan 25 21:42:22 volumio volumio[31402]: info: CorePlayQueue::getTrack 0 Jan 25 21:42:22 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 25 21:42:22 volumio go-librespot[31633]: go-librespot daemon starting... Jan 25 21:42:22 volumio volumio[31402]: info: MPD Permissions set Jan 25 21:42:22 volumio volumio[31402]: info: MPD Permissions set Jan 25 21:42:22 volumio volumio[31402]: info: Upmpdcli Daemon Started Jan 25 21:42:22 volumio go-librespot[31634]: time="2026-01-25T21:42:22+07:00" level=info msg="running go-librespot 0.4.0" Jan 25 21:42:22 volumio go-librespot[31634]: time="2026-01-25T21:42:22+07:00" level=debug msg="app state loaded" Jan 25 21:42:22 volumio go-librespot[31634]: time="2026-01-25T21:42:22+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 25 21:42:22 volumio volumio[31402]: info: Volumio called home Jan 25 21:42:22 volumio volumio[31402]: info: Spotify config file written Jan 25 21:42:22 volumio sudo[31641]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jan 25 21:42:22 volumio sudo[31641]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 21:42:22 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Jan 25 21:42:22 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Jan 25 21:42:22 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 25 21:42:22 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 25 21:42:22 volumio go-librespot[31643]: go-librespot daemon starting... Jan 25 21:42:22 volumio sudo[31641]: pam_unix(sudo:session): session closed for user root Jan 25 21:42:22 volumio volumio[31402]: 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 25 21:42:22 volumio go-librespot[31644]: time="2026-01-25T21:42:22+07:00" level=info msg="running go-librespot 0.4.0" Jan 25 21:42:22 volumio go-librespot[31644]: time="2026-01-25T21:42:22+07:00" level=debug msg="app state loaded" Jan 25 21:42:22 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 25 21:42:22 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 25 21:42:22 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 25 21:42:22 volumio go-librespot[31644]: time="2026-01-25T21:42:22+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 25 21:42:22 volumio volumio[31402]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 21:42:22 volumio volumio[31402]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 21:42:22 volumio volumio[31402]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 21:42:22 volumio volumio[31402]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 21:42:22 volumio volumio[31402]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 21:42:22 volumio volumio[31402]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 21:42:22 volumio volumio[31402]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 21:42:22 volumio volumio[31402]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 21:42:22 volumio volumio[31402]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 25 21:42:22 volumio volumio[31402]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 21:42:22 volumio volumio[31402]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 21:42:22 volumio volumio[31402]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 21:42:22 volumio volumio[31402]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 21:42:22 volumio volumio[31402]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 21:42:22 volumio volumio[31402]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 21:42:23 volumio volumio[31402]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 21:42:23 volumio volumio[31402]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 21:42:23 volumio volumio[31402]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 21:42:23 volumio volumio[31402]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 25 21:42:23 volumio volumio[31402]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 21:42:23 volumio volumio[31402]: info: No need to fix Spotify hosts Jan 25 21:42:23 volumio go-librespot[31644]: time="2026-01-25T21:42:23+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 25 21:42:23 volumio go-librespot[31644]: time="2026-01-25T21:42:23+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 25 21:42:23 volumio go-librespot[31644]: time="2026-01-25T21:42:23+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 25 21:42:23 volumio go-librespot[31644]: time="2026-01-25T21:42:23+07:00" level=info msg="zeroconf server listening on port 34421" Jan 25 21:42:23 volumio go-librespot[31644]: time="2026-01-25T21:42:23+07:00" level=debug msg="obtained new client token: AACN+SOt3/7OyjY5wtcs7qiuXhIAjjTAn+XqIM1z4ebpUAhM9sxA/bPoM2Nd23Wd9l34q4iN7P0YvZ1kr8SIgZ+5FHFFdo9h0hxKgKfeolSqCIDsf6rAxXikLqvMD5J/dj4rzdlJIEsznwrZPdbM0SgEqu9jHemP8TTKXcNjfH0S1HQEI4qoWaDnkw5yh77TGgqL7Nom7krw6FDYbrsNikOBDnOhEdyUfV+moch9eRLra963Ph4nHfVVuKk=" Jan 25 21:42:23 volumio go-librespot[31644]: time="2026-01-25T21:42:23+07:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:4070, retrying with a different AP" error="dial tcp 104.199.241.202:4070: connect: connection refused" Jan 25 21:42:24 volumio go-librespot[31644]: time="2026-01-25T21:42:24+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Jan 25 21:42:24 volumio go-librespot[31644]: time="2026-01-25T21:42:24+07:00" level=debug msg="completed keyexchange" Jan 25 21:42:24 volumio go-librespot[31644]: time="2026-01-25T21:42:24+07:00" level=debug msg="completed challenge" Jan 25 21:42:24 volumio go-librespot[31644]: time="2026-01-25T21:42:24+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 25 21:42:24 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 25 21:42:24 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 25 21:42:24 volumio volumio[31402]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 25 21:42:24 volumio volumio[31402]: SPOTIFY: BQDk639scjXUO-S8Q5X6rqg5rPP_td4aey3pddMCL4M6r8aApLaQs7jRJTXwuMuKGlT1nVIxkh582EcqUl4Zu6tSTbCBwQrs-P-lXWUR30uTuQYDMVrSmWDkIXm6j0ZhwyNjTDa_5Uld2PTBhSwLuZEAor14rgFAPsO6DH7cT3PQfGutWDpC9tR05rO1XwopKodJ2qLldc_ePyLjUvSQRjiWtFpt5gCsIUSVNHtv_A58jLagrYUhzsR_u-NuAlzVtkFOF_LQoCjj8RGnBRnHnBtvnEVHsZvoco9Hf40nPmD6Qs40kBaF1p6F Jan 25 21:42:24 volumio volumio[31402]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 25 21:42:24 volumio volumio[31402]: info: New Spotify access token = BQDk639scjXUO-S8Q5X6rqg5rPP_td4aey3pddMCL4M6r8aApLaQs7jRJTXwuMuKGlT1nVIxkh582EcqUl4Zu6tSTbCBwQrs-P-lXWUR30uTuQYDMVrSmWDkIXm6j0ZhwyNjTDa_5Uld2PTBhSwLuZEAor14rgFAPsO6DH7cT3PQfGutWDpC9tR05rO1XwopKodJ2qLldc_ePyLjUvSQRjiWtFpt5gCsIUSVNHtv_A58jLagrYUhzsR_u-NuAlzVtkFOF_LQoCjj8RGnBRnHnBtvnEVHsZvoco9Hf40nPmD6Qs40kBaF1p6F Jan 25 21:42:24 volumio volumio[31402]: info: Spotify credentials grant success - running version from March 24, 2019 Jan 25 21:42:24 volumio volumio[31402]: info: Starting Shairport Sync Jan 25 21:42:24 volumio volumio[31402]: info: Starting Shairport Sync Jan 25 21:42:24 volumio volumio[31402]: info: Starting Shairport Sync Jan 25 21:42:24 volumio sudo[31681]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 25 21:42:24 volumio sudo[31681]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 21:42:24 volumio sudo[31683]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 25 21:42:24 volumio sudo[31683]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 21:42:24 volumio sudo[31685]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 25 21:42:24 volumio sudo[31685]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 21:42:24 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 25 21:42:24 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Jan 25 21:42:24 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 25 21:42:24 volumio systemd[1]: shairport-sync.service: Consumed 2.271s CPU time. Jan 25 21:42:24 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 25 21:42:24 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 25 21:42:24 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 25 21:42:25 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 25 21:42:25 volumio sudo[31681]: pam_unix(sudo:session): session closed for user root Jan 25 21:42:25 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 25 21:42:25 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Jan 25 21:42:25 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 25 21:42:25 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 25 21:42:25 volumio volumio[31402]: info: CoreCommandRouter::volumioGetState Jan 25 21:42:25 volumio volumio[31402]: info: CorePlayQueue::getTrack 0 Jan 25 21:42:25 volumio sudo[31683]: pam_unix(sudo:session): session closed for user root Jan 25 21:42:25 volumio sudo[31685]: pam_unix(sudo:session): session closed for user root Jan 25 21:42:25 volumio volumio[31402]: info: Shairport-Sync Started Jan 25 21:42:25 volumio volumio[31402]: Error adding Membership: Error: addMembership EINVAL Jan 25 21:42:25 volumio volumio[31402]: info: Shairport-Sync Started Jan 25 21:42:25 volumio volumio[31402]: info: Shairport-Sync Started Jan 25 21:42:25 volumio volumio[31402]: 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 25 21:42:25 volumio volumio[31402]: info: Spotify Successfully logged in Jan 25 21:42:25 volumio volumio[31402]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 25 21:42:25 volumio volumio[31402]: info: [1769352145446] CoreMusicLibrary::Adding element Spotify Jan 25 21:42:25 volumio volumio[31402]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 25 21:42:25 volumio volumio[31402]: Cannot find translation for source YouTube Music Jan 25 21:42:25 volumio volumio[31402]: Cannot find translation for source Spotify Jan 25 21:42:26 volumio volumio[31402]: info: [yt-cast-receiver] DIAL server listening on port 8098 Jan 25 21:42:26 volumio volumio[31402]: info: CoreCommandRouter::volumioRetrievevolume Jan 25 21:42:26 volumio volumio[31402]: info: VolumeController:: Volume=100 Mute =false Jan 25 21:42:26 volumio volumio[31402]: info: CoreCommandRouter::volumioGetState Jan 25 21:42:26 volumio volumio[31402]: info: CorePlayQueue::getTrack 0 Jan 25 21:42:26 volumio volumio[31402]: info: CoreStateMachine::pushState Jan 25 21:42:26 volumio volumio[31402]: info: CorePlayQueue::getTrack 0 Jan 25 21:42:26 volumio volumio[31402]: info: CoreCommandRouter::volumioPushState Jan 25 21:42:26 volumio volumio[31402]: info: go-librespot daemon successfully initialized Jan 25 21:42:26 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 25 21:42:26 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 25 21:42:26 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 25 21:42:27 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Jan 25 21:42:27 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 25 21:42:27 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 25 21:42:27 volumio go-librespot[31721]: go-librespot daemon starting... Jan 25 21:42:27 volumio go-librespot[31722]: time="2026-01-25T21:42:27+07:00" level=info msg="running go-librespot 0.4.0" Jan 25 21:42:27 volumio go-librespot[31722]: time="2026-01-25T21:42:27+07:00" level=debug msg="app state loaded" Jan 25 21:42:27 volumio go-librespot[31722]: time="2026-01-25T21:42:27+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 25 21:42:28 volumio mpd[31626]: 2026-01-25T21:42:28 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 25 21:42:28 volumio systemd[1]: Started mpd.service - Music Player Daemon. Jan 25 21:42:28 volumio sudo[31588]: pam_unix(sudo:session): session closed for user root Jan 25 21:42:28 volumio sudo[31599]: pam_unix(sudo:session): session closed for user root Jan 25 21:42:28 volumio go-librespot[31722]: time="2026-01-25T21:42: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 25 21:42:28 volumio go-librespot[31722]: time="2026-01-25T21:42: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 25 21:42:28 volumio go-librespot[31722]: time="2026-01-25T21:42: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 25 21:42:28 volumio go-librespot[31722]: time="2026-01-25T21:42:28+07:00" level=info msg="zeroconf server listening on port 45721" Jan 25 21:42:28 volumio volumio[31402]: error: MPD error: The expression evaluated to a falsy value: Jan 25 21:42:28 volumio volumio[31402]: assert.ok(self.idling) Jan 25 21:42:28 volumio volumio[31402]: error: The expression evaluated to a falsy value: Jan 25 21:42:28 volumio volumio[31402]: assert.ok(self.idling) Jan 25 21:42:28 volumio volumio[31402]: error: updateQueue error: null Jan 25 21:42:28 volumio go-librespot[31722]: time="2026-01-25T21:42:28+07:00" level=debug msg="obtained new client token: AAA/MCEowCFxREfzu8UUuIBmYUnW5Mg4LvhQdEn8uxOxjXv7OJzLXAd4fREXAWHkKSuvH/pBUB3axinr0+oaHPTU8H6V3vPMU5YmY7Dnsw7BjezP4qUFd+IfGKOWWUqynBWo1F2y5kFUXYlRGmcUtoo4lIKzCzcHSPevta2DRvWg0YwMbx8SocbtFxMU7nYX7tD+AQe3xp9wbrAk4GGfMDSqkw5hSZHMio+LRn12lwNVFDkFVooZABw7Yz4=" Jan 25 21:42:28 volumio volumio[31402]: info: Completed starting Core Plugins Jan 25 21:42:28 volumio volumio[31402]: info: ------------------------------------------- Jan 25 21:42:28 volumio volumio[31402]: info: ----- MyVolumio plugins startup ---- Jan 25 21:42:28 volumio volumio[31402]: info: ------------------------------------------- Jan 25 21:42:28 volumio volumio[31402]: info: [MyVolumio PluginManager] Fetching plans data.... Jan 25 21:42:28 volumio volumio[31402]: info: MPD running with PID31626 Jan 25 21:42:28 volumio volumio[31402]: ,establishing connection Jan 25 21:42:28 volumio go-librespot[31722]: time="2026-01-25T21:42:28+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 25 21:42:28 volumio volumio[31402]: error: updateQueue error: null Jan 25 21:42:28 volumio go-librespot[31722]: time="2026-01-25T21:42:28+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 25 21:42:28 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 25 21:42:28 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 25 21:42:28 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 25 21:42:28 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 25 21:42:28 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 25 21:42:29 volumio volumio[31402]: info: Initializing connection to go-librespot Websocket Jan 25 21:42:29 volumio volumio[31402]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 25 21:42:30 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 25 21:42:30 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 25 21:42:30 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 25 21:42:31 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Jan 25 21:42:31 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 25 21:42:31 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 25 21:42:31 volumio go-librespot[31734]: go-librespot daemon starting... Jan 25 21:42:31 volumio go-librespot[31735]: time="2026-01-25T21:42:31+07:00" level=info msg="running go-librespot 0.4.0" Jan 25 21:42:31 volumio go-librespot[31735]: time="2026-01-25T21:42:31+07:00" level=debug msg="app state loaded" Jan 25 21:42:31 volumio go-librespot[31735]: time="2026-01-25T21:42:31+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 25 21:42:32 volumio go-librespot[31735]: time="2026-01-25T21:42:32+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 25 21:42:32 volumio go-librespot[31735]: time="2026-01-25T21:42:32+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Jan 25 21:42:32 volumio go-librespot[31735]: time="2026-01-25T21:42:32+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Jan 25 21:42:32 volumio go-librespot[31735]: time="2026-01-25T21:42:32+07:00" level=info msg="zeroconf server listening on port 43471" Jan 25 21:42:32 volumio go-librespot[31735]: time="2026-01-25T21:42:32+07:00" level=debug msg="obtained new client token: AACa9goTHr0G82rhtw7MkEHm3qBrWkQ2zyrzj697ndQqhlo98AD/pVPYjDtcjdK1FYvJiYKn83HPX09XHuRUyPB2nLmV7kJzpwmFQTkaQo2J1Yg7s0XS7gsRSkjOD0zjt5bMkp9QRysLh849NkW2ajUeSQ59d5/vkd68oJwe/99VFhxeWZzgOOTxqMrKF1B28ovhibMcDtH/zt+D0mIonmYH+0qk3+13Z0LTjf8/MfFzSGiBIJ405lp0SQw=" Jan 25 21:42:32 volumio go-librespot[31735]: time="2026-01-25T21:42:32+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 25 21:42:32 volumio go-librespot[31735]: time="2026-01-25T21:42:32+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 25 21:42:32 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 25 21:42:32 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 25 21:42:32 volumio volumio[31402]: info: Initializing connection to go-librespot Websocket Jan 25 21:42:32 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 25 21:42:32 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 25 21:42:32 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 25 21:42:32 volumio volumio[31402]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 25 21:42:33 volumio volumio[31402]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Jan 25 21:42:34 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 25 21:42:34 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 25 21:42:34 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 25 21:42:35 volumio volumio[31402]: info: Initializing connection to go-librespot Websocket Jan 25 21:42:35 volumio volumio[31402]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 25 21:42:35 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Jan 25 21:42:35 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 25 21:42:36 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 25 21:42:36 volumio go-librespot[31743]: go-librespot daemon starting... Jan 25 21:42:36 volumio go-librespot[31744]: time="2026-01-25T21:42:36+07:00" level=info msg="running go-librespot 0.4.0" Jan 25 21:42:36 volumio go-librespot[31744]: time="2026-01-25T21:42:36+07:00" level=debug msg="app state loaded" Jan 25 21:42:36 volumio go-librespot[31744]: time="2026-01-25T21:42:36+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 25 21:42:36 volumio go-librespot[31744]: time="2026-01-25T21:42:36+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 25 21:42:36 volumio go-librespot[31744]: time="2026-01-25T21:42:36+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 25 21:42:36 volumio go-librespot[31744]: time="2026-01-25T21:42:36+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 25 21:42:36 volumio go-librespot[31744]: time="2026-01-25T21:42:36+07:00" level=info msg="zeroconf server listening on port 44983" Jan 25 21:42:36 volumio go-librespot[31744]: time="2026-01-25T21:42:36+07:00" level=debug msg="obtained new client token: AAATQvH+Df9p/VC4wr3NheuzebFMBCPGdbzKnLLAZE4/v8M6WolKxpNSLcDnVFAhjrv1NKnEqdpxsnOkmsFaqWfOish0qKaKxLgY3T/9eNa6AbwEb1fg2AQ+PpPUNZubCXTsd3BLB+pzfM/oEhoelsSiNpQZn4EpkJrdiZ4wa0opiDkN/8JuhvdUv+V4fbfk5u6tUcCUUXwxpqCXaGu53GJMYyEivZGjmejK7TYLD6p7m3EVAZ03yLZp6o4=" Jan 25 21:42:36 volumio go-librespot[31744]: time="2026-01-25T21:42:36+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 25 21:42:36 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 25 21:42:36 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 25 21:42:36 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 25 21:42:36 volumio go-librespot[31744]: time="2026-01-25T21:42:36+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Jan 25 21:42:36 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 25 21:42:36 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 25 21:42:37 volumio volumio[31402]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Jan 25 21:42:37 volumio volumio[31402]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Jan 25 21:42:37 volumio volumio[31402]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Jan 25 21:42:37 volumio volumio[31402]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Jan 25 21:42:37 volumio volumio[31402]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Jan 25 21:42:37 volumio volumio[31402]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Jan 25 21:42:37 volumio volumio[31402]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Jan 25 21:42:37 volumio volumio[31402]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Jan 25 21:42:37 volumio volumio[31402]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Jan 25 21:42:37 volumio volumio[31402]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Jan 25 21:42:37 volumio volumio[31402]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Jan 25 21:42:37 volumio volumio[31402]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Jan 25 21:42:37 volumio volumio[31402]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Jan 25 21:42:37 volumio volumio[31402]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Jan 25 21:42:37 volumio volumio[31402]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Jan 25 21:42:37 volumio volumio[31402]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Jan 25 21:42:37 volumio volumio[31402]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Jan 25 21:42:37 volumio volumio[31402]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Jan 25 21:42:37 volumio volumio[31402]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Jan 25 21:42:37 volumio volumio[31402]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Jan 25 21:42:37 volumio volumio[31402]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Jan 25 21:42:37 volumio volumio[31402]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Jan 25 21:42:37 volumio volumio[31402]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Jan 25 21:42:37 volumio volumio[31402]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Jan 25 21:42:37 volumio volumio[31402]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Jan 25 21:42:37 volumio volumio[31402]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Jan 25 21:42:37 volumio volumio[31402]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Jan 25 21:42:37 volumio volumio[31402]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Jan 25 21:42:37 volumio volumio[31402]: info: Adding plugin bluetooth to MyMusic Plugins Jan 25 21:42:37 volumio volumio[31402]: info: Adding plugin multiroom to MyMusic Plugins Jan 25 21:42:37 volumio volumio[31402]: info: Adding plugin metavolumio to MyMusic Plugins Jan 25 21:42:37 volumio volumio[31402]: info: Adding plugin cd_controller to MyMusic Plugins Jan 25 21:42:37 volumio volumio[31402]: info: Adding plugin qobuzconnect to MyMusic Plugins Jan 25 21:42:37 volumio volumio[31402]: info: Adding plugin smart_inputs to MyMusic Plugins Jan 25 21:42:37 volumio volumio[31402]: info: Adding plugin tidalconnect to MyMusic Plugins Jan 25 21:42:37 volumio volumio[31402]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Jan 25 21:42:38 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 25 21:42:38 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 25 21:42:38 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 25 21:42:39 volumio volumio[31402]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Jan 25 21:42:39 volumio volumio[31402]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Jan 25 21:42:39 volumio volumio[31402]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 25 21:42:39 volumio volumio[31402]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 25 21:42:39 volumio volumio[31402]: info: Starting MyVolumio Remote Streaming Endpoints Jan 25 21:42:39 volumio volumio[31402]: info: MyVolumio login type: Token Jan 25 21:42:39 volumio volumio[31402]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Jan 25 21:42:39 volumio volumio[31402]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Jan 25 21:42:40 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Jan 25 21:42:40 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 25 21:42:40 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 25 21:42:40 volumio go-librespot[31767]: go-librespot daemon starting... Jan 25 21:42:40 volumio go-librespot[31768]: time="2026-01-25T21:42:40+07:00" level=info msg="running go-librespot 0.4.0" Jan 25 21:42:40 volumio go-librespot[31768]: time="2026-01-25T21:42:40+07:00" level=debug msg="app state loaded" Jan 25 21:42:40 volumio go-librespot[31768]: time="2026-01-25T21:42:40+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 25 21:42:40 volumio go-librespot[31768]: time="2026-01-25T21:42:40+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 25 21:42:40 volumio go-librespot[31768]: time="2026-01-25T21:42:40+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 25 21:42:40 volumio go-librespot[31768]: time="2026-01-25T21:42:40+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 25 21:42:40 volumio go-librespot[31768]: time="2026-01-25T21:42:40+07:00" level=info msg="zeroconf server listening on port 37741" Jan 25 21:42:40 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 25 21:42:40 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 25 21:42:40 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 25 21:42:41 volumio go-librespot[31768]: time="2026-01-25T21:42:41+07:00" level=debug msg="obtained new client token: AACifwQI/YYPvcL7KpboFit8c5zXk5IlcdPAmkCoZG3qIlz9aUrc+DRkQLjJGWTuKO3iyEOajZB+j1J3N5nrWe7wdr97MBQ+pyBPlhnBDK+KMWILqyNRoi2HzQaJgxvbeeiDE1pgqm/Yhcyc/AX1KeCf4N8RukhWb/digOCbHVI9Lq6t9EiDnpcceE74TAQwr3el7WAaXQnXm5O48zAYAEGPDHbMJss5NmeaFlmcD2+YrTaJB/ofArsT" Jan 25 21:42:41 volumio volumio[31402]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Jan 25 21:42:41 volumio volumio[31402]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Jan 25 21:42:41 volumio volumio[31402]: info: Streaming services startup Jan 25 21:42:41 volumio volumio[31402]: info: Starting Streaming Daemon Jan 25 21:42:41 volumio go-librespot[31768]: time="2026-01-25T21:42:41+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 25 21:42:41 volumio sudo[31776]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jan 25 21:42:41 volumio volumio[31402]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Jan 25 21:42:41 volumio sudo[31776]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 21:42:41 volumio sudo[31776]: pam_unix(sudo:session): session closed for user root Jan 25 21:42:41 volumio volumio[31402]: info: Initializing connection to go-librespot Websocket Jan 25 21:42:41 volumio volumio[31402]: error: Cannot start Volumio Streaming Daemon Jan 25 21:42:41 volumio volumio[31402]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Jan 25 21:42:41 volumio volumio[31402]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Jan 25 21:42:41 volumio go-librespot[31768]: time="2026-01-25T21:42:41+07:00" level=debug msg="new websocket client" Jan 25 21:42:41 volumio volumio[31402]: info: Connection to go-librespot Websocket established Jan 25 21:42:42 volumio go-librespot[31768]: time="2026-01-25T21:42:42+07:00" level=debug msg="completed keyexchange" Jan 25 21:42:42 volumio go-librespot[31768]: time="2026-01-25T21:42:42+07:00" level=debug msg="completed challenge" Jan 25 21:42:42 volumio go-librespot[31768]: time="2026-01-25T21:42: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 25 21:42:42 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 25 21:42:42 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 25 21:42:42 volumio volumio[31402]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Jan 25 21:42:42 volumio volumio[31402]: info: Connection to go-librespot Websocket closed Jan 25 21:42:42 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 25 21:42:42 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 25 21:42:42 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 25 21:42:43 volumio volumio[31402]: info: MyVolumio token set successfully Jan 25 21:42:43 volumio volumio[31402]: info: MYVOLUMIO: Adding device Jan 25 21:42:43 volumio volumio[31402]: info: MYVOLUMIO: Evaluating Server Jan 25 21:42:43 volumio volumio[31402]: info: MyVolumio status changed Jan 25 21:42:43 volumio volumio[31402]: info: Streaming services startup Jan 25 21:42:43 volumio volumio[31402]: info: Starting Streaming Daemon Jan 25 21:42:43 volumio volumio[31402]: info: Removing browser output: myVolumio user plan is not superstar Jan 25 21:42:43 volumio volumio[31402]: info: Removing audio output: Jan 25 21:42:43 volumio volumio[31402]: info: Stoppping Tunnel 1 Jan 25 21:42:43 volumio sudo[31803]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jan 25 21:42:43 volumio sudo[31803]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 21:42:43 volumio sudo[31803]: pam_unix(sudo:session): session closed for user root Jan 25 21:42:43 volumio sudo[31806]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Jan 25 21:42:43 volumio volumio[31402]: error: Cannot start Volumio Streaming Daemon Jan 25 21:42:43 volumio volumio[31402]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Jan 25 21:42:43 volumio volumio[31402]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Jan 25 21:42:43 volumio sudo[31806]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 21:42:43 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jan 25 21:42:43 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jan 25 21:42:43 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jan 25 21:42:43 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jan 25 21:42:43 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jan 25 21:42:43 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jan 25 21:42:43 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jan 25 21:42:43 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jan 25 21:42:43 volumio sudo[31806]: pam_unix(sudo:session): session closed for user root Jan 25 21:42:43 volumio volumio[31402]: info: Remote SSH Stopped Jan 25 21:42:44 volumio volumio[31402]: info: Setting Geolocation for MyVolumio to as1 Jan 25 21:42:44 volumio volumio[31402]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 25 21:42:44 volumio volumio[31402]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 25 21:42:44 volumio volumio[31402]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 25 21:42:44 volumio volumio[31402]: info: Getting Spotify volume Jan 25 21:42:44 volumio volumio[31402]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 25 21:42:44 volumio volumio[31402]: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 25 21:42:44 volumio volumio[31402]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Jan 25 21:42:44 volumio volumio[31402]: errno: -111, Jan 25 21:42:44 volumio volumio[31402]: code: 'ECONNREFUSED', Jan 25 21:42:44 volumio volumio[31402]: syscall: 'connect', Jan 25 21:42:44 volumio volumio[31402]: address: '127.0.0.1', Jan 25 21:42:44 volumio volumio[31402]: port: 9879, Jan 25 21:42:44 volumio volumio[31402]: response: undefined Jan 25 21:42:44 volumio volumio[31402]: } Jan 25 21:42:44 volumio volumio[31402]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 25 21:42:44 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 25 21:42:44 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 25 21:42:44 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 25 21:42:45 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Jan 25 21:42:45 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 25 21:42:45 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 25 21:42:45 volumio go-librespot[31820]: go-librespot daemon starting... Jan 25 21:42:45 volumio go-librespot[31821]: time="2026-01-25T21:42:45+07:00" level=info msg="running go-librespot 0.4.0" Jan 25 21:42:45 volumio go-librespot[31821]: time="2026-01-25T21:42:45+07:00" level=debug msg="app state loaded" Jan 25 21:42:45 volumio go-librespot[31821]: time="2026-01-25T21:42:45+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 25 21:42:45 volumio sudo[31829]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-01-25 21:41' Jan 25 21:42:45 volumio sudo[31829]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 21:42:46 volumio go-librespot[31821]: time="2026-01-25T21:42:46+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 25 21:42:46 volumio go-librespot[31821]: time="2026-01-25T21:42:46+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 25 21:42:46 volumio go-librespot[31821]: time="2026-01-25T21:42:46+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 25 21:42:46 volumio go-librespot[31821]: time="2026-01-25T21:42:46+07:00" level=info msg="zeroconf server listening on port 41659" Jan 25 21:42:46 volumio sudo[31829]: pam_unix(sudo:session): session closed for user root Jan 25 21:42:46 volumio go-librespot[31821]: time="2026-01-25T21:42:46+07:00" level=debug msg="obtained new client token: AAAEWcOqbZJ7qj5n2SaIqJdqLQtjdpEUAEE0qUttWPdRyngB1vrRVLPs7WbSJAy+wNN1TMpsbmOv2TB2OZqP1HOVPSr+/mP5+CsocuD8strTKitP4/dVkoBmr4Z86/u6hDZghpVPM5+f+54flc2UwJ0j6DgOHoE0CXYqU1gC3m04xVP6hiSk3Ik8xAbp4B/stak0QSB6ZjyB3TzqnV+wdLPdz2z2Rc/jt+BpmPDhEeRHchXEOYip+Cf3exo=" Jan 25 21:42:46 volumio go-librespot[31821]: time="2026-01-25T21:42:46+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 25 21:42:46 volumio volumio-remote-updater[628]: [2026-01-25 21:42:46] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Jan 25 21:42:46 volumio volumio-remote-updater[628]: [2026-01-25 21:42:46] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Jan 25 21:42:46 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Jan 25 21:42:46 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Jan 25 21:42:46 volumio systemd[1]: volumio.service: Consumed 1min 2.531s CPU time. Jan 25 21:42:46 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 25 21:42:46 volumio go-librespot[31821]: time="2026-01-25T21:42:46+07:00" level=debug msg="completed keyexchange" Jan 25 21:42:46 volumio go-librespot[31821]: time="2026-01-25T21:42:46+07:00" level=debug msg="completed challenge" Jan 25 21:42:46 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Jan 25 21:42:46 volumio go-librespot[31821]: time="2026-01-25T21:42: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 25 21:42:46 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 25 21:42:46 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 25 21:42:46 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 6021. Jan 25 21:42:46 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 25 21:42:46 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Jan 25 21:42:46 volumio systemd[1]: volumio.service: Consumed 1min 2.531s CPU time. Jan 25 21:42:46 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Jan 25 21:42:46 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Jan 25 21:42:46 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 25 21:42:46 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 25 21:42:46 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 25 21:42:48 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 25 21:42:48 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 25 21:42:48 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 25 21:42:49 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Jan 25 21:42:49 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 25 21:42:49 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 25 21:42:49 volumio go-librespot[31866]: go-librespot daemon starting... Jan 25 21:42:49 volumio go-librespot[31867]: time="2026-01-25T21:42:49+07:00" level=info msg="running go-librespot 0.4.0" Jan 25 21:42:49 volumio go-librespot[31867]: time="2026-01-25T21:42:49+07:00" level=debug msg="app state loaded" Jan 25 21:42:49 volumio go-librespot[31867]: time="2026-01-25T21:42:49+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 25 21:42:50 volumio go-librespot[31867]: time="2026-01-25T21:42: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 25 21:42:50 volumio go-librespot[31867]: time="2026-01-25T21:42:50+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 25 21:42:50 volumio go-librespot[31867]: time="2026-01-25T21:42:50+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 25 21:42:50 volumio go-librespot[31867]: time="2026-01-25T21:42:50+07:00" level=info msg="zeroconf server listening on port 34353" Jan 25 21:42:50 volumio volumio[31850]: info: ------------------------------------------- Jan 25 21:42:50 volumio volumio[31850]: info: ----- Volumio3 ---- Jan 25 21:42:50 volumio volumio[31850]: info: ------------------------------------------- Jan 25 21:42:50 volumio volumio[31850]: info: ----- System startup ---- Jan 25 21:42:50 volumio volumio[31850]: info: ------------------------------------------- Jan 25 21:42:50 volumio go-librespot[31867]: time="2026-01-25T21:42:50+07:00" level=debug msg="obtained new client token: AAC+INV/AJx61+71wB8+9W4qZuBSoYo4CVJQGSAHCBWHWoeBs8vtnDC+8BLXc5Ee/I43/D2XWH7T/EctxRst9hsB49Wady3AMtdv/cMvnhLX7ORaQaRgQBuZn7NCL4lurRdFDZruDk8xwMLlhUdeDRgobgIRF0OctJbgCMBHkcnWK3TRMdsSbHTEZqhu7UchZNifcJf4ezlwgpQ6E8m1xIak8IVt2K3JctG6XSyepZlwxfeLW6vpI73YjVU=" Jan 25 21:42:50 volumio go-librespot[31867]: time="2026-01-25T21:42:50+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 25 21:42:50 volumio go-librespot[31867]: time="2026-01-25T21:42:50+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 25 21:42:50 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 25 21:42:50 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 25 21:42:50 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 25 21:42:50 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 25 21:42:50 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 25 21:42:51 volumio volumio-remote-updater[628]: [2026-01-25 21:42:51] [connect] Successful connection Jan 25 21:42:51 volumio volumio[31850]: info: MYVOLUMIO Environment detected Jan 25 21:42:51 volumio volumio[31850]: info: Plugin folders cleanup Jan 25 21:42:51 volumio volumio[31850]: info: Scanning into folder /volumio/app/plugins/ Jan 25 21:42:51 volumio volumio[31850]: info: Scanning category audio_interface Jan 25 21:42:51 volumio volumio[31850]: info: Scanning category miscellanea Jan 25 21:42:51 volumio volumio[31850]: info: Scanning category music_service Jan 25 21:42:51 volumio volumio[31850]: info: Scanning category plugins.json Jan 25 21:42:51 volumio volumio[31850]: info: Scanning category system_controller Jan 25 21:42:51 volumio volumio[31850]: info: Scanning category user_interface Jan 25 21:42:51 volumio volumio[31850]: info: Scanning into folder /data/plugins/ Jan 25 21:42:51 volumio volumio[31850]: info: Scanning category music_service Jan 25 21:42:51 volumio volumio[31850]: info: Plugin folders cleanup completed Jan 25 21:42:51 volumio volumio[31850]: info: ------------------------------------------- Jan 25 21:42:51 volumio volumio[31850]: info: ----- Core plugins startup ---- Jan 25 21:42:51 volumio volumio[31850]: info: ------------------------------------------- Jan 25 21:42:51 volumio volumio[31850]: info: Loading plugins from folder /volumio/app/plugins/ Jan 25 21:42:51 volumio volumio[31850]: info: Adding plugin upnp to MyMusic Plugins Jan 25 21:42:52 volumio volumio[31850]: info: Adding plugin airplay_emulation to MyMusic Plugins Jan 25 21:42:52 volumio volumio[31850]: info: Adding plugin upnp_browser to MyMusic Plugins Jan 25 21:42:52 volumio volumio[31850]: info: Loading plugins from folder /data/plugins/ Jan 25 21:42:52 volumio volumio[31850]: info: Loading plugin "system"... Jan 25 21:42:52 volumio volumio[31850]: info: Loading plugin "appearance"... Jan 25 21:42:52 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 25 21:42:52 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 25 21:42:52 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 25 21:42:53 volumio volumio[31850]: info: Loading plugin "network"... Jan 25 21:42:53 volumio volumio[31850]: info: Refreshing Cached IP Addresses Jan 25 21:42:53 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Jan 25 21:42:53 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 25 21:42:54 volumio sudo[31888]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 25 21:42:54 volumio sudo[31888]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 21:42:54 volumio sudo[31890]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 25 21:42:54 volumio sudo[31890]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 21:42:54 volumio sudo[31890]: pam_unix(sudo:session): session closed for user root Jan 25 21:42:54 volumio volumio[31850]: info: Loading plugin "services"... Jan 25 21:42:54 volumio sudo[31888]: pam_unix(sudo:session): session closed for user root Jan 25 21:42:54 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 25 21:42:54 volumio go-librespot[31891]: go-librespot daemon starting... Jan 25 21:42:54 volumio volumio[31850]: info: Loading plugin "alsa_controller"... Jan 25 21:42:54 volumio sudo[31900]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Jan 25 21:42:54 volumio go-librespot[31910]: time="2026-01-25T21:42:54+07:00" level=info msg="running go-librespot 0.4.0" Jan 25 21:42:54 volumio go-librespot[31910]: time="2026-01-25T21:42:54+07:00" level=debug msg="app state loaded" Jan 25 21:42:54 volumio sudo[31900]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 21:42:54 volumio go-librespot[31910]: time="2026-01-25T21:42:54+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 25 21:42:54 volumio volumio[31850]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 25 21:42:54 volumio volumio[31850]: info: Loading plugin "wizard"... Jan 25 21:42:54 volumio volumio[31850]: info: Loading plugin "networkfs"... Jan 25 21:42:54 volumio volumio[31850]: info: Starting Udev Watcher for removable devices Jan 25 21:42:54 volumio volumio[31850]: info: Ignoring mount for partition: boot Jan 25 21:42:54 volumio volumio[31850]: info: Ignoring mount for partition: volumio Jan 25 21:42:54 volumio volumio[31850]: info: Ignoring mount for partition: volumio_data Jan 25 21:42:54 volumio volumio[31850]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 25 21:42:54 volumio volumio[31850]: info: Loading plugin "volumio_command_line_client"... Jan 25 21:42:54 volumio volumio[31850]: info: Loading plugin "upnp"... Jan 25 21:42:54 volumio volumio[31850]: info: [1769352174423] Starting Upmpd Daemon Jan 25 21:42:54 volumio volumio[31850]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 25 21:42:54 volumio volumio[31850]: info: Loading plugin "my_music"... Jan 25 21:42:54 volumio volumio[31850]: info: Loading plugin "mpd"... Jan 25 21:42:54 volumio go-librespot[31910]: time="2026-01-25T21:42: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 25 21:42:54 volumio go-librespot[31910]: time="2026-01-25T21:42: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 25 21:42:54 volumio go-librespot[31910]: time="2026-01-25T21:42: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 25 21:42:54 volumio go-librespot[31910]: time="2026-01-25T21:42:54+07:00" level=info msg="zeroconf server listening on port 36173" Jan 25 21:42:54 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 25 21:42:54 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 25 21:42:54 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 25 21:42:54 volumio go-librespot[31910]: time="2026-01-25T21:42:54+07:00" level=debug msg="obtained new client token: AADVZ2V8uRy3x9n6MYw7FHKFWtw5gVDeDmecHA3FWFCvwifHWmIu7yCy9Bihk/WhG6hqd2cZsfk+slsRwBtdPg8kUVSNKP7YekgFmwROamBE187bTH92Kv+1JBz3KxTw3OQTDsn1tp8ZSJ6dBlrZ+7gH4IKa1cdfbAZpEGv3f9HZbUdkfINX9f5VPquUQUgV5RYCDvB5aDUy90j8XHYLBnchJdPvAS+qfdWhIxTHdKkklYp5sAwhCsITcEo=" Jan 25 21:42:55 volumio go-librespot[31910]: time="2026-01-25T21:42:55+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 25 21:42:55 volumio volumio[31850]: info: Loading plugin "upnp_browser"... Jan 25 21:42:55 volumio go-librespot[31910]: time="2026-01-25T21:42:55+07:00" level=debug msg="completed keyexchange" Jan 25 21:42:55 volumio go-librespot[31910]: time="2026-01-25T21:42:55+07:00" level=debug msg="completed challenge" Jan 25 21:42:55 volumio go-librespot[31910]: time="2026-01-25T21:42:55+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 25 21:42:55 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 25 21:42:55 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 25 21:42:56 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 25 21:42:56 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 25 21:42:56 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 25 21:42:56 volumio sudo[31900]: pam_unix(sudo:session): session closed for user root Jan 25 21:42:58 volumio volumio[31850]: info: Starting UPNP Browser Jan 25 21:42:58 volumio volumio[31850]: info: Loading plugin "alarm-clock"... Jan 25 21:42:58 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Jan 25 21:42:58 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 25 21:42:58 volumio volumio[31850]: info: Loading plugin "airplay_emulation"... Jan 25 21:42:58 volumio volumio[31850]: info: Starting Shairport Sync Jan 25 21:42:58 volumio volumio[31850]: info: Loading plugin "last_100"... Jan 25 21:42:58 volumio volumio[31850]: info: Loading plugin "webradio"... Jan 25 21:42:58 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 25 21:42:58 volumio go-librespot[31930]: go-librespot daemon starting... Jan 25 21:42:58 volumio go-librespot[31931]: time="2026-01-25T21:42:58+07:00" level=info msg="running go-librespot 0.4.0" Jan 25 21:42:58 volumio go-librespot[31931]: time="2026-01-25T21:42:58+07:00" level=debug msg="app state loaded" Jan 25 21:42:58 volumio go-librespot[31931]: time="2026-01-25T21:42:58+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 25 21:42:58 volumio volumio[31850]: info: Loading plugin "i2s_dacs"... Jan 25 21:42:58 volumio volumio[31850]: info: Loading plugin "volumiodiscovery"... Jan 25 21:42:58 volumio volumio[31850]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 25 21:42:58 volumio volumio[31850]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 25 21:42:58 volumio volumio[31850]: *** WARNING *** For more information see Jan 25 21:42:58 volumio volumio[31850]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 25 21:42:58 volumio volumio[31850]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 25 21:42:58 volumio volumio[31850]: *** WARNING *** For more information see Jan 25 21:42:58 volumio node[31850]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 25 21:42:58 volumio node[31850]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 25 21:42:58 volumio node[31850]: *** WARNING *** For more information see Jan 25 21:42:58 volumio node[31850]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 25 21:42:58 volumio node[31850]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 25 21:42:58 volumio node[31850]: *** WARNING *** For more information see Jan 25 21:42:58 volumio volumio[31850]: info: Applying required configuration parameters for plugin volumiodiscovery Jan 25 21:42:58 volumio volumio[31850]: info: Discovery: Started advertising with name: Volumio Jan 25 21:42:58 volumio volumio[31850]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 25 21:42:58 volumio volumio[31850]: info: Loading plugin "spop"... Jan 25 21:42:58 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 25 21:42:58 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 25 21:42:58 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 25 21:42:58 volumio go-librespot[31931]: time="2026-01-25T21:42: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 25 21:42:58 volumio go-librespot[31931]: time="2026-01-25T21:42:58+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 25 21:42:58 volumio go-librespot[31931]: time="2026-01-25T21:42:58+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 25 21:42:59 volumio go-librespot[31931]: time="2026-01-25T21:42:59+07:00" level=info msg="zeroconf server listening on port 33095" Jan 25 21:42:59 volumio go-librespot[31931]: time="2026-01-25T21:42:59+07:00" level=debug msg="obtained new client token: AABvzakOFSGu3GXGxuQG8mYjHQYo6p5GayIr1a2Vu1T2nBbfUCfbAeCdm/PjMbdCeeld6BhsLwFFKdK/itqpeNO0O6lKzrWchZQqC5YNjiejuJjcz9CUyQG0fHb/V2yCRy/HHxHQjY76e3OTxRgJUiVfi504UaZbgG1bO7dS7XeL+blh74eNOn3pUE5l0e/3C+9X4u5LkHobK6rmKZBONKrPy6hW71I1un1EUAG6i2RnhwOmG7n5x3S2" Jan 25 21:42:59 volumio go-librespot[31931]: time="2026-01-25T21:42:59+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 25 21:42:59 volumio go-librespot[31931]: time="2026-01-25T21:42: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 25 21:42:59 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 25 21:42:59 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 25 21:43:00 volumio volumio[31850]: info: Loading plugin "ytcr"... Jan 25 21:43:00 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 25 21:43:00 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 25 21:43:00 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 25 21:43:02 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Jan 25 21:43:02 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 25 21:43:02 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 25 21:43:02 volumio go-librespot[31941]: go-librespot daemon starting... Jan 25 21:43:02 volumio go-librespot[31942]: time="2026-01-25T21:43:02+07:00" level=info msg="running go-librespot 0.4.0" Jan 25 21:43:02 volumio go-librespot[31942]: time="2026-01-25T21:43:02+07:00" level=debug msg="app state loaded" Jan 25 21:43:02 volumio go-librespot[31942]: time="2026-01-25T21:43:02+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 25 21:43:02 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 25 21:43:02 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 25 21:43:02 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 25 21:43:03 volumio go-librespot[31942]: time="2026-01-25T21:43:03+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 25 21:43:03 volumio go-librespot[31942]: time="2026-01-25T21:43:03+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 25 21:43:03 volumio go-librespot[31942]: time="2026-01-25T21:43:03+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 25 21:43:03 volumio go-librespot[31942]: time="2026-01-25T21:43:03+07:00" level=info msg="zeroconf server listening on port 43783" Jan 25 21:43:03 volumio go-librespot[31942]: time="2026-01-25T21:43:03+07:00" level=debug msg="obtained new client token: AAAieFDqHCpXvU6YzrPJFg/SIYQeXAfA/974jPIZh69HO5r7pPh0izjbqG3squpya6jXuv8q/ZvVXsbmPvOYizFBOYuQvkGZZJGDsNaQpcTX4Y8vU+KysjRfMDHmWZZDwtHg+mSEQ0Kbqi+4XHHD8FXs+FJjGxbeokU2kJ81FBA3dnogbvaI1to4pwEC1bCrrlhNWmVcyjgQldnsIdpIkcgJdj8Yrv7D1Sj53/ndsKJwLeFnaZ8h5u0eCGo=" Jan 25 21:43:03 volumio volumio[31850]: info: Loading plugin "ytmusic"... Jan 25 21:43:03 volumio go-librespot[31942]: time="2026-01-25T21:43:03+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 25 21:43:03 volumio go-librespot[31942]: time="2026-01-25T21:43:03+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 25 21:43:03 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 25 21:43:03 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 25 21:43:04 volumio volumio-remote-updater[628]: [2026-01-25 21:43:04] [connect] Successful connection Jan 25 21:43:04 volumio volumio[31850]: info: Loading plugin "outputs"... Jan 25 21:43:04 volumio volumio[31850]: info: Loading plugin "albumart"... Jan 25 21:43:04 volumio volumio[31850]: info: Plugin example_plugin is not enabled Jan 25 21:43:04 volumio volumio[31850]: info: Loading plugin "inputs"... Jan 25 21:43:04 volumio volumio[31850]: info: Loading plugin "updater_comm"... Jan 25 21:43:04 volumio volumio[31850]: info: Plugin mpdemulation is not enabled Jan 25 21:43:04 volumio volumio[31850]: info: Loading plugin "rest_api"... Jan 25 21:43:04 volumio volumio[31850]: info: Loading plugin "websocket"... Jan 25 21:43:04 volumio volumio[31850]: info: Starting Socket.io Server version 1.7.4 Jan 25 21:43:04 volumio volumio[31850]: info: Loading plugin "RoonBridge"... Jan 25 21:43:04 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 25 21:43:04 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 25 21:43:04 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 25 21:43:05 volumio volumio[31850]: info: Applying required configuration parameters for plugin RoonBridge Jan 25 21:43:05 volumio volumio[31850]: info: Loading i18n strings for locale en Jan 25 21:43:05 volumio volumio[31850]: Updating browse sources language Jan 25 21:43:05 volumio volumio[31850]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 25 21:43:05 volumio volumio[31963]: Forking 3 albumart workers Jan 25 21:43:05 volumio volumio[31850]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 25 21:43:05 volumio volumio[31850]: info: CoreCommandRouter::initPlayerControls Jan 25 21:43:05 volumio volumio[31850]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 21:43:05 volumio volumio[31850]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 21:43:05 volumio volumio[31850]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 21:43:05 volumio volumio[31850]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 21:43:05 volumio volumio[31850]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 21:43:05 volumio volumio[31850]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 21:43:05 volumio volumio[31850]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 21:43:05 volumio volumio[31850]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 21:43:05 volumio volumio[31850]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 25 21:43:05 volumio volumio[31850]: Express server listening on port 3000 Jan 25 21:43:05 volumio volumio[31850]: [Metrics] WebUI: 16s 252.98ms Jan 25 21:43:05 volumio volumio[31850]: info: CoreStateMachine::resetVolumioState Jan 25 21:43:05 volumio volumio[31850]: info: CoreStateMachine::getcurrentVolume Jan 25 21:43:05 volumio volumio[31850]: info: CoreCommandRouter::volumioRetrievevolume Jan 25 21:43:05 volumio sudo[32005]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 25 21:43:05 volumio sudo[32005]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 21:43:05 volumio sudo[32007]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 25 21:43:05 volumio volumio[31850]: info: Volumio Network Manager: Network status updated: 1 Jan 25 21:43:05 volumio sudo[32007]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 21:43:05 volumio sudo[32005]: pam_unix(sudo:session): session closed for user root Jan 25 21:43:05 volumio sudo[32007]: pam_unix(sudo:session): session closed for user root Jan 25 21:43:06 volumio volumio[31850]: info: VolumeController:: Volume=100 Mute =false Jan 25 21:43:06 volumio volumio[31850]: info: CoreStateMachine::pushState Jan 25 21:43:06 volumio volumio[31850]: info: CorePlayQueue::getTrack 0 Jan 25 21:43:06 volumio volumio[31850]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 25 21:43:06 volumio volumio[31850]: info: CoreCommandRouter::volumioPushState Jan 25 21:43:06 volumio volumio[31850]: info: CoreStateMachine::updateTrackBlock Jan 25 21:43:06 volumio volumio[31850]: info: CorePlayQueue::getTrackBlock Jan 25 21:43:06 volumio volumio[31850]: info: CoreCommandRouter::volumioRetrievevolume Jan 25 21:43:06 volumio volumio-remote-updater[628]: [2026-01-25 21:43:06] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1769352184 101 Jan 25 21:43:06 volumio volumio[31850]: 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 25 21:43:06 volumio volumio[31850]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 25 21:43:06 volumio volumio[31850]: info: Reloading queue from file Jan 25 21:43:06 volumio volumio[31850]: info: CoreStateMachine::setRepeat null single undefined Jan 25 21:43:06 volumio volumio[31850]: info: CoreStateMachine::pushState Jan 25 21:43:06 volumio volumio[31850]: info: CorePlayQueue::getTrack 0 Jan 25 21:43:06 volumio volumio[31850]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 25 21:43:06 volumio volumio[31850]: info: CoreCommandRouter::volumioPushState Jan 25 21:43:06 volumio volumio[31850]: info: CoreStateMachine::setRandom null Jan 25 21:43:06 volumio volumio[31850]: info: CoreStateMachine::pushState Jan 25 21:43:06 volumio volumio[31850]: info: CorePlayQueue::getTrack 0 Jan 25 21:43:06 volumio volumio[31850]: info: CoreCommandRouter::volumioPushState Jan 25 21:43:06 volumio volumio[31850]: info: Setting Device type: Raspberry PI Jan 25 21:43:06 volumio volumio[31850]: info: Completed loading Core Plugins Jan 25 21:43:06 volumio volumio[31850]: info: Preparing to generate the ALSA configuration file Jan 25 21:43:06 volumio volumio[31850]: info: VolumeController:: Volume=100 Mute =false Jan 25 21:43:06 volumio volumio[31850]: info: CoreStateMachine::pushState Jan 25 21:43:06 volumio volumio[31850]: info: CorePlayQueue::getTrack 0 Jan 25 21:43:06 volumio volumio[31850]: info: CoreCommandRouter::volumioPushState Jan 25 21:43:06 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Jan 25 21:43:06 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 25 21:43:06 volumio volumio[31850]: info: Asound.conf file unchanged, so no further update is needed Jan 25 21:43:06 volumio volumio[31850]: info: Output device has changed, restarting MPD Jan 25 21:43:06 volumio sudo[32024]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Jan 25 21:43:06 volumio sudo[32024]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 21:43:06 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 25 21:43:06 volumio go-librespot[32025]: go-librespot daemon starting... Jan 25 21:43:06 volumio volumio[31850]: info: Output device has changed, restarting Shairport Sync Jan 25 21:43:06 volumio volumio[31850]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 21:43:06 volumio volumio[31850]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 25 21:43:06 volumio sudo[32027]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 25 21:43:06 volumio sudo[32027]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 21:43:06 volumio go-librespot[32030]: time="2026-01-25T21:43:06+07:00" level=info msg="running go-librespot 0.4.0" Jan 25 21:43:06 volumio go-librespot[32030]: time="2026-01-25T21:43:06+07:00" level=debug msg="app state loaded" Jan 25 21:43:06 volumio go-librespot[32030]: time="2026-01-25T21:43:06+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 25 21:43:06 volumio sudo[32031]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 25 21:43:06 volumio sudo[32027]: pam_unix(sudo:session): session closed for user root Jan 25 21:43:06 volumio sudo[32031]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 21:43:06 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 25 21:43:06 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 25 21:43:06 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 25 21:43:06 volumio volumio[31850]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 25 21:43:06 volumio volumio[31850]: info: ___________ START PLUGINS ___________ Jan 25 21:43:07 volumio volumio[31850]: info: ControllerMpd::onStart: Initializing MPD Jan 25 21:43:07 volumio volumio[31850]: info: Creating MPD Configuration file Jan 25 21:43:07 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Jan 25 21:43:07 volumio sudo[32024]: pam_unix(sudo:session): session closed for user root Jan 25 21:43:07 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 25 21:43:07 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 25 21:43:07 volumio systemd[1]: mpd.service: Consumed 7.518s CPU time. Jan 25 21:43:07 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 25 21:43:07 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 25 21:43:07 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 25 21:43:07 volumio volumio[31850]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 25 21:43:07 volumio volumio[31850]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 25 21:43:07 volumio volumio[31850]: info: [1769352187209] CoreMusicLibrary::Adding element Media Servers Jan 25 21:43:07 volumio volumio[31850]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 25 21:43:07 volumio sudo[32046]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 25 21:43:07 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 25 21:43:07 volumio sudo[32044]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 25 21:43:07 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 25 21:43:07 volumio sudo[32046]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 21:43:07 volumio volumio[31850]: info: UPNP Browser: Client initialized successfully Jan 25 21:43:07 volumio sudo[32044]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 21:43:07 volumio sudo[32044]: pam_unix(sudo:session): session closed for user root Jan 25 21:43:07 volumio volumio[31850]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 21:43:07 volumio volumio[31850]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 25 21:43:07 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 25 21:43:07 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 25 21:43:07 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 25 21:43:07 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 25 21:43:07 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 25 21:43:07 volumio volumio[31850]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 25 21:43:07 volumio volumio[31850]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 21:43:07 volumio volumio[31850]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 25 21:43:07 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 25 21:43:07 volumio volumio[31850]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 25 21:43:07 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 25 21:43:07 volumio volumio[31850]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 25 21:43:07 volumio volumio[31850]: info: [1769352187626] CoreMusicLibrary::Adding element Last_100 Jan 25 21:43:07 volumio volumio[31850]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 25 21:43:07 volumio go-librespot[32030]: time="2026-01-25T21:43:07+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 25 21:43:07 volumio go-librespot[32030]: time="2026-01-25T21:43:07+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 25 21:43:07 volumio go-librespot[32030]: time="2026-01-25T21:43:07+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 25 21:43:07 volumio volumio[31850]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 25 21:43:07 volumio volumio[31850]: info: [1769352187667] CoreMusicLibrary::Adding element Webradio Jan 25 21:43:07 volumio volumio[31850]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 25 21:43:07 volumio volumio[31850]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 25 21:43:07 volumio go-librespot[32030]: time="2026-01-25T21:43:07+07:00" level=info msg="zeroconf server listening on port 42703" Jan 25 21:43:07 volumio volumio[31850]: info: Initializing BBC Radios Jan 25 21:43:07 volumio volumio[31850]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 25 21:43:07 volumio volumio[31850]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 25 21:43:07 volumio volumio[31850]: info: Creating Spotify config file Jan 25 21:43:08 volumio volumio[31850]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 21:43:08 volumio go-librespot[32030]: time="2026-01-25T21:43:08+07:00" level=debug msg="obtained new client token: AAA+3NTQfbJyNPmwKPhapmKqTHq4lb1rAccNFaSPKsQlrq+uuwNELTl7C69yLgQe2cxf8VXJZkz/NENM9pQHCInd+nxOagh3ka5S3HOXR400i7IrwZ4VjgBDlM+S2qAaOuyoLLH527WXlQlIHQVse4OCK4SMYEMnLs0Q6sBmnh3Egh+XGo78JuGlKUhCulh2V9gZRJbrsRulHIsYNTNY/1xuuz2hBOaxTG9BUYdIkhv2Y/vsNa+yJrQF0Gc=" Jan 25 21:43:08 volumio go-librespot[32030]: time="2026-01-25T21:43:08+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 25 21:43:08 volumio sudo[32061]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 25 21:43:08 volumio sudo[32061]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jan 25 21:43:08 volumio sudo[32061]: pam_unix(sudo:session): session closed for user root Jan 25 21:43:08 volumio go-librespot[32030]: time="2026-01-25T21:43:08+07:00" level=debug msg="completed keyexchange" Jan 25 21:43:08 volumio go-librespot[32030]: time="2026-01-25T21:43:08+07:00" level=debug msg="completed challenge" Jan 25 21:43:08 volumio go-librespot[32030]: time="2026-01-25T21:43:08+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 25 21:43:08 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 25 21:43:08 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 25 21:43:08 volumio volumio[31974]: Starting albumart workers Jan 25 21:43:08 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 25 21:43:08 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 25 21:43:08 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 25 21:43:09 volumio volumio[31850]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 25 21:43:09 volumio volumio[31850]: info: [1769352189170] CoreMusicLibrary::Adding element YouTube Music Jan 25 21:43:09 volumio volumio[31850]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 25 21:43:09 volumio volumio[31850]: Cannot find translation for source YouTube Music Jan 25 21:43:09 volumio volumio[31850]: info: Volumio Calling Home Jan 25 21:43:09 volumio volumio[31975]: Starting albumart workers Jan 25 21:43:09 volumio sudo[32081]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Jan 25 21:43:09 volumio sudo[32081]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 21:43:09 volumio volumio[31973]: Starting albumart workers Jan 25 21:43:09 volumio sudo[32081]: pam_unix(sudo:session): session closed for user root Jan 25 21:43:10 volumio volumio[31850]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Jan 25 21:43:10 volumio volumio[31850]: info: Discovery: Found device Volumio Jan 25 21:43:10 volumio volumio[31850]: info: CoreCommandRouter::volumioGetState Jan 25 21:43:10 volumio volumio[31850]: info: CorePlayQueue::getTrack 0 Jan 25 21:43:10 volumio volumio[31850]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Jan 25 21:43:10 volumio volumio[31850]: info: Discovery: Found device Volumio Jan 25 21:43:10 volumio volumio[31850]: info: CoreCommandRouter::volumioGetState Jan 25 21:43:10 volumio volumio[31850]: info: CorePlayQueue::getTrack 0 Jan 25 21:43:10 volumio volumio[31850]: info: MPD Permissions set Jan 25 21:43:10 volumio volumio[31850]: info: MPD Permissions set Jan 25 21:43:10 volumio volumio[31850]: info: Upmpdcli Daemon Started Jan 25 21:43:10 volumio volumio[31850]: info: Spotify config file written Jan 25 21:43:10 volumio sudo[32087]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jan 25 21:43:10 volumio sudo[32087]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 21:43:10 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 25 21:43:10 volumio volumio[31850]: 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 25 21:43:10 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 25 21:43:10 volumio go-librespot[32095]: go-librespot daemon starting... Jan 25 21:43:10 volumio volumio[31850]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 21:43:10 volumio volumio[31850]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 21:43:10 volumio volumio[31850]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 21:43:10 volumio volumio[31850]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 21:43:10 volumio volumio[31850]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 21:43:10 volumio volumio[31850]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 21:43:10 volumio volumio[31850]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 21:43:10 volumio sudo[32087]: pam_unix(sudo:session): session closed for user root Jan 25 21:43:10 volumio volumio[31850]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 21:43:10 volumio go-librespot[32096]: time="2026-01-25T21:43:10+07:00" level=info msg="running go-librespot 0.4.0" Jan 25 21:43:10 volumio go-librespot[32096]: time="2026-01-25T21:43:10+07:00" level=debug msg="app state loaded" Jan 25 21:43:10 volumio go-librespot[32096]: time="2026-01-25T21:43:10+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 25 21:43:10 volumio volumio[31850]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 25 21:43:10 volumio volumio[31850]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 21:43:10 volumio volumio[31850]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 21:43:10 volumio volumio[31850]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 21:43:10 volumio volumio[31850]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 21:43:10 volumio volumio[31850]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 21:43:10 volumio volumio[31850]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 21:43:10 volumio volumio[31850]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 21:43:10 volumio volumio[31850]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 21:43:10 volumio volumio[31850]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 21:43:10 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 25 21:43:10 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 25 21:43:10 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 25 21:43:11 volumio volumio[31850]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 25 21:43:11 volumio volumio[31850]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 21:43:11 volumio volumio[31850]: info: No need to fix Spotify hosts Jan 25 21:43:11 volumio go-librespot[32096]: time="2026-01-25T21:43:11+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 25 21:43:11 volumio go-librespot[32096]: time="2026-01-25T21:43:11+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 25 21:43:11 volumio go-librespot[32096]: time="2026-01-25T21:43:11+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 25 21:43:11 volumio volumio[31850]: info: Volumio called home Jan 25 21:43:11 volumio go-librespot[32096]: time="2026-01-25T21:43:11+07:00" level=info msg="zeroconf server listening on port 38807" Jan 25 21:43:11 volumio go-librespot[32096]: time="2026-01-25T21:43:11+07:00" level=debug msg="obtained new client token: AACkexLLxPnt1N8n7bsIKCp4hYd9vcw8ti1QP6K+OK4JAPhAvzxZ8w0Oa2Qj/+sG+Kkv7g0Ajcevx0q36RwimbY+Nk/OICAFfS9JdZPaPEatZcYEu718MuRDoc/cG+U2s4qEKd6LXL+NKYdIezt5bzcUdTMX6rOKgck/GUUGlYof4boNxDebzb0RvfF+UX7tBUmSxQuHRpRRiLyckThaubswK3jCAl1DOoYAL5mhJUf44yoCbX168ABPSxw=" Jan 25 21:43:11 volumio volumio[31850]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 25 21:43:11 volumio volumio[31850]: SPOTIFY: BQBfWk461110_6JBI2QJ3dUcmVlsHbNv10nrZ2iUCo3j3XZPIXaNVJIg5GIiCQtC_MmaWpNRYZ8uoEeB0ZXd74efOlFsY-0D-S5uNJV0afSXBN5esv6aZurzU7KzRICxLhBpH7pVTA7vSkCn0NZZn1vvJncnKfEybHMpZiBxR15RGHFx3RG1S1lU-DfbJ-GdL4Lj120KwBl-97RXH19QnNeO07hjEwMC8D1LqAHPXX9kvjX9vTlAiLcYRqDmIDwlNuH9UguHoORGXO-WAf3Tpn8brcviHfWaXfBIS3c9gA2XSSam9RspXh5w Jan 25 21:43:11 volumio volumio[31850]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 25 21:43:11 volumio volumio[31850]: info: New Spotify access token = BQBfWk461110_6JBI2QJ3dUcmVlsHbNv10nrZ2iUCo3j3XZPIXaNVJIg5GIiCQtC_MmaWpNRYZ8uoEeB0ZXd74efOlFsY-0D-S5uNJV0afSXBN5esv6aZurzU7KzRICxLhBpH7pVTA7vSkCn0NZZn1vvJncnKfEybHMpZiBxR15RGHFx3RG1S1lU-DfbJ-GdL4Lj120KwBl-97RXH19QnNeO07hjEwMC8D1LqAHPXX9kvjX9vTlAiLcYRqDmIDwlNuH9UguHoORGXO-WAf3Tpn8brcviHfWaXfBIS3c9gA2XSSam9RspXh5w Jan 25 21:43:11 volumio volumio[31850]: info: Spotify credentials grant success - running version from March 24, 2019 Jan 25 21:43:11 volumio go-librespot[32096]: time="2026-01-25T21:43:11+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 25 21:43:12 volumio go-librespot[32096]: time="2026-01-25T21:43:12+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 25 21:43:12 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 25 21:43:12 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 25 21:43:12 volumio volumio[31850]: info: Starting Shairport Sync Jan 25 21:43:12 volumio volumio[31850]: info: Starting Shairport Sync Jan 25 21:43:12 volumio volumio[31850]: info: Starting Shairport Sync Jan 25 21:43:12 volumio sudo[32128]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 25 21:43:12 volumio sudo[32128]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 21:43:12 volumio sudo[32133]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 25 21:43:12 volumio sudo[32133]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 21:43:12 volumio sudo[32130]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 25 21:43:12 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 25 21:43:12 volumio sudo[32130]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 21:43:12 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Jan 25 21:43:12 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 25 21:43:12 volumio systemd[1]: shairport-sync.service: Consumed 2.402s CPU time. Jan 25 21:43:12 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 25 21:43:12 volumio volumio[31850]: info: CoreCommandRouter::volumioGetState Jan 25 21:43:12 volumio volumio[31850]: info: CorePlayQueue::getTrack 0 Jan 25 21:43:12 volumio sudo[32128]: pam_unix(sudo:session): session closed for user root Jan 25 21:43:12 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 25 21:43:12 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Jan 25 21:43:12 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 25 21:43:12 volumio volumio[31850]: info: Shairport-Sync Started Jan 25 21:43:12 volumio volumio[31850]: Error adding Membership: Error: addMembership EINVAL Jan 25 21:43:12 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 25 21:43:12 volumio sudo[32133]: pam_unix(sudo:session): session closed for user root Jan 25 21:43:12 volumio sudo[32130]: pam_unix(sudo:session): session closed for user root Jan 25 21:43:12 volumio volumio[31850]: info: Shairport-Sync Started Jan 25 21:43:12 volumio volumio[31850]: info: Shairport-Sync Started Jan 25 21:43:12 volumio volumio[31850]: 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 25 21:43:12 volumio volumio[31850]: info: Spotify Successfully logged in Jan 25 21:43:12 volumio volumio[31850]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 25 21:43:12 volumio volumio[31850]: info: [1769352192720] CoreMusicLibrary::Adding element Spotify Jan 25 21:43:12 volumio volumio[31850]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 25 21:43:12 volumio volumio[31850]: Cannot find translation for source YouTube Music Jan 25 21:43:12 volumio volumio[31850]: Cannot find translation for source Spotify Jan 25 21:43:12 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 25 21:43:12 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 25 21:43:12 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 25 21:43:13 volumio volumio[31850]: info: [yt-cast-receiver] DIAL server listening on port 8098 Jan 25 21:43:13 volumio volumio[31850]: info: CoreCommandRouter::volumioRetrievevolume Jan 25 21:43:13 volumio volumio[31850]: info: VolumeController:: Volume=100 Mute =false Jan 25 21:43:13 volumio volumio[31850]: info: CoreCommandRouter::volumioGetState Jan 25 21:43:13 volumio volumio[31850]: info: CorePlayQueue::getTrack 0 Jan 25 21:43:13 volumio volumio[31850]: info: CoreStateMachine::pushState Jan 25 21:43:13 volumio volumio[31850]: info: CorePlayQueue::getTrack 0 Jan 25 21:43:13 volumio volumio[31850]: info: CoreCommandRouter::volumioPushState Jan 25 21:43:14 volumio volumio[31850]: info: go-librespot daemon successfully initialized Jan 25 21:43:14 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 25 21:43:14 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 25 21:43:14 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 25 21:43:15 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 11. Jan 25 21:43:15 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 25 21:43:15 volumio mpd[32079]: 2026-01-25T21:43:15 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 25 21:43:15 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 25 21:43:15 volumio go-librespot[32169]: go-librespot daemon starting... Jan 25 21:43:15 volumio systemd[1]: Started mpd.service - Music Player Daemon. Jan 25 21:43:15 volumio sudo[32046]: pam_unix(sudo:session): session closed for user root Jan 25 21:43:15 volumio sudo[32031]: pam_unix(sudo:session): session closed for user root Jan 25 21:43:15 volumio go-librespot[32172]: time="2026-01-25T21:43:15+07:00" level=info msg="running go-librespot 0.4.0" Jan 25 21:43:15 volumio go-librespot[32172]: time="2026-01-25T21:43:15+07:00" level=debug msg="app state loaded" Jan 25 21:43:15 volumio go-librespot[32172]: time="2026-01-25T21:43:15+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 25 21:43:15 volumio volumio[31850]: error: MPD error: The expression evaluated to a falsy value: Jan 25 21:43:15 volumio volumio[31850]: assert.ok(self.idling) Jan 25 21:43:15 volumio volumio[31850]: error: The expression evaluated to a falsy value: Jan 25 21:43:15 volumio volumio[31850]: assert.ok(self.idling) Jan 25 21:43:15 volumio volumio[31850]: error: updateQueue error: null Jan 25 21:43:15 volumio volumio[31850]: info: MPD running with PID32079 Jan 25 21:43:15 volumio volumio[31850]: ,establishing connection Jan 25 21:43:15 volumio volumio[31850]: info: Completed starting Core Plugins Jan 25 21:43:15 volumio volumio[31850]: info: ------------------------------------------- Jan 25 21:43:15 volumio volumio[31850]: info: ----- MyVolumio plugins startup ---- Jan 25 21:43:15 volumio volumio[31850]: info: ------------------------------------------- Jan 25 21:43:15 volumio volumio[31850]: info: [MyVolumio PluginManager] Fetching plans data.... Jan 25 21:43:15 volumio volumio[31850]: error: updateQueue error: null Jan 25 21:43:15 volumio go-librespot[32172]: time="2026-01-25T21:43:15+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 25 21:43:15 volumio go-librespot[32172]: time="2026-01-25T21:43:15+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 25 21:43:15 volumio go-librespot[32172]: time="2026-01-25T21:43:15+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 25 21:43:15 volumio go-librespot[32172]: time="2026-01-25T21:43:15+07:00" level=info msg="zeroconf server listening on port 34339" Jan 25 21:43:16 volumio go-librespot[32172]: time="2026-01-25T21:43:16+07:00" level=debug msg="obtained new client token: AAC9bFsuBLIFDf2mYRFifgE9Itfuu/XI9oWSQFPxAd+wiwrm72I8Hs1uebD4kGqwmGahWZEdrMTUYCJz45YrYyssy+v+4sUIyE2SCY1RkggA+y2ITwbs4nZIndOgYBf/PK2xuu6PlMSQNg+dIPoWlAPyRRIGVTgDXxnHDRrY0Bll2rPLagR+pqCwJgCkF75eGRUlT3dMARoOFG4uPkt7bBh2LQ/Ur42yykRnEUCBXjDhdoCjX2W4m39f" Jan 25 21:43:16 volumio go-librespot[32172]: time="2026-01-25T21:43:16+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 25 21:43:16 volumio go-librespot[32172]: time="2026-01-25T21:43:16+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 25 21:43:16 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 25 21:43:16 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 25 21:43:16 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 25 21:43:16 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 25 21:43:16 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 25 21:43:17 volumio volumio[31850]: info: Initializing connection to go-librespot Websocket Jan 25 21:43:17 volumio volumio[31850]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 25 21:43:18 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 25 21:43:18 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 25 21:43:18 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 25 21:43:19 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 12. Jan 25 21:43:19 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 25 21:43:19 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 25 21:43:19 volumio go-librespot[32181]: go-librespot daemon starting... Jan 25 21:43:19 volumio go-librespot[32182]: time="2026-01-25T21:43:19+07:00" level=info msg="running go-librespot 0.4.0" Jan 25 21:43:19 volumio go-librespot[32182]: time="2026-01-25T21:43:19+07:00" level=debug msg="app state loaded" Jan 25 21:43:19 volumio go-librespot[32182]: time="2026-01-25T21:43:19+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 25 21:43:20 volumio go-librespot[32182]: time="2026-01-25T21:43:20+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 25 21:43:20 volumio go-librespot[32182]: time="2026-01-25T21:43:20+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 25 21:43:20 volumio go-librespot[32182]: time="2026-01-25T21:43:20+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 25 21:43:20 volumio go-librespot[32182]: time="2026-01-25T21:43:20+07:00" level=info msg="zeroconf server listening on port 35101" Jan 25 21:43:20 volumio go-librespot[32182]: time="2026-01-25T21:43:20+07:00" level=debug msg="obtained new client token: AADGKBtfEZFmFV7skDSn5EsKaH8ZXuaE1Ttv8ntooHK9NvQtZsa84mXZQ9Dq+b1AHQx/gh61e+xDBlgI+fxYDd9WZIrocEY1Y+BPK/MCXyFdRuANWmvZ8Mnha48fZcDoliO/LsOzqR0a2X9roFJf90Tc5Ufvm3iGfvKGpTDbtigbTkXqyNNiZt33L/PLRxawD23/85BFzBvmzVnTX9+08l9GvaOcudBMQ6Gh07UCfs4u2zIzlyfSkVuj" Jan 25 21:43:20 volumio go-librespot[32182]: time="2026-01-25T21:43:20+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 25 21:43:20 volumio volumio[31850]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Jan 25 21:43:20 volumio go-librespot[32182]: time="2026-01-25T21:43:20+07:00" level=debug msg="completed keyexchange" Jan 25 21:43:20 volumio go-librespot[32182]: time="2026-01-25T21:43:20+07:00" level=debug msg="completed challenge" Jan 25 21:43:20 volumio go-librespot[32182]: time="2026-01-25T21:43:20+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 25 21:43:20 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 25 21:43:20 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 25 21:43:20 volumio volumio[31850]: info: Initializing connection to go-librespot Websocket Jan 25 21:43:20 volumio volumio[31850]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 25 21:43:20 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 25 21:43:20 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 25 21:43:20 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 25 21:43:22 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 25 21:43:22 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 25 21:43:22 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 25 21:43:23 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 13. Jan 25 21:43:23 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 25 21:43:23 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 25 21:43:23 volumio go-librespot[32189]: go-librespot daemon starting... Jan 25 21:43:23 volumio go-librespot[32190]: time="2026-01-25T21:43:23+07:00" level=info msg="running go-librespot 0.4.0" Jan 25 21:43:23 volumio go-librespot[32190]: time="2026-01-25T21:43:23+07:00" level=debug msg="app state loaded" Jan 25 21:43:23 volumio go-librespot[32190]: time="2026-01-25T21:43:23+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 25 21:43:23 volumio volumio[31850]: info: Initializing connection to go-librespot Websocket Jan 25 21:43:23 volumio go-librespot[32190]: time="2026-01-25T21:43:23+07:00" level=debug msg="new websocket client" Jan 25 21:43:23 volumio volumio[31850]: info: Connection to go-librespot Websocket established Jan 25 21:43:24 volumio go-librespot[32190]: time="2026-01-25T21:43: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 25 21:43:24 volumio go-librespot[32190]: time="2026-01-25T21:43: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 25 21:43:24 volumio go-librespot[32190]: time="2026-01-25T21:43: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 25 21:43:24 volumio go-librespot[32190]: time="2026-01-25T21:43:24+07:00" level=info msg="zeroconf server listening on port 39673" Jan 25 21:43:24 volumio go-librespot[32190]: time="2026-01-25T21:43:24+07:00" level=debug msg="obtained new client token: AACWTQvY+LM5TE6nCriwHjiUEQtI84e2cy9welWpfGMPBGcpe+d1OumYJCni+fdjgahNEgxSlFylQEaco1bABBw/6eOcPAsFIR2XWMD41MdOSUNlLUgWKsekBS/qVmE0atWfbw4FWDuciIR2/d8feCJjmPYuiqb06ZPCQne86dcFdzXS6Ea/ZpiHgJP9jCBMcOdoJF7FuSFwYA7okPnsc4fqa/YvINjSEzxpyKds9qQrExB/g+WJAbCrakw=" Jan 25 21:43:24 volumio go-librespot[32190]: time="2026-01-25T21:43:24+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 25 21:43:24 volumio go-librespot[32190]: time="2026-01-25T21:43:24+07:00" level=debug msg="completed keyexchange" Jan 25 21:43:24 volumio go-librespot[32190]: time="2026-01-25T21:43:24+07:00" level=debug msg="completed challenge" Jan 25 21:43:24 volumio go-librespot[32190]: time="2026-01-25T21:43:24+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 25 21:43:24 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 25 21:43:24 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 25 21:43:24 volumio volumio[31850]: info: Connection to go-librespot Websocket closed Jan 25 21:43:24 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 25 21:43:24 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 25 21:43:24 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 25 21:43:25 volumio volumio[31850]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Jan 25 21:43:25 volumio volumio[31850]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Jan 25 21:43:25 volumio volumio[31850]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Jan 25 21:43:25 volumio volumio[31850]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Jan 25 21:43:25 volumio volumio[31850]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Jan 25 21:43:25 volumio volumio[31850]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Jan 25 21:43:25 volumio volumio[31850]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Jan 25 21:43:25 volumio volumio[31850]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Jan 25 21:43:25 volumio volumio[31850]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Jan 25 21:43:25 volumio volumio[31850]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Jan 25 21:43:25 volumio volumio[31850]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Jan 25 21:43:25 volumio volumio[31850]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Jan 25 21:43:25 volumio volumio[31850]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Jan 25 21:43:25 volumio volumio[31850]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Jan 25 21:43:25 volumio volumio[31850]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Jan 25 21:43:25 volumio volumio[31850]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Jan 25 21:43:25 volumio volumio[31850]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Jan 25 21:43:25 volumio volumio[31850]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Jan 25 21:43:25 volumio volumio[31850]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Jan 25 21:43:25 volumio volumio[31850]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Jan 25 21:43:25 volumio volumio[31850]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Jan 25 21:43:25 volumio volumio[31850]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Jan 25 21:43:25 volumio volumio[31850]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Jan 25 21:43:25 volumio volumio[31850]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Jan 25 21:43:25 volumio volumio[31850]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Jan 25 21:43:25 volumio volumio[31850]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Jan 25 21:43:25 volumio volumio[31850]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Jan 25 21:43:25 volumio volumio[31850]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Jan 25 21:43:25 volumio volumio[31850]: info: Adding plugin bluetooth to MyMusic Plugins Jan 25 21:43:25 volumio volumio[31850]: info: Adding plugin multiroom to MyMusic Plugins Jan 25 21:43:25 volumio volumio[31850]: info: Adding plugin metavolumio to MyMusic Plugins Jan 25 21:43:25 volumio volumio[31850]: info: Adding plugin cd_controller to MyMusic Plugins Jan 25 21:43:25 volumio volumio[31850]: info: Adding plugin qobuzconnect to MyMusic Plugins Jan 25 21:43:25 volumio volumio[31850]: info: Adding plugin smart_inputs to MyMusic Plugins Jan 25 21:43:25 volumio volumio[31850]: info: Adding plugin tidalconnect to MyMusic Plugins Jan 25 21:43:25 volumio volumio[31850]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Jan 25 21:43:26 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 25 21:43:26 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 25 21:43:26 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 25 21:43:27 volumio volumio[31850]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Jan 25 21:43:27 volumio volumio[31850]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Jan 25 21:43:27 volumio volumio[31850]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 25 21:43:27 volumio volumio[31850]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 25 21:43:27 volumio volumio[31850]: info: Starting MyVolumio Remote Streaming Endpoints Jan 25 21:43:27 volumio volumio[31850]: info: MyVolumio login type: Token Jan 25 21:43:27 volumio volumio[31850]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Jan 25 21:43:27 volumio volumio[31850]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Jan 25 21:43:27 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 14. Jan 25 21:43:27 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 25 21:43:28 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 25 21:43:28 volumio go-librespot[32211]: go-librespot daemon starting... Jan 25 21:43:28 volumio go-librespot[32212]: time="2026-01-25T21:43:28+07:00" level=info msg="running go-librespot 0.4.0" Jan 25 21:43:28 volumio go-librespot[32212]: time="2026-01-25T21:43:28+07:00" level=debug msg="app state loaded" Jan 25 21:43:28 volumio go-librespot[32212]: time="2026-01-25T21:43:28+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 25 21:43:28 volumio go-librespot[32212]: time="2026-01-25T21:43:28+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 25 21:43:28 volumio go-librespot[32212]: time="2026-01-25T21:43:28+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Jan 25 21:43:28 volumio go-librespot[32212]: time="2026-01-25T21:43:28+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Jan 25 21:43:28 volumio go-librespot[32212]: time="2026-01-25T21:43:28+07:00" level=info msg="zeroconf server listening on port 43095" Jan 25 21:43:28 volumio go-librespot[32212]: time="2026-01-25T21:43:28+07:00" level=debug msg="obtained new client token: AAC7X8lpBEhxqaJgck0lYkqxo167rqeWt9wTpeV13NCt2e9bHrdqj2zsBEMKBk3XzvhqjlUmkoDR5NyqSVI5ZCZ5QYnRFq9ZeVrUTz0xQdAfMjOYAWZMxc1RkKMV1HN8FuaYIvlh+4O4VV503Yvz55F0jl8k6ZWoP/OL38xzbn56Eh94CIS2T7Wsx+o0U6+9DVZr2F9TcHHzhGKE6hfqv2DsjUWi7CPzk82SK/hMP/VSqmEplboIiIogVDg=" Jan 25 21:43:28 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 25 21:43:28 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 25 21:43:28 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 25 21:43:29 volumio volumio[31850]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Jan 25 21:43:29 volumio volumio[31850]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Jan 25 21:43:29 volumio volumio[31850]: info: Streaming services startup Jan 25 21:43:29 volumio volumio[31850]: info: Starting Streaming Daemon Jan 25 21:43:29 volumio go-librespot[32212]: time="2026-01-25T21:43:29+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 25 21:43:29 volumio volumio[31850]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Jan 25 21:43:29 volumio sudo[32220]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jan 25 21:43:29 volumio sudo[32220]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 21:43:29 volumio go-librespot[32212]: time="2026-01-25T21:43:29+07:00" level=debug msg="completed keyexchange" Jan 25 21:43:29 volumio go-librespot[32212]: time="2026-01-25T21:43:29+07:00" level=debug msg="completed challenge" Jan 25 21:43:29 volumio sudo[32220]: pam_unix(sudo:session): session closed for user root Jan 25 21:43:29 volumio volumio[31850]: info: Getting Spotify volume Jan 25 21:43:29 volumio volumio[31850]: info: Initializing connection to go-librespot Websocket Jan 25 21:43:29 volumio go-librespot[32212]: time="2026-01-25T21:43: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 25 21:43:29 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 25 21:43:29 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 25 21:43:29 volumio volumio[31850]: error: Cannot start Volumio Streaming Daemon Jan 25 21:43:29 volumio volumio[31850]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Jan 25 21:43:29 volumio volumio[31850]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Jan 25 21:43:29 volumio volumio[31850]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 25 21:43:29 volumio volumio[31850]: Error: socket hang up Jan 25 21:43:29 volumio volumio[31850]: at connResetException (node:internal/errors:720:14) Jan 25 21:43:29 volumio volumio[31850]: at Socket.socketOnEnd (node:_http_client:519:23) Jan 25 21:43:29 volumio volumio[31850]: at Socket.emit (node:events:526:35) Jan 25 21:43:29 volumio volumio[31850]: at endReadableNT (node:internal/streams/readable:1376:12) Jan 25 21:43:29 volumio volumio[31850]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Jan 25 21:43:29 volumio volumio[31850]: code: 'ECONNRESET', Jan 25 21:43:29 volumio volumio[31850]: response: undefined Jan 25 21:43:29 volumio volumio[31850]: } Jan 25 21:43:29 volumio volumio[31850]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 25 21:43:30 volumio sudo[32241]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-01-25 21:42' Jan 25 21:43:30 volumio sudo[32241]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 21:43:30 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 25 21:43:30 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 25 21:43:30 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 PRETTY_NAME="Raspbian GNU/Linux 12 (bookworm)" NAME="Raspbian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="b05a530ca81d05eb9a84d0acf82089f0a60b8ee6" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="4ad85e2147d972f0b838d33c21382d2d813b2ae8" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu Dec 25 09:13:19 UTC 2025" VOLUMIO_VERSION="4.084" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="792f09af7488531aecd1aadcaa9b175e"