Jan 28 23:06:00 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 23:06:00 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 23:06:00 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 23:06:01 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 16. Jan 28 23:06:01 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 23:06:01 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 23:06:01 volumio go-librespot[23373]: go-librespot daemon starting... Jan 28 23:06:01 volumio go-librespot[23374]: time="2026-01-28T23:06:01+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 23:06:01 volumio go-librespot[23374]: time="2026-01-28T23:06:01+07:00" level=debug msg="app state loaded" Jan 28 23:06:01 volumio go-librespot[23374]: time="2026-01-28T23:06:01+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 23:06:02 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 23:06:02 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 23:06:02 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 23:06:02 volumio go-librespot[23374]: time="2026-01-28T23:06:02+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 28 23:06:02 volumio go-librespot[23374]: time="2026-01-28T23:06:02+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Jan 28 23:06:02 volumio go-librespot[23374]: time="2026-01-28T23:06:02+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Jan 28 23:06:02 volumio go-librespot[23374]: time="2026-01-28T23:06:02+07:00" level=info msg="zeroconf server listening on port 44843" Jan 28 23:06:02 volumio volumio[23358]: info: ------------------------------------------- Jan 28 23:06:02 volumio volumio[23358]: info: ----- Volumio3 ---- Jan 28 23:06:02 volumio volumio[23358]: info: ------------------------------------------- Jan 28 23:06:02 volumio volumio[23358]: info: ----- System startup ---- Jan 28 23:06:02 volumio volumio[23358]: info: ------------------------------------------- Jan 28 23:06:02 volumio go-librespot[23374]: time="2026-01-28T23:06:02+07:00" level=debug msg="obtained new client token: AAAYJxmrMyIiKv9R6iqVW4gaBTd1J3x6OIGV9dp11tBoRWK5/7XF7Lw8muoyLHD1wy5G6F4sfI21p52RXVKJP4kRgzMJiosz9l8egPdivT/T3SHBDROaZoyTM3uogCnot3iBR3zhLkd1O9gtFxT0RBR1MadGI3UgAZLcPUc5VMHgJlILC6bCCCjWJoYH80SQrnjRupQ1pWgQENiBvDp5C/SYuUd7OsuG5pCHWuAc1XQenp3/KJdWdSb1DMY=" Jan 28 23:06:02 volumio go-librespot[23374]: time="2026-01-28T23:06:02+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 23:06:03 volumio go-librespot[23374]: time="2026-01-28T23:06:03+07:00" level=debug msg="completed keyexchange" Jan 28 23:06:03 volumio go-librespot[23374]: time="2026-01-28T23:06:03+07:00" level=debug msg="completed challenge" Jan 28 23:06:03 volumio go-librespot[23374]: time="2026-01-28T23:06:03+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 23:06:03 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 23:06:03 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 23:06:03 volumio volumio-remote-updater[628]: [2026-01-28 23:06:03] [connect] Successful connection Jan 28 23:06:04 volumio volumio[23358]: info: MYVOLUMIO Environment detected Jan 28 23:06:04 volumio volumio[23358]: info: Plugin folders cleanup Jan 28 23:06:04 volumio volumio[23358]: info: Scanning into folder /volumio/app/plugins/ Jan 28 23:06:04 volumio volumio[23358]: info: Scanning category audio_interface Jan 28 23:06:04 volumio volumio[23358]: info: Scanning category miscellanea Jan 28 23:06:04 volumio volumio[23358]: info: Scanning category music_service Jan 28 23:06:04 volumio volumio[23358]: info: Scanning category plugins.json Jan 28 23:06:04 volumio volumio[23358]: info: Scanning category system_controller Jan 28 23:06:04 volumio volumio[23358]: info: Scanning category user_interface Jan 28 23:06:04 volumio volumio[23358]: info: Scanning into folder /data/plugins/ Jan 28 23:06:04 volumio volumio[23358]: info: Scanning category music_service Jan 28 23:06:04 volumio volumio[23358]: info: Plugin folders cleanup completed Jan 28 23:06:04 volumio volumio[23358]: info: ------------------------------------------- Jan 28 23:06:04 volumio volumio[23358]: info: ----- Core plugins startup ---- Jan 28 23:06:04 volumio volumio[23358]: info: ------------------------------------------- Jan 28 23:06:04 volumio volumio[23358]: info: Loading plugins from folder /volumio/app/plugins/ Jan 28 23:06:04 volumio volumio[23358]: info: Adding plugin upnp to MyMusic Plugins Jan 28 23:06:04 volumio volumio[23358]: info: Adding plugin airplay_emulation to MyMusic Plugins Jan 28 23:06:04 volumio volumio[23358]: info: Adding plugin upnp_browser to MyMusic Plugins Jan 28 23:06:04 volumio volumio[23358]: info: Loading plugins from folder /data/plugins/ Jan 28 23:06:04 volumio volumio[23358]: info: Loading plugin "system"... Jan 28 23:06:04 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 23:06:04 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 23:06:04 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 23:06:04 volumio volumio[23358]: info: Loading plugin "appearance"... Jan 28 23:06:06 volumio volumio[23358]: info: Loading plugin "network"... Jan 28 23:06:06 volumio volumio[23358]: info: Refreshing Cached IP Addresses Jan 28 23:06:06 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 17. Jan 28 23:06:06 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 23:06:06 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 23:06:06 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 23:06:06 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 23:06:06 volumio sudo[23394]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 28 23:06:06 volumio sudo[23394]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 23:06:06 volumio sudo[23396]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 28 23:06:06 volumio sudo[23396]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 23:06:06 volumio sudo[23394]: pam_unix(sudo:session): session closed for user root Jan 28 23:06:06 volumio volumio[23358]: info: Loading plugin "services"... Jan 28 23:06:06 volumio sudo[23396]: pam_unix(sudo:session): session closed for user root Jan 28 23:06:06 volumio volumio[23358]: info: Loading plugin "alsa_controller"... Jan 28 23:06:06 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 23:06:06 volumio go-librespot[23401]: go-librespot daemon starting... Jan 28 23:06:06 volumio sudo[23408]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Jan 28 23:06:06 volumio sudo[23408]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 23:06:06 volumio go-librespot[23417]: time="2026-01-28T23:06:06+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 23:06:06 volumio go-librespot[23417]: time="2026-01-28T23:06:06+07:00" level=debug msg="app state loaded" Jan 28 23:06:06 volumio go-librespot[23417]: time="2026-01-28T23:06:06+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 23:06:06 volumio volumio[23358]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 28 23:06:06 volumio volumio[23358]: info: Loading plugin "wizard"... Jan 28 23:06:06 volumio volumio[23358]: info: Loading plugin "networkfs"... Jan 28 23:06:06 volumio volumio[23358]: info: Starting Udev Watcher for removable devices Jan 28 23:06:06 volumio volumio[23358]: info: Ignoring mount for partition: boot Jan 28 23:06:06 volumio volumio[23358]: info: Ignoring mount for partition: volumio Jan 28 23:06:06 volumio volumio[23358]: info: Ignoring mount for partition: volumio_data Jan 28 23:06:06 volumio volumio[23358]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 28 23:06:06 volumio volumio[23358]: info: Loading plugin "volumio_command_line_client"... Jan 28 23:06:06 volumio volumio[23358]: info: Loading plugin "upnp"... Jan 28 23:06:06 volumio volumio[23358]: info: [1769616366631] Starting Upmpd Daemon Jan 28 23:06:06 volumio volumio[23358]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 28 23:06:06 volumio volumio[23358]: info: Loading plugin "my_music"... Jan 28 23:06:06 volumio volumio[23358]: info: Loading plugin "mpd"... Jan 28 23:06:06 volumio go-librespot[23417]: time="2026-01-28T23:06:06+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 23:06:06 volumio go-librespot[23417]: time="2026-01-28T23:06:06+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 28 23:06:06 volumio go-librespot[23417]: time="2026-01-28T23:06:06+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 28 23:06:06 volumio go-librespot[23417]: time="2026-01-28T23:06:06+07:00" level=info msg="zeroconf server listening on port 39841" Jan 28 23:06:07 volumio go-librespot[23417]: time="2026-01-28T23:06:07+07:00" level=debug msg="obtained new client token: AAByNX7NhFt8ssn5eVic3BIFUJqwgZ66Z9BAQ3WCZhOielzycrsb7RcA78q2pjlKNvWy4CY7Gdbf5v++ObmXaPbq6jnDUCSbBiJPTcsD5C1VOSPWspe7rti2XA0ZqCrAm0XrvirUSsBx8i69/96o5+AuGPwDH2okDQ/tTBp6yD6vWqIRdKDYsSYtmIXscOs+vYcoIiuE/zySyOIOfBH5r2nQFa+0hk0njLucaOEihjJjRdYJQERUUQo/" Jan 28 23:06:07 volumio go-librespot[23417]: time="2026-01-28T23:06:07+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 23:06:07 volumio volumio[23358]: info: Loading plugin "upnp_browser"... Jan 28 23:06:07 volumio go-librespot[23417]: time="2026-01-28T23:06:07+07:00" level=debug msg="completed keyexchange" Jan 28 23:06:07 volumio go-librespot[23417]: time="2026-01-28T23:06:07+07:00" level=debug msg="completed challenge" Jan 28 23:06:07 volumio go-librespot[23417]: time="2026-01-28T23:06:07+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 23:06:07 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 23:06:07 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 23:06:08 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 23:06:08 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 23:06:08 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 23:06:09 volumio sudo[23408]: pam_unix(sudo:session): session closed for user root Jan 28 23:06:10 volumio volumio[23358]: info: Starting UPNP Browser Jan 28 23:06:10 volumio volumio[23358]: info: Loading plugin "alarm-clock"... Jan 28 23:06:10 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 23:06:10 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 23:06:10 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 23:06:10 volumio volumio[23358]: info: Loading plugin "airplay_emulation"... Jan 28 23:06:10 volumio volumio[23358]: info: Starting Shairport Sync Jan 28 23:06:10 volumio volumio[23358]: info: Loading plugin "last_100"... Jan 28 23:06:10 volumio volumio[23358]: info: Loading plugin "webradio"... Jan 28 23:06:10 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 18. Jan 28 23:06:10 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 23:06:10 volumio volumio[23358]: info: Loading plugin "i2s_dacs"... Jan 28 23:06:10 volumio volumio[23358]: info: Loading plugin "volumiodiscovery"... Jan 28 23:06:10 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 23:06:10 volumio go-librespot[23436]: go-librespot daemon starting... Jan 28 23:06:10 volumio volumio[23358]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 28 23:06:10 volumio volumio[23358]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 23:06:10 volumio volumio[23358]: *** WARNING *** For more information see Jan 28 23:06:10 volumio volumio[23358]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 28 23:06:10 volumio volumio[23358]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 23:06:10 volumio volumio[23358]: *** WARNING *** For more information see Jan 28 23:06:10 volumio node[23358]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 28 23:06:10 volumio node[23358]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 23:06:10 volumio node[23358]: *** WARNING *** For more information see Jan 28 23:06:10 volumio node[23358]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 28 23:06:10 volumio node[23358]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 23:06:10 volumio node[23358]: *** WARNING *** For more information see Jan 28 23:06:10 volumio go-librespot[23437]: time="2026-01-28T23:06:10+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 23:06:10 volumio go-librespot[23437]: time="2026-01-28T23:06:10+07:00" level=debug msg="app state loaded" Jan 28 23:06:10 volumio volumio[23358]: info: Applying required configuration parameters for plugin volumiodiscovery Jan 28 23:06:10 volumio go-librespot[23437]: time="2026-01-28T23:06:10+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 23:06:10 volumio volumio[23358]: info: Discovery: Started advertising with name: Volumio Jan 28 23:06:10 volumio volumio[23358]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 28 23:06:10 volumio volumio[23358]: info: Loading plugin "spop"... Jan 28 23:06:11 volumio go-librespot[23437]: time="2026-01-28T23:06: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 28 23:06:11 volumio go-librespot[23437]: time="2026-01-28T23:06: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 28 23:06:11 volumio go-librespot[23437]: time="2026-01-28T23:06: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 28 23:06:11 volumio go-librespot[23437]: time="2026-01-28T23:06:11+07:00" level=info msg="zeroconf server listening on port 41925" Jan 28 23:06:11 volumio go-librespot[23437]: time="2026-01-28T23:06:11+07:00" level=debug msg="obtained new client token: AAC9I1KdFVg/h4rEEKzXeGf4NKdlddpI3AxD6uDCRm93Ch5RnJuDP6Ok5kUZvVPuUsZSBQSIr3wdfJBjAo4uQMjxy51D/yilLph5A5k2Z8YzUYXJxzr7zP34xW93Xgf2nG0QGZr60UGGt1ChM6/Io2z0XdaLMT64flDqumowr3AmcvPZEDcf/Wo92DN1SQPV2auUfPUZ4eCRIbT8Nr+vspaGat7+nIF9bRl8WsUG2xeFXHKNwI8UwyxbjKk=" Jan 28 23:06:11 volumio go-librespot[23437]: time="2026-01-28T23:06:11+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 23:06:11 volumio go-librespot[23437]: time="2026-01-28T23:06:11+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Jan 28 23:06:11 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 23:06:11 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 23:06:12 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 23:06:12 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 23:06:12 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 23:06:12 volumio volumio[23358]: info: Loading plugin "ytcr"... Jan 28 23:06:14 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 23:06:14 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 23:06:14 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 23:06:14 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 19. Jan 28 23:06:14 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 23:06:15 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 23:06:15 volumio go-librespot[23447]: go-librespot daemon starting... Jan 28 23:06:15 volumio go-librespot[23448]: time="2026-01-28T23:06:15+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 23:06:15 volumio go-librespot[23448]: time="2026-01-28T23:06:15+07:00" level=debug msg="app state loaded" Jan 28 23:06:15 volumio go-librespot[23448]: time="2026-01-28T23:06:15+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 23:06:15 volumio volumio[23358]: info: Loading plugin "ytmusic"... Jan 28 23:06:15 volumio go-librespot[23448]: time="2026-01-28T23:06: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-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 23:06:15 volumio go-librespot[23448]: time="2026-01-28T23:06:15+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 28 23:06:15 volumio go-librespot[23448]: time="2026-01-28T23:06:15+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 28 23:06:15 volumio go-librespot[23448]: time="2026-01-28T23:06:15+07:00" level=info msg="zeroconf server listening on port 41037" Jan 28 23:06:15 volumio go-librespot[23448]: time="2026-01-28T23:06:15+07:00" level=debug msg="obtained new client token: AACV3qJJsVUXYUlbIK+R+Yj8b2tdNSVmuqIRtGC97SGvrTbQCquMRXjq4l1UFFP1aAMiZamB+4eRy9AhR8njm3heu18twVwPSaweXeINO6qbzPLr77Z5YFYemBpJadBTM33utkguegq5Kim4o3H3PpsBqaFKa5mpAY6IQZThu3i1AHcp2Xn78NZNoAgqh+0VTm/DR3MyzoaX+dVsCyvTKa5i68BFCviRdfKq/DYbaWAUSNJbfO8Ly28f8cg=" Jan 28 23:06:15 volumio go-librespot[23448]: time="2026-01-28T23:06:15+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 23:06:16 volumio go-librespot[23448]: time="2026-01-28T23:06: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 28 23:06:16 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 23:06:16 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 23:06:16 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 23:06:16 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 23:06:16 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 23:06:16 volumio volumio-remote-updater[628]: [2026-01-28 23:06:16] [connect] Successful connection Jan 28 23:06:16 volumio volumio[23358]: info: Loading plugin "outputs"... Jan 28 23:06:16 volumio volumio[23358]: info: Loading plugin "albumart"... Jan 28 23:06:16 volumio volumio[23358]: info: Plugin example_plugin is not enabled Jan 28 23:06:16 volumio volumio[23358]: info: Loading plugin "inputs"... Jan 28 23:06:16 volumio volumio[23358]: info: Loading plugin "updater_comm"... Jan 28 23:06:16 volumio volumio[23358]: info: Plugin mpdemulation is not enabled Jan 28 23:06:16 volumio volumio[23358]: info: Loading plugin "rest_api"... Jan 28 23:06:16 volumio volumio[23358]: info: Loading plugin "websocket"... Jan 28 23:06:16 volumio volumio[23358]: info: Starting Socket.io Server version 1.7.4 Jan 28 23:06:16 volumio volumio[23358]: info: Loading plugin "RoonBridge"... Jan 28 23:06:17 volumio volumio[23358]: info: Applying required configuration parameters for plugin RoonBridge Jan 28 23:06:17 volumio volumio[23358]: info: Loading i18n strings for locale en Jan 28 23:06:17 volumio volumio[23358]: Updating browse sources language Jan 28 23:06:17 volumio volumio[23358]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 23:06:17 volumio volumio[23469]: Forking 3 albumart workers Jan 28 23:06:17 volumio volumio[23358]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 28 23:06:17 volumio volumio[23358]: info: CoreCommandRouter::initPlayerControls Jan 28 23:06:17 volumio volumio[23358]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 23:06:17 volumio volumio[23358]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 23:06:17 volumio volumio[23358]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 23:06:17 volumio volumio[23358]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 23:06:17 volumio volumio[23358]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 23:06:17 volumio volumio[23358]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 23:06:17 volumio volumio[23358]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 23:06:17 volumio volumio[23358]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 23:06:17 volumio volumio[23358]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 28 23:06:17 volumio volumio[23358]: Express server listening on port 3000 Jan 28 23:06:17 volumio volumio[23358]: [Metrics] WebUI: 16s 137.12ms Jan 28 23:06:17 volumio volumio[23358]: info: CoreStateMachine::resetVolumioState Jan 28 23:06:17 volumio volumio[23358]: info: CoreStateMachine::getcurrentVolume Jan 28 23:06:17 volumio volumio[23358]: info: CoreCommandRouter::volumioRetrievevolume Jan 28 23:06:18 volumio sudo[23513]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 28 23:06:18 volumio sudo[23513]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 23:06:18 volumio sudo[23513]: pam_unix(sudo:session): session closed for user root Jan 28 23:06:18 volumio volumio[23358]: info: Volumio Network Manager: Network status updated: 1 Jan 28 23:06:18 volumio sudo[23516]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 28 23:06:18 volumio sudo[23516]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 23:06:18 volumio sudo[23516]: pam_unix(sudo:session): session closed for user root Jan 28 23:06:18 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 23:06:18 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 23:06:18 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 23:06:18 volumio volumio[23358]: info: VolumeController:: Volume=100 Mute =false Jan 28 23:06:18 volumio volumio[23358]: info: CoreStateMachine::pushState Jan 28 23:06:18 volumio volumio[23358]: info: CorePlayQueue::getTrack 0 Jan 28 23:06:18 volumio volumio[23358]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 28 23:06:18 volumio volumio[23358]: info: CoreCommandRouter::volumioPushState Jan 28 23:06:18 volumio volumio[23358]: info: CoreStateMachine::updateTrackBlock Jan 28 23:06:18 volumio volumio[23358]: info: CorePlayQueue::getTrackBlock Jan 28 23:06:18 volumio volumio[23358]: info: CoreCommandRouter::volumioRetrievevolume Jan 28 23:06:18 volumio volumio-remote-updater[628]: [2026-01-28 23:06:18] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1769616376 101 Jan 28 23:06:18 volumio volumio[23358]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 1 Jan 28 23:06:18 volumio volumio[23358]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 23:06:18 volumio volumio[23358]: info: Reloading queue from file Jan 28 23:06:18 volumio volumio[23358]: info: CoreStateMachine::setRepeat null single undefined Jan 28 23:06:18 volumio volumio[23358]: info: CoreStateMachine::pushState Jan 28 23:06:18 volumio volumio[23358]: info: CorePlayQueue::getTrack 0 Jan 28 23:06:18 volumio volumio[23358]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 28 23:06:18 volumio volumio[23358]: info: CoreCommandRouter::volumioPushState Jan 28 23:06:18 volumio volumio[23358]: info: CoreStateMachine::setRandom null Jan 28 23:06:18 volumio volumio[23358]: info: CoreStateMachine::pushState Jan 28 23:06:18 volumio volumio[23358]: info: CorePlayQueue::getTrack 0 Jan 28 23:06:18 volumio volumio[23358]: info: CoreCommandRouter::volumioPushState Jan 28 23:06:18 volumio volumio[23358]: info: Setting Device type: Raspberry PI Jan 28 23:06:18 volumio volumio[23358]: info: Completed loading Core Plugins Jan 28 23:06:18 volumio volumio[23358]: info: Preparing to generate the ALSA configuration file Jan 28 23:06:18 volumio volumio[23358]: info: VolumeController:: Volume=100 Mute =false Jan 28 23:06:18 volumio volumio[23358]: info: CoreStateMachine::pushState Jan 28 23:06:18 volumio volumio[23358]: info: CorePlayQueue::getTrack 0 Jan 28 23:06:18 volumio volumio[23358]: info: CoreCommandRouter::volumioPushState Jan 28 23:06:18 volumio volumio[23358]: info: Asound.conf file unchanged, so no further update is needed Jan 28 23:06:18 volumio volumio[23358]: info: Output device has changed, restarting MPD Jan 28 23:06:18 volumio sudo[23530]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Jan 28 23:06:18 volumio sudo[23530]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 23:06:18 volumio volumio[23358]: info: Output device has changed, restarting Shairport Sync Jan 28 23:06:18 volumio volumio[23358]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 23:06:18 volumio volumio[23358]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 23:06:19 volumio sudo[23532]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 28 23:06:19 volumio sudo[23532]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 23:06:19 volumio sudo[23532]: pam_unix(sudo:session): session closed for user root Jan 28 23:06:19 volumio volumio[23358]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 28 23:06:19 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 20. Jan 28 23:06:19 volumio volumio[23358]: info: ___________ START PLUGINS ___________ Jan 28 23:06:19 volumio sudo[23535]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 28 23:06:19 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 23:06:19 volumio sudo[23535]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 23:06:19 volumio volumio[23358]: info: ControllerMpd::onStart: Initializing MPD Jan 28 23:06:19 volumio volumio[23358]: info: Creating MPD Configuration file Jan 28 23:06:19 volumio volumio[23358]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 28 23:06:19 volumio volumio[23358]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 23:06:19 volumio volumio[23358]: info: [1769616379167] CoreMusicLibrary::Adding element Media Servers Jan 28 23:06:19 volumio volumio[23358]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 23:06:19 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 23:06:19 volumio go-librespot[23542]: go-librespot daemon starting... Jan 28 23:06:19 volumio sudo[23530]: pam_unix(sudo:session): session closed for user root Jan 28 23:06:19 volumio sudo[23544]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 28 23:06:19 volumio sudo[23544]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 23:06:19 volumio volumio[23358]: info: UPNP Browser: Client initialized successfully Jan 28 23:06:19 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Jan 28 23:06:19 volumio go-librespot[23547]: time="2026-01-28T23:06:19+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 23:06:19 volumio go-librespot[23547]: time="2026-01-28T23:06:19+07:00" level=debug msg="app state loaded" Jan 28 23:06:19 volumio go-librespot[23547]: time="2026-01-28T23:06:19+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 23:06:19 volumio sudo[23544]: pam_unix(sudo:session): session closed for user root Jan 28 23:06:19 volumio volumio[23358]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 23:06:19 volumio volumio[23358]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 23:06:19 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 28 23:06:19 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 28 23:06:19 volumio systemd[1]: mpd.service: Consumed 7.299s CPU time. Jan 28 23:06:19 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 28 23:06:19 volumio sudo[23546]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 28 23:06:19 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 28 23:06:19 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 28 23:06:19 volumio sudo[23546]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 23:06:19 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 28 23:06:19 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 28 23:06:19 volumio volumio[23358]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 28 23:06:19 volumio volumio[23358]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 23:06:19 volumio volumio[23358]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 23:06:19 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 28 23:06:19 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 28 23:06:19 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 28 23:06:19 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 28 23:06:19 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 28 23:06:19 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 28 23:06:19 volumio volumio[23358]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 28 23:06:19 volumio volumio[23358]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 23:06:19 volumio volumio[23358]: info: [1769616379737] CoreMusicLibrary::Adding element Last_100 Jan 28 23:06:19 volumio volumio[23358]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 23:06:19 volumio volumio[23358]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 23:06:19 volumio volumio[23358]: info: [1769616379750] CoreMusicLibrary::Adding element Webradio Jan 28 23:06:19 volumio volumio[23358]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 23:06:19 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 28 23:06:19 volumio volumio[23358]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 28 23:06:19 volumio volumio[23358]: info: Initializing BBC Radios Jan 28 23:06:19 volumio go-librespot[23547]: time="2026-01-28T23:06:19+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 23:06:19 volumio go-librespot[23547]: time="2026-01-28T23:06:19+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 28 23:06:19 volumio go-librespot[23547]: time="2026-01-28T23:06:19+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 28 23:06:20 volumio go-librespot[23547]: time="2026-01-28T23:06:20+07:00" level=info msg="zeroconf server listening on port 34915" Jan 28 23:06:20 volumio volumio[23358]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 28 23:06:20 volumio volumio[23358]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 23:06:20 volumio volumio[23358]: info: Creating Spotify config file Jan 28 23:06:20 volumio volumio[23358]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 23:06:20 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 23:06:20 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 23:06:20 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 23:06:20 volumio sudo[23567]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 28 23:06:20 volumio sudo[23567]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jan 28 23:06:20 volumio sudo[23567]: pam_unix(sudo:session): session closed for user root Jan 28 23:06:20 volumio go-librespot[23547]: time="2026-01-28T23:06:20+07:00" level=debug msg="obtained new client token: AADdyl8q4cRAURXcFn53WwzF1WR5zqrOwU6OWVFvOqiGb6WM/7YrH+l+fRGN4tUawV8cdlnJOCbQNJms+fewPXQFEq/uyT4rgz0dGARw9t8zFcIZZGSWG/qqBskdrG74+GukZnEc6sxrWggg5nz/s1E/OwoScRw2SQd0KN6UkIfA1o81ByeSF4xkpWAhh1syRm1WWdSCNNkBrWi2lhcaSv0n2l4Q19Zq7IhI3R3dpoA01ce9OwjEhDZy" Jan 28 23:06:20 volumio go-librespot[23547]: time="2026-01-28T23:06:20+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 23:06:20 volumio go-librespot[23547]: time="2026-01-28T23:06:20+07:00" level=debug msg="completed keyexchange" Jan 28 23:06:20 volumio go-librespot[23547]: time="2026-01-28T23:06:20+07:00" level=debug msg="completed challenge" Jan 28 23:06:20 volumio go-librespot[23547]: time="2026-01-28T23:06: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 28 23:06:20 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 23:06:20 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 23:06:20 volumio volumio[23479]: Starting albumart workers Jan 28 23:06:21 volumio volumio[23481]: Starting albumart workers Jan 28 23:06:21 volumio volumio[23480]: Starting albumart workers Jan 28 23:06:21 volumio volumio[23358]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 23:06:21 volumio volumio[23358]: info: [1769616381498] CoreMusicLibrary::Adding element YouTube Music Jan 28 23:06:21 volumio volumio[23358]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 23:06:21 volumio volumio[23358]: Cannot find translation for source YouTube Music Jan 28 23:06:21 volumio volumio[23358]: info: Volumio Calling Home Jan 28 23:06:21 volumio sudo[23585]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Jan 28 23:06:21 volumio sudo[23585]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 23:06:21 volumio sudo[23585]: pam_unix(sudo:session): session closed for user root Jan 28 23:06:22 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 23:06:22 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 23:06:22 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 23:06:22 volumio volumio[23358]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Jan 28 23:06:22 volumio volumio[23358]: info: Discovery: Found device Volumio Jan 28 23:06:22 volumio volumio[23358]: info: CoreCommandRouter::volumioGetState Jan 28 23:06:22 volumio volumio[23358]: info: CorePlayQueue::getTrack 0 Jan 28 23:06:22 volumio volumio[23358]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Jan 28 23:06:22 volumio volumio[23358]: info: Discovery: Found device Volumio Jan 28 23:06:22 volumio volumio[23358]: info: CoreCommandRouter::volumioGetState Jan 28 23:06:22 volumio volumio[23358]: info: CorePlayQueue::getTrack 0 Jan 28 23:06:22 volumio volumio[23358]: info: MPD Permissions set Jan 28 23:06:22 volumio volumio[23358]: info: MPD Permissions set Jan 28 23:06:22 volumio volumio[23358]: info: Upmpdcli Daemon Started Jan 28 23:06:22 volumio volumio[23358]: info: Volumio called home Jan 28 23:06:22 volumio volumio[23358]: info: Spotify config file written Jan 28 23:06:22 volumio sudo[23604]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jan 28 23:06:22 volumio sudo[23604]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 23:06:23 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 23:06:23 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 23:06:23 volumio go-librespot[23611]: go-librespot daemon starting... Jan 28 23:06:23 volumio sudo[23604]: pam_unix(sudo:session): session closed for user root Jan 28 23:06:23 volumio go-librespot[23612]: time="2026-01-28T23:06:23+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 23:06:23 volumio go-librespot[23612]: time="2026-01-28T23:06:23+07:00" level=debug msg="app state loaded" Jan 28 23:06:23 volumio go-librespot[23612]: time="2026-01-28T23:06:23+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 23:06:23 volumio volumio[23358]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Jan 28 23:06:23 volumio volumio[23358]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 23:06:23 volumio volumio[23358]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 23:06:23 volumio volumio[23358]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 23:06:23 volumio volumio[23358]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 23:06:23 volumio volumio[23358]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 23:06:23 volumio volumio[23358]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 23:06:23 volumio volumio[23358]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 23:06:23 volumio volumio[23358]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 23:06:23 volumio volumio[23358]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 23:06:23 volumio volumio[23358]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 23:06:23 volumio volumio[23358]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 23:06:23 volumio volumio[23358]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 23:06:23 volumio volumio[23358]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 23:06:23 volumio volumio[23358]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 23:06:23 volumio volumio[23358]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 23:06:23 volumio volumio[23358]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 23:06:23 volumio volumio[23358]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 23:06:23 volumio volumio[23358]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 23:06:23 volumio volumio[23358]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 23:06:23 volumio volumio[23358]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 23:06:23 volumio volumio[23358]: info: No need to fix Spotify hosts Jan 28 23:06:23 volumio go-librespot[23612]: time="2026-01-28T23:06:23+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 23:06:23 volumio go-librespot[23612]: time="2026-01-28T23:06:23+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 28 23:06:23 volumio go-librespot[23612]: time="2026-01-28T23:06:23+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 28 23:06:23 volumio go-librespot[23612]: time="2026-01-28T23:06:23+07:00" level=info msg="zeroconf server listening on port 35351" Jan 28 23:06:24 volumio go-librespot[23612]: time="2026-01-28T23:06:24+07:00" level=debug msg="obtained new client token: AABAQF3TTVAvvCDKrqQyJKqJUL18UzwmARtcxQ2xFo2lHJicrrsk45edK+t7KcgIDi2RuygL83t5DcAd+HFJ0vfhTdT0wDmDAAbVm1KTGmKIgnFlm8F5bWAyaRhSyuztlvmLZILc/rZLr/wE7q9X9eghMazsbbCaQIxppWJu/1AfM4LrHDfVTGcqUEkHSLMrRWBg19mbTQiNHOKeK9BNbtZ35JhLL9LvKmbThfNTEgtfhglQjZOLVUwxzLQ=" Jan 28 23:06:24 volumio volumio[23358]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 28 23:06:24 volumio volumio[23358]: SPOTIFY: BQD9KVEVue7R1_Nh0GRQJzYl6EdR22L_AfowVPYeqRKb5ZmCg-cDJsoYU8M_9Zix5fQt7rz0NY56TAvpFh3CezBpj3jE4KY0alyIr3OZ225FM8GohPNb5dheceiXrIFePqsOzO5ZoeJAnHCxT_CNDt7loO7mGW28tIA2aX1Kx3yRbalN1lxtVT4Y1m_AArX7qbP_YPiXlED4yimgqfrecj8IL2D7Vun-ENKwhvhyt_BQREKk6_5OkUD2grfYTc4saxnLmzGvlJXDap84Fqc9_XbJ9OACgRAWhsLKre5T2NTChDnoLBuoSYdO Jan 28 23:06:24 volumio volumio[23358]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 28 23:06:24 volumio volumio[23358]: info: New Spotify access token = BQD9KVEVue7R1_Nh0GRQJzYl6EdR22L_AfowVPYeqRKb5ZmCg-cDJsoYU8M_9Zix5fQt7rz0NY56TAvpFh3CezBpj3jE4KY0alyIr3OZ225FM8GohPNb5dheceiXrIFePqsOzO5ZoeJAnHCxT_CNDt7loO7mGW28tIA2aX1Kx3yRbalN1lxtVT4Y1m_AArX7qbP_YPiXlED4yimgqfrecj8IL2D7Vun-ENKwhvhyt_BQREKk6_5OkUD2grfYTc4saxnLmzGvlJXDap84Fqc9_XbJ9OACgRAWhsLKre5T2NTChDnoLBuoSYdO Jan 28 23:06:24 volumio volumio[23358]: info: Spotify credentials grant success - running version from March 24, 2019 Jan 28 23:06:24 volumio volumio[23358]: info: Starting Shairport Sync Jan 28 23:06:24 volumio go-librespot[23612]: time="2026-01-28T23:06:24+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 23:06:24 volumio volumio[23358]: info: Starting Shairport Sync Jan 28 23:06:24 volumio volumio[23358]: info: Starting Shairport Sync Jan 28 23:06:24 volumio go-librespot[23612]: time="2026-01-28T23:06:24+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Jan 28 23:06:24 volumio sudo[23630]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 28 23:06:24 volumio sudo[23630]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 23:06:24 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 23:06:24 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 23:06:24 volumio sudo[23632]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 28 23:06:24 volumio sudo[23632]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 23:06:24 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 23:06:24 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 23:06:24 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 23:06:24 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 28 23:06:24 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Jan 28 23:06:24 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 28 23:06:24 volumio systemd[1]: shairport-sync.service: Consumed 2.379s CPU time. Jan 28 23:06:24 volumio sudo[23635]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 28 23:06:24 volumio sudo[23635]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 23:06:24 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 28 23:06:24 volumio sudo[23630]: pam_unix(sudo:session): session closed for user root Jan 28 23:06:24 volumio sudo[23632]: pam_unix(sudo:session): session closed for user root Jan 28 23:06:24 volumio volumio[23358]: info: Shairport-Sync Started Jan 28 23:06:24 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 28 23:06:24 volumio volumio[23358]: Error adding Membership: Error: addMembership EINVAL Jan 28 23:06:24 volumio volumio[23358]: info: Shairport-Sync Started Jan 28 23:06:24 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Jan 28 23:06:24 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 28 23:06:24 volumio volumio[23358]: info: CoreCommandRouter::volumioGetState Jan 28 23:06:24 volumio volumio[23358]: info: CorePlayQueue::getTrack 0 Jan 28 23:06:24 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 28 23:06:24 volumio sudo[23635]: pam_unix(sudo:session): session closed for user root Jan 28 23:06:24 volumio volumio[23358]: info: Shairport-Sync Started Jan 28 23:06:24 volumio volumio[23358]: SPOTIFY: User informations: {"country":"PK","display_name":"215mmgea6kss3jxeqsqdquvji","email":"linh.ngotran@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/215mmgea6kss3jxeqsqdquvji"},"followers":{"href":null,"total":1},"href":"https://api.spotify.com/v1/users/215mmgea6kss3jxeqsqdquvji","id":"215mmgea6kss3jxeqsqdquvji","images":[],"product":"premium","type":"user","uri":"spotify:user:215mmgea6kss3jxeqsqdquvji"} Jan 28 23:06:24 volumio volumio[23358]: info: Spotify Successfully logged in Jan 28 23:06:24 volumio volumio[23358]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 23:06:24 volumio volumio[23358]: info: [1769616384951] CoreMusicLibrary::Adding element Spotify Jan 28 23:06:24 volumio volumio[23358]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 23:06:24 volumio volumio[23358]: Cannot find translation for source YouTube Music Jan 28 23:06:24 volumio volumio[23358]: Cannot find translation for source Spotify Jan 28 23:06:25 volumio volumio[23358]: info: [yt-cast-receiver] DIAL server listening on port 8098 Jan 28 23:06:25 volumio volumio[23358]: info: CoreCommandRouter::volumioRetrievevolume Jan 28 23:06:26 volumio volumio[23358]: info: VolumeController:: Volume=100 Mute =false Jan 28 23:06:26 volumio volumio[23358]: info: CoreCommandRouter::volumioGetState Jan 28 23:06:26 volumio volumio[23358]: info: CorePlayQueue::getTrack 0 Jan 28 23:06:26 volumio volumio[23358]: info: CoreStateMachine::pushState Jan 28 23:06:26 volumio volumio[23358]: info: CorePlayQueue::getTrack 0 Jan 28 23:06:26 volumio volumio[23358]: info: CoreCommandRouter::volumioPushState Jan 28 23:06:26 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 23:06:26 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 23:06:26 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 23:06:26 volumio volumio[23358]: info: go-librespot daemon successfully initialized Jan 28 23:06:27 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 21. Jan 28 23:06:27 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 23:06:27 volumio mpd[23582]: 2026-01-28T23:06:27 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 28 23:06:27 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 23:06:27 volumio go-librespot[23679]: go-librespot daemon starting... Jan 28 23:06:27 volumio systemd[1]: Started mpd.service - Music Player Daemon. Jan 28 23:06:27 volumio sudo[23546]: pam_unix(sudo:session): session closed for user root Jan 28 23:06:27 volumio sudo[23535]: pam_unix(sudo:session): session closed for user root Jan 28 23:06:27 volumio go-librespot[23682]: time="2026-01-28T23:06:27+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 23:06:27 volumio go-librespot[23682]: time="2026-01-28T23:06:27+07:00" level=debug msg="app state loaded" Jan 28 23:06:27 volumio go-librespot[23682]: time="2026-01-28T23:06:27+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 23:06:27 volumio volumio[23358]: error: MPD error: The expression evaluated to a falsy value: Jan 28 23:06:27 volumio volumio[23358]: assert.ok(self.idling) Jan 28 23:06:27 volumio volumio[23358]: error: The expression evaluated to a falsy value: Jan 28 23:06:27 volumio volumio[23358]: assert.ok(self.idling) Jan 28 23:06:27 volumio volumio[23358]: info: Completed starting Core Plugins Jan 28 23:06:27 volumio volumio[23358]: info: ------------------------------------------- Jan 28 23:06:27 volumio volumio[23358]: info: ----- MyVolumio plugins startup ---- Jan 28 23:06:27 volumio volumio[23358]: info: ------------------------------------------- Jan 28 23:06:27 volumio volumio[23358]: info: [MyVolumio PluginManager] Fetching plans data.... Jan 28 23:06:27 volumio volumio[23358]: info: MPD running with PID23582 Jan 28 23:06:27 volumio volumio[23358]: ,establishing connection Jan 28 23:06:27 volumio volumio[23358]: error: updateQueue error: null Jan 28 23:06:27 volumio volumio[23358]: error: updateQueue error: null Jan 28 23:06:27 volumio go-librespot[23682]: time="2026-01-28T23:06:27+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 23:06:27 volumio go-librespot[23682]: time="2026-01-28T23:06:27+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 28 23:06:27 volumio go-librespot[23682]: time="2026-01-28T23:06:27+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 28 23:06:27 volumio go-librespot[23682]: time="2026-01-28T23:06:27+07:00" level=info msg="zeroconf server listening on port 34115" Jan 28 23:06:28 volumio go-librespot[23682]: time="2026-01-28T23:06:28+07:00" level=debug msg="obtained new client token: AADjeFvW3qzIjVbyN25nU1UQxPG5f7dDM0xQjeN2kC65b0Ta5DZisdGavnDMnoRxIPl0msSEHaSQKNOX/yRXc3A7hX6VpxE2u7gWsRvR1QqvDgJg5gXoHmqxl2sHnFMX0zGLRtf2553pQMEWlGr+WLyr31p4AneILfg7eK8z7lRh6wilREJ5HSWOBrtdAbRGldej1+/EwRG7WhSD4/VZ1KzYUVn6WECq9R5Um5tdfOUvqyexHVAv9Kxm" Jan 28 23:06:28 volumio go-librespot[23682]: time="2026-01-28T23:06:28+07:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:4070, retrying with a different AP" error="dial tcp 104.199.241.202:4070: connect: connection refused" Jan 28 23:06:28 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 23:06:28 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 23:06:28 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 23:06:28 volumio go-librespot[23682]: time="2026-01-28T23:06:28+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Jan 28 23:06:28 volumio go-librespot[23682]: time="2026-01-28T23:06: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 28 23:06:28 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 23:06:28 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 23:06:29 volumio volumio[23358]: info: Initializing connection to go-librespot Websocket Jan 28 23:06:29 volumio volumio[23358]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 28 23:06:30 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 23:06:30 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 23:06:30 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 23:06:31 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 22. Jan 28 23:06:31 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 23:06:31 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 23:06:31 volumio go-librespot[23691]: go-librespot daemon starting... Jan 28 23:06:31 volumio go-librespot[23692]: time="2026-01-28T23:06:31+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 23:06:31 volumio go-librespot[23692]: time="2026-01-28T23:06:31+07:00" level=debug msg="app state loaded" Jan 28 23:06:31 volumio go-librespot[23692]: time="2026-01-28T23:06:31+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 23:06:32 volumio go-librespot[23692]: time="2026-01-28T23:06: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-gew4.spotify.com:80]" Jan 28 23:06:32 volumio go-librespot[23692]: time="2026-01-28T23:06:32+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 28 23:06:32 volumio go-librespot[23692]: time="2026-01-28T23:06:32+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 28 23:06:32 volumio go-librespot[23692]: time="2026-01-28T23:06:32+07:00" level=info msg="zeroconf server listening on port 40197" Jan 28 23:06:32 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 23:06:32 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 23:06:32 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 23:06:32 volumio go-librespot[23692]: time="2026-01-28T23:06:32+07:00" level=debug msg="obtained new client token: AAAh2NbEF85GRzvB/xRVeyn2UFIpCsooAz866v4zQL1tuMX+belnZVvu0WhNP0KclsGAG7wNSfL6V08diJk/+rKwS0Nu1uNe/MO2otrf0jsUpM8ESTqN24AQ6be6WPWWBB9jBFDJO83tXy9Kcy1dHn7uCFCmPYmNmrRjBsf3IMFGvrMfs0ZGMhUcsu9iQ7jOqslb4lwsXaVb6N3wzJZX0atDNysWM9WkhL1bGmfQSNLrcnMbPt5jnEhLmLE=" Jan 28 23:06:32 volumio go-librespot[23692]: time="2026-01-28T23:06:32+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 23:06:32 volumio volumio[23358]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Jan 28 23:06:32 volumio go-librespot[23692]: time="2026-01-28T23:06:32+07:00" level=debug msg="completed keyexchange" Jan 28 23:06:32 volumio go-librespot[23692]: time="2026-01-28T23:06:32+07:00" level=debug msg="completed challenge" Jan 28 23:06:32 volumio go-librespot[23692]: time="2026-01-28T23:06:32+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 23:06:32 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 23:06:32 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 23:06:32 volumio volumio[23358]: info: Initializing connection to go-librespot Websocket Jan 28 23:06:32 volumio volumio[23358]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 28 23:06:34 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 23:06:34 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 23:06:34 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 23:06:35 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 23. Jan 28 23:06:35 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 23:06:35 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 23:06:35 volumio go-librespot[23699]: go-librespot daemon starting... Jan 28 23:06:35 volumio go-librespot[23700]: time="2026-01-28T23:06:35+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 23:06:35 volumio go-librespot[23700]: time="2026-01-28T23:06:35+07:00" level=debug msg="app state loaded" Jan 28 23:06:35 volumio go-librespot[23700]: time="2026-01-28T23:06:35+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 23:06:35 volumio volumio[23358]: info: Initializing connection to go-librespot Websocket Jan 28 23:06:35 volumio go-librespot[23700]: time="2026-01-28T23:06:35+07:00" level=debug msg="new websocket client" Jan 28 23:06:35 volumio volumio[23358]: info: Connection to go-librespot Websocket established Jan 28 23:06:36 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 23:06:36 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 23:06:36 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 23:06:36 volumio go-librespot[23700]: time="2026-01-28T23:06: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-gew1.spotify.com:80]" Jan 28 23:06:36 volumio go-librespot[23700]: time="2026-01-28T23:06:36+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Jan 28 23:06:36 volumio go-librespot[23700]: time="2026-01-28T23:06:36+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Jan 28 23:06:36 volumio go-librespot[23700]: time="2026-01-28T23:06:36+07:00" level=info msg="zeroconf server listening on port 46175" Jan 28 23:06:36 volumio volumio[23358]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Jan 28 23:06:36 volumio volumio[23358]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Jan 28 23:06:36 volumio volumio[23358]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Jan 28 23:06:36 volumio volumio[23358]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Jan 28 23:06:36 volumio volumio[23358]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Jan 28 23:06:36 volumio volumio[23358]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Jan 28 23:06:36 volumio volumio[23358]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Jan 28 23:06:36 volumio volumio[23358]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Jan 28 23:06:36 volumio volumio[23358]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Jan 28 23:06:36 volumio volumio[23358]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Jan 28 23:06:36 volumio volumio[23358]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Jan 28 23:06:36 volumio volumio[23358]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Jan 28 23:06:36 volumio volumio[23358]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Jan 28 23:06:36 volumio volumio[23358]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Jan 28 23:06:36 volumio volumio[23358]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Jan 28 23:06:36 volumio volumio[23358]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Jan 28 23:06:36 volumio volumio[23358]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Jan 28 23:06:36 volumio volumio[23358]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Jan 28 23:06:36 volumio volumio[23358]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Jan 28 23:06:36 volumio volumio[23358]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Jan 28 23:06:36 volumio volumio[23358]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Jan 28 23:06:36 volumio volumio[23358]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Jan 28 23:06:36 volumio volumio[23358]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Jan 28 23:06:36 volumio volumio[23358]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Jan 28 23:06:36 volumio volumio[23358]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Jan 28 23:06:36 volumio volumio[23358]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Jan 28 23:06:36 volumio volumio[23358]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Jan 28 23:06:36 volumio volumio[23358]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Jan 28 23:06:36 volumio volumio[23358]: info: Adding plugin bluetooth to MyMusic Plugins Jan 28 23:06:36 volumio volumio[23358]: info: Adding plugin multiroom to MyMusic Plugins Jan 28 23:06:36 volumio go-librespot[23700]: time="2026-01-28T23:06:36+07:00" level=debug msg="obtained new client token: AAA/PzPPFoGQb14swh10BCOfcC4LzhwHdpwxGSrGzVU7pAuZGo7/XRzy8szvmYrakjw9vIqVFWBYXgMEouQ+swqgfodcMbEWtCIYS6fdX5dSbN5mq4vQt7tSW8amvB5LlB5PiYnAE6WKxj+7hZH9+oPmncfN184pHWRRiWdnWgCvOI53Y8Ah71HRjW/GYZYpT/9c6IBIIl7Iuc+JbslRDv3c7WCyLhdODE3ie9ToI97N3oAhsnl/K9owEhc=" Jan 28 23:06:36 volumio volumio[23358]: info: Adding plugin metavolumio to MyMusic Plugins Jan 28 23:06:36 volumio volumio[23358]: info: Adding plugin cd_controller to MyMusic Plugins Jan 28 23:06:36 volumio volumio[23358]: info: Adding plugin qobuzconnect to MyMusic Plugins Jan 28 23:06:36 volumio volumio[23358]: info: Adding plugin smart_inputs to MyMusic Plugins Jan 28 23:06:36 volumio volumio[23358]: info: Adding plugin tidalconnect to MyMusic Plugins Jan 28 23:06:36 volumio volumio[23358]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Jan 28 23:06:36 volumio go-librespot[23700]: time="2026-01-28T23:06:36+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 23:06:36 volumio go-librespot[23700]: time="2026-01-28T23:06:36+07:00" level=debug msg="completed keyexchange" Jan 28 23:06:36 volumio go-librespot[23700]: time="2026-01-28T23:06:36+07:00" level=debug msg="completed challenge" Jan 28 23:06:36 volumio go-librespot[23700]: time="2026-01-28T23:06:36+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 23:06:36 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 23:06:36 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 23:06:38 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 23:06:38 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 23:06:38 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 23:06:38 volumio volumio[23358]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Jan 28 23:06:38 volumio volumio[23358]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Jan 28 23:06:38 volumio volumio[23358]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 23:06:38 volumio volumio[23358]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 23:06:38 volumio volumio[23358]: info: Starting MyVolumio Remote Streaming Endpoints Jan 28 23:06:38 volumio volumio[23358]: info: MyVolumio login type: Token Jan 28 23:06:38 volumio volumio[23358]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Jan 28 23:06:38 volumio volumio[23358]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Jan 28 23:06:39 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 24. Jan 28 23:06:39 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 23:06:40 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 23:06:40 volumio go-librespot[23723]: go-librespot daemon starting... Jan 28 23:06:40 volumio go-librespot[23724]: time="2026-01-28T23:06:40+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 23:06:40 volumio go-librespot[23724]: time="2026-01-28T23:06:40+07:00" level=debug msg="app state loaded" Jan 28 23:06:40 volumio go-librespot[23724]: time="2026-01-28T23:06:40+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 23:06:40 volumio volumio[23358]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Jan 28 23:06:40 volumio volumio[23358]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Jan 28 23:06:40 volumio volumio[23358]: info: Streaming services startup Jan 28 23:06:40 volumio volumio[23358]: info: Starting Streaming Daemon Jan 28 23:06:40 volumio sudo[23732]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jan 28 23:06:40 volumio sudo[23732]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 23:06:40 volumio volumio[23358]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Jan 28 23:06:40 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 23:06:40 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 23:06:40 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 23:06:40 volumio sudo[23732]: pam_unix(sudo:session): session closed for user root Jan 28 23:06:40 volumio volumio[23358]: info: Getting Spotify volume Jan 28 23:06:40 volumio volumio[23358]: info: Connection to go-librespot Websocket closed Jan 28 23:06:40 volumio volumio[23358]: error: Cannot start Volumio Streaming Daemon Jan 28 23:06:40 volumio volumio[23358]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Jan 28 23:06:40 volumio volumio[23358]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Jan 28 23:06:40 volumio volumio[23358]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Jan 28 23:06:40 volumio go-librespot[23724]: time="2026-01-28T23:06: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 28 23:06:40 volumio go-librespot[23724]: time="2026-01-28T23:06: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 28 23:06:40 volumio go-librespot[23724]: time="2026-01-28T23:06: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 28 23:06:40 volumio volumio[23358]: info: CoreCommandRouter::volumioGetState Jan 28 23:06:40 volumio volumio[23358]: info: CorePlayQueue::getTrack 0 Jan 28 23:06:40 volumio go-librespot[23724]: time="2026-01-28T23:06:40+07:00" level=info msg="zeroconf server listening on port 37835" Jan 28 23:06:40 volumio volumio[23358]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jan 28 23:06:40 volumio volumio[23358]: SPOTIFY: SPOTIFY VOLUME undefined Jan 28 23:06:40 volumio volumio[23358]: SPOTIFY: VOLUMIO VOLUME 100 Jan 28 23:06:40 volumio volumio[23358]: info: Aligning Spotify Volume to Volumio Volume Jan 28 23:06:40 volumio volumio[23358]: info: CoreCommandRouter::volumioGetState Jan 28 23:06:40 volumio volumio[23358]: info: CorePlayQueue::getTrack 0 Jan 28 23:06:40 volumio volumio[23358]: info: Setting Spotify Volume from Volumio: 100 Jan 28 23:06:40 volumio go-librespot[23724]: time="2026-01-28T23:06:40+07:00" level=debug msg="obtained new client token: AACiq+MRT/zQzoIAfsSsIXc3Kmfqiz+PA6SyGe8v08ac9rSRGLhPWHCiuTvOMPWipodNB4OLB5W5ggOuogsyqtSwLaMCwHepYITFiMAh2L4JujFJQ/6G9gUHHex421l9CCSz8wlZSIybLx1q1sYfFC7ff0SOPfoWHehSvvddQu5M8kZLGHB2f9/XB1GRFdRHV3RPjdFViHP0OvlqckNEeZ2PXeU17yb4pY+FyaDNqDO0U1d844UTcPaDnxk=" Jan 28 23:06:41 volumio go-librespot[23724]: time="2026-01-28T23:06:41+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 23:06:41 volumio go-librespot[23724]: time="2026-01-28T23:06:41+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Jan 28 23:06:41 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 23:06:41 volumio volumio[23358]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 28 23:06:41 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 23:06:41 volumio volumio[23358]: Error: socket hang up Jan 28 23:06:41 volumio volumio[23358]: at connResetException (node:internal/errors:720:14) Jan 28 23:06:41 volumio volumio[23358]: at Socket.socketOnEnd (node:_http_client:519:23) Jan 28 23:06:41 volumio volumio[23358]: at Socket.emit (node:events:526:35) Jan 28 23:06:41 volumio volumio[23358]: at endReadableNT (node:internal/streams/readable:1376:12) Jan 28 23:06:41 volumio volumio[23358]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Jan 28 23:06:41 volumio volumio[23358]: code: 'ECONNRESET', Jan 28 23:06:41 volumio volumio[23358]: response: undefined Jan 28 23:06:41 volumio volumio[23358]: } Jan 28 23:06:41 volumio volumio[23358]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 28 23:06:42 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 23:06:42 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 23:06:42 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 23:06:42 volumio sudo[23753]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-01-28 23:05' Jan 28 23:06:42 volumio sudo[23753]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 23:06:42 volumio sudo[23753]: pam_unix(sudo:session): session closed for user root Jan 28 23:06:44 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 25. Jan 28 23:06:44 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 23:06:44 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 23:06:44 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 23:06:44 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 23:06:44 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 23:06:44 volumio go-librespot[23761]: go-librespot daemon starting... Jan 28 23:06:44 volumio go-librespot[23762]: time="2026-01-28T23:06:44+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 23:06:44 volumio go-librespot[23762]: time="2026-01-28T23:06:44+07:00" level=debug msg="app state loaded" Jan 28 23:06:44 volumio go-librespot[23762]: time="2026-01-28T23:06:44+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 23:06:44 volumio volumio-remote-updater[628]: [2026-01-28 23:06:44] [error] handle_read_frame error: asio.system:104 (Connection reset by peer) Jan 28 23:06:44 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Jan 28 23:06:44 volumio volumio-remote-updater[628]: [2026-01-28 23:06:44] [disconnect] Disconnect close local:[1006,Connection reset by peer] remote:[1006] Jan 28 23:06:44 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Jan 28 23:06:44 volumio systemd[1]: volumio.service: Consumed 1min 2.534s CPU time. Jan 28 23:06:44 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 28 23:06:44 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Jan 28 23:06:44 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 10814. Jan 28 23:06:44 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 28 23:06:44 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Jan 28 23:06:44 volumio systemd[1]: volumio.service: Consumed 1min 2.534s CPU time. Jan 28 23:06:44 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Jan 28 23:06:44 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Jan 28 23:06:44 volumio go-librespot[23762]: time="2026-01-28T23:06:44+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 28 23:06:44 volumio go-librespot[23762]: time="2026-01-28T23:06:44+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Jan 28 23:06:44 volumio go-librespot[23762]: time="2026-01-28T23:06:44+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Jan 28 23:06:44 volumio go-librespot[23762]: time="2026-01-28T23:06:44+07:00" level=info msg="zeroconf server listening on port 34823" Jan 28 23:06:45 volumio go-librespot[23762]: time="2026-01-28T23:06:45+07:00" level=debug msg="obtained new client token: AADlr2bUn1ce79p/ubg4O3Db6gIJR9E37qYJKhJbhcBYRL2xwObrKym85y2ULNaEmPZjPXld5qltwyINjyZsEGcQYhJXq5P+4mnFl+OQFwFMqgM9cJ05zyeAnf4w+0yahXyFf5Wj4B97m573Xc028qQLgnt6heddgECD82n6kKIpNcgBFMDDvRvqCh4bs+TLeTCUGOikr4GJh2UmZT8mZFgrgrNXQXUy2oVF3GujtH+cXb7zYDOfsSML" Jan 28 23:06:45 volumio go-librespot[23762]: time="2026-01-28T23:06:45+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 23:06:45 volumio go-librespot[23762]: time="2026-01-28T23:06:45+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Jan 28 23:06:45 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 23:06:45 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 23:06:46 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 23:06:46 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 23:06:46 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 23:06:48 volumio volumio[23776]: info: ------------------------------------------- Jan 28 23:06:48 volumio volumio[23776]: info: ----- Volumio3 ---- Jan 28 23:06:48 volumio volumio[23776]: info: ------------------------------------------- Jan 28 23:06:48 volumio volumio[23776]: info: ----- System startup ---- Jan 28 23:06:48 volumio volumio[23776]: info: ------------------------------------------- Jan 28 23:06:48 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 23:06:48 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 23:06:48 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 23:06:48 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 26. Jan 28 23:06:48 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 23:06:48 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 23:06:48 volumio go-librespot[23799]: go-librespot daemon starting... Jan 28 23:06:48 volumio go-librespot[23800]: time="2026-01-28T23:06:48+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 23:06:48 volumio go-librespot[23800]: time="2026-01-28T23:06:48+07:00" level=debug msg="app state loaded" Jan 28 23:06:48 volumio go-librespot[23800]: time="2026-01-28T23:06:48+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 23:06:49 volumio go-librespot[23800]: time="2026-01-28T23:06:49+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 28 23:06:49 volumio go-librespot[23800]: time="2026-01-28T23:06:49+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Jan 28 23:06:49 volumio go-librespot[23800]: time="2026-01-28T23:06:49+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Jan 28 23:06:49 volumio go-librespot[23800]: time="2026-01-28T23:06:49+07:00" level=info msg="zeroconf server listening on port 41555" Jan 28 23:06:49 volumio go-librespot[23800]: time="2026-01-28T23:06:49+07:00" level=debug msg="obtained new client token: AABjtXDhs/60bDLUEEL3P+3L6zK1L8F901P9TcYwJ6IAJsDsw/uDhWrXS7NI6zblY/m64D7vw+jvh74neUrBbyu5uB47HrHOhEgjEQgVD5zg5kb765XgilE6COSuzuEVL+s0zxRmrO8OKg8rPaTKeOgWtPby06V1BLdvJNGcs35LW8rBEg1GyyFK6WJFmnFv3GQJA0g8L7eY4yWcdRuC8pIum/R/8LCNYzMauQD7j19gUYIuGLKwJrLcYUg=" Jan 28 23:06:49 volumio volumio-remote-updater[628]: [2026-01-28 23:06:49] [connect] Successful connection Jan 28 23:06:49 volumio go-librespot[23800]: time="2026-01-28T23:06:49+07:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:4070, retrying with a different AP" error="dial tcp 104.199.241.202:4070: connect: connection refused" Jan 28 23:06:49 volumio go-librespot[23800]: time="2026-01-28T23:06:49+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Jan 28 23:06:49 volumio volumio[23776]: info: MYVOLUMIO Environment detected Jan 28 23:06:49 volumio go-librespot[23800]: time="2026-01-28T23:06:49+07:00" level=debug msg="completed keyexchange" Jan 28 23:06:49 volumio go-librespot[23800]: time="2026-01-28T23:06:49+07:00" level=debug msg="completed challenge" Jan 28 23:06:49 volumio volumio[23776]: info: Plugin folders cleanup Jan 28 23:06:49 volumio volumio[23776]: info: Scanning into folder /volumio/app/plugins/ Jan 28 23:06:49 volumio volumio[23776]: info: Scanning category audio_interface Jan 28 23:06:49 volumio go-librespot[23800]: time="2026-01-28T23:06:49+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 23:06:49 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 23:06:49 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 23:06:49 volumio volumio[23776]: info: Scanning category miscellanea Jan 28 23:06:49 volumio volumio[23776]: info: Scanning category music_service Jan 28 23:06:49 volumio volumio[23776]: info: Scanning category plugins.json Jan 28 23:06:49 volumio volumio[23776]: info: Scanning category system_controller Jan 28 23:06:49 volumio volumio[23776]: info: Scanning category user_interface Jan 28 23:06:49 volumio volumio[23776]: info: Scanning into folder /data/plugins/ Jan 28 23:06:49 volumio volumio[23776]: info: Scanning category music_service Jan 28 23:06:49 volumio volumio[23776]: info: Plugin folders cleanup completed Jan 28 23:06:49 volumio volumio[23776]: info: ------------------------------------------- Jan 28 23:06:49 volumio volumio[23776]: info: ----- Core plugins startup ---- Jan 28 23:06:49 volumio volumio[23776]: info: ------------------------------------------- Jan 28 23:06:49 volumio volumio[23776]: info: Loading plugins from folder /volumio/app/plugins/ Jan 28 23:06:49 volumio volumio[23776]: info: Adding plugin upnp to MyMusic Plugins Jan 28 23:06:49 volumio volumio[23776]: info: Adding plugin airplay_emulation to MyMusic Plugins Jan 28 23:06:49 volumio volumio[23776]: info: Adding plugin upnp_browser to MyMusic Plugins Jan 28 23:06:49 volumio volumio[23776]: info: Loading plugins from folder /data/plugins/ Jan 28 23:06:49 volumio volumio[23776]: info: Loading plugin "system"... Jan 28 23:06:49 volumio volumio[23776]: info: Loading plugin "appearance"... Jan 28 23:06:50 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 23:06:50 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 23:06:50 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 23:06:51 volumio volumio[23776]: info: Loading plugin "network"... Jan 28 23:06:51 volumio volumio[23776]: info: Refreshing Cached IP Addresses Jan 28 23:06:51 volumio sudo[23815]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 28 23:06:51 volumio sudo[23815]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 23:06:51 volumio sudo[23817]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 28 23:06:51 volumio sudo[23817]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 23:06:51 volumio volumio[23776]: info: Loading plugin "services"... Jan 28 23:06:51 volumio sudo[23815]: pam_unix(sudo:session): session closed for user root Jan 28 23:06:51 volumio volumio[23776]: info: Loading plugin "alsa_controller"... Jan 28 23:06:51 volumio sudo[23817]: pam_unix(sudo:session): session closed for user root Jan 28 23:06:51 volumio sudo[23825]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Jan 28 23:06:51 volumio sudo[23825]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 23:06:52 volumio volumio[23776]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 28 23:06:52 volumio volumio[23776]: info: Loading plugin "wizard"... Jan 28 23:06:52 volumio volumio[23776]: info: Loading plugin "networkfs"... Jan 28 23:06:52 volumio volumio[23776]: info: Starting Udev Watcher for removable devices Jan 28 23:06:52 volumio volumio[23776]: info: Ignoring mount for partition: boot Jan 28 23:06:52 volumio volumio[23776]: info: Ignoring mount for partition: volumio Jan 28 23:06:52 volumio volumio[23776]: info: Ignoring mount for partition: volumio_data Jan 28 23:06:52 volumio volumio[23776]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 28 23:06:52 volumio volumio[23776]: info: Loading plugin "volumio_command_line_client"... Jan 28 23:06:52 volumio volumio[23776]: info: Loading plugin "upnp"... Jan 28 23:06:52 volumio volumio[23776]: info: [1769616412191] Starting Upmpd Daemon Jan 28 23:06:52 volumio volumio[23776]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 28 23:06:52 volumio volumio[23776]: info: Loading plugin "my_music"... Jan 28 23:06:52 volumio volumio[23776]: info: Loading plugin "mpd"... Jan 28 23:06:52 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 23:06:52 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 23:06:52 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 23:06:52 volumio volumio[23776]: info: Loading plugin "upnp_browser"... Jan 28 23:06:52 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 27. Jan 28 23:06:52 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 23:06:53 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 23:06:53 volumio go-librespot[23848]: go-librespot daemon starting... Jan 28 23:06:53 volumio go-librespot[23849]: time="2026-01-28T23:06:53+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 23:06:53 volumio go-librespot[23849]: time="2026-01-28T23:06:53+07:00" level=debug msg="app state loaded" Jan 28 23:06:53 volumio go-librespot[23849]: time="2026-01-28T23:06:53+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 23:06:53 volumio go-librespot[23849]: time="2026-01-28T23:06:53+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 28 23:06:53 volumio go-librespot[23849]: time="2026-01-28T23:06:53+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Jan 28 23:06:53 volumio go-librespot[23849]: time="2026-01-28T23:06:53+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Jan 28 23:06:53 volumio go-librespot[23849]: time="2026-01-28T23:06:53+07:00" level=info msg="zeroconf server listening on port 38389" Jan 28 23:06:53 volumio go-librespot[23849]: time="2026-01-28T23:06:53+07:00" level=debug msg="obtained new client token: AACw55IWHl4NYRHqm+dv1jAugHE88Qk30tSpGhVEvaIRfjXRAlK03LTVQr5BKVqT5v4IhFRT9zsy0skxBKny+GYObYH7/F95mox0SJgxQ/Q8lryTVAAA2rRmycjkJXz0CNGfZHAfP3rOu/kcC7ym2s5WmfZIwZ3HpWiYLdfCtQyBjRclybRAeqXcl55hkWNi124amlSIvVj6aIj3J7HPbYpE0GFnF4bpT2EfD6OkFK5ZBpGSb2ueBgJ0pQo=" Jan 28 23:06:53 volumio go-librespot[23849]: time="2026-01-28T23:06:53+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 23:06:54 volumio go-librespot[23849]: time="2026-01-28T23:06:54+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Jan 28 23:06:54 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 23:06:54 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 23:06:54 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 23:06:54 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 23:06:54 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 23:06:54 volumio sudo[23825]: pam_unix(sudo:session): session closed for user root Jan 28 23:06:55 volumio volumio[23776]: info: Starting UPNP Browser Jan 28 23:06:55 volumio volumio[23776]: info: Loading plugin "alarm-clock"... Jan 28 23:06:56 volumio volumio[23776]: info: Loading plugin "airplay_emulation"... Jan 28 23:06:56 volumio volumio[23776]: info: Starting Shairport Sync Jan 28 23:06:56 volumio volumio[23776]: info: Loading plugin "last_100"... Jan 28 23:06:56 volumio volumio[23776]: info: Loading plugin "webradio"... Jan 28 23:06:56 volumio volumio[23776]: info: Loading plugin "i2s_dacs"... Jan 28 23:06:56 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 23:06:56 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 23:06:56 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 23:06:56 volumio volumio[23776]: info: Loading plugin "volumiodiscovery"... Jan 28 23:06:56 volumio volumio[23776]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 28 23:06:56 volumio volumio[23776]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 23:06:56 volumio node[23776]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 28 23:06:56 volumio volumio[23776]: *** WARNING *** For more information see Jan 28 23:06:56 volumio volumio[23776]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 28 23:06:56 volumio volumio[23776]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 23:06:56 volumio volumio[23776]: *** WARNING *** For more information see Jan 28 23:06:56 volumio node[23776]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 23:06:56 volumio node[23776]: *** WARNING *** For more information see Jan 28 23:06:56 volumio node[23776]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 28 23:06:56 volumio node[23776]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 23:06:56 volumio node[23776]: *** WARNING *** For more information see Jan 28 23:06:56 volumio volumio[23776]: info: Applying required configuration parameters for plugin volumiodiscovery Jan 28 23:06:56 volumio volumio[23776]: info: Discovery: Started advertising with name: Volumio Jan 28 23:06:56 volumio volumio[23776]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 28 23:06:56 volumio volumio[23776]: info: Loading plugin "spop"... Jan 28 23:06:57 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 28. Jan 28 23:06:57 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 23:06:57 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 23:06:57 volumio go-librespot[23858]: go-librespot daemon starting... Jan 28 23:06:57 volumio go-librespot[23859]: time="2026-01-28T23:06:57+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 23:06:57 volumio go-librespot[23859]: time="2026-01-28T23:06:57+07:00" level=debug msg="app state loaded" Jan 28 23:06:57 volumio go-librespot[23859]: time="2026-01-28T23:06:57+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 23:06:57 volumio go-librespot[23859]: time="2026-01-28T23:06:57+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 23:06:57 volumio go-librespot[23859]: time="2026-01-28T23:06:57+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 28 23:06:57 volumio go-librespot[23859]: time="2026-01-28T23:06:57+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 28 23:06:57 volumio go-librespot[23859]: time="2026-01-28T23:06:57+07:00" level=info msg="zeroconf server listening on port 36813" Jan 28 23:06:58 volumio go-librespot[23859]: time="2026-01-28T23:06:58+07:00" level=debug msg="obtained new client token: AAB0M8HRIg0rw6EYukTiW325aAmQPakB1fK/CNkeVtUrNPDtpMJj3vkOULMu7d8S9SWIjW19/I+Bu0tCuvViiBJdSwC4VraFKB+M3yxzP3t8I5sLVMS4NdfUVLyZeJCIUS5uP1UwqFlq7Exac32+OQZ43XiFlpre1BX2uv/0sx13n4p2gZxIj1gj0RLZgO9Xv6oaE30qxQ5Yrvd8K1p3o+JD4qUQozBnQPgo9bUv4xy+f/ivTIBVIpaA" Jan 28 23:06:58 volumio go-librespot[23859]: time="2026-01-28T23:06:58+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 23:06:58 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 23:06:58 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 23:06:58 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 23:06:58 volumio go-librespot[23859]: time="2026-01-28T23:06:58+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Jan 28 23:06:58 volumio volumio[23776]: info: Loading plugin "ytcr"... Jan 28 23:06:58 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 23:06:58 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 23:07:00 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 23:07:00 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 23:07:00 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 23:07:00 volumio volumio[23776]: info: Loading plugin "ytmusic"... Jan 28 23:07:01 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 29. Jan 28 23:07:01 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 23:07:01 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 23:07:01 volumio go-librespot[23867]: go-librespot daemon starting... Jan 28 23:07:01 volumio go-librespot[23868]: time="2026-01-28T23:07:01+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 23:07:01 volumio go-librespot[23868]: time="2026-01-28T23:07:01+07:00" level=debug msg="app state loaded" Jan 28 23:07:01 volumio go-librespot[23868]: time="2026-01-28T23:07:01+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 23:07:01 volumio volumio-remote-updater[628]: [2026-01-28 23:07:01] [connect] Successful connection Jan 28 23:07:02 volumio volumio[23776]: info: Loading plugin "outputs"... Jan 28 23:07:02 volumio volumio[23776]: info: Loading plugin "albumart"... Jan 28 23:07:02 volumio volumio[23776]: info: Plugin example_plugin is not enabled Jan 28 23:07:02 volumio volumio[23776]: info: Loading plugin "inputs"... Jan 28 23:07:02 volumio volumio[23776]: info: Loading plugin "updater_comm"... Jan 28 23:07:02 volumio go-librespot[23868]: time="2026-01-28T23:07:02+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 28 23:07:02 volumio go-librespot[23868]: time="2026-01-28T23:07:02+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Jan 28 23:07:02 volumio go-librespot[23868]: time="2026-01-28T23:07:02+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Jan 28 23:07:02 volumio go-librespot[23868]: time="2026-01-28T23:07:02+07:00" level=info msg="zeroconf server listening on port 43789" Jan 28 23:07:02 volumio volumio[23776]: info: Plugin mpdemulation is not enabled Jan 28 23:07:02 volumio volumio[23776]: info: Loading plugin "rest_api"... Jan 28 23:07:02 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 23:07:02 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 23:07:02 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 23:07:02 volumio volumio[23776]: info: Loading plugin "websocket"... Jan 28 23:07:02 volumio volumio[23776]: info: Starting Socket.io Server version 1.7.4 Jan 28 23:07:02 volumio volumio[23776]: info: Loading plugin "RoonBridge"... Jan 28 23:07:02 volumio go-librespot[23868]: time="2026-01-28T23:07:02+07:00" level=debug msg="obtained new client token: AABnHccxDmuc3tb3czsIKfxKP979ABMyntkrAcJX5xRhImXGimp9RR4FTP8cICU8Qz2oOnh7r2rRdV7xHtQF7PecT9ZT1rMq+C4G7jMPoK2+nTh+i3s2KipD1raSnx7aZK0JNJ46MuzSJD9vaZzj/5A5RJkKA8E1AN5kItad/STj2zmjvAGl9ltbqdjstnABS2Bwp4CgQ2XtI7A4PXOfzWe9AfzvsIJL/H2m7tLwT5bhKQz8P3gBDdokwY8=" Jan 28 23:07:02 volumio go-librespot[23868]: time="2026-01-28T23:07:02+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 23:07:02 volumio go-librespot[23868]: time="2026-01-28T23:07:02+07:00" level=debug msg="completed keyexchange" Jan 28 23:07:02 volumio go-librespot[23868]: time="2026-01-28T23:07:02+07:00" level=debug msg="completed challenge" Jan 28 23:07:02 volumio go-librespot[23868]: time="2026-01-28T23:07:02+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 23:07:02 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 23:07:02 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 23:07:02 volumio volumio[23776]: info: Applying required configuration parameters for plugin RoonBridge Jan 28 23:07:02 volumio volumio[23776]: info: Loading i18n strings for locale en Jan 28 23:07:02 volumio volumio[23776]: Updating browse sources language Jan 28 23:07:02 volumio volumio[23776]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 23:07:03 volumio volumio[23776]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 28 23:07:03 volumio volumio[23776]: info: CoreCommandRouter::initPlayerControls Jan 28 23:07:03 volumio volumio[23776]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 23:07:03 volumio volumio[23776]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 23:07:03 volumio volumio[23776]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 23:07:03 volumio volumio[23776]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 23:07:03 volumio volumio[23776]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 23:07:03 volumio volumio[23776]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 23:07:03 volumio volumio[23776]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 23:07:03 volumio volumio[23776]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 23:07:03 volumio volumio[23776]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 28 23:07:03 volumio volumio[23776]: Express server listening on port 3000 Jan 28 23:07:03 volumio volumio[23776]: [Metrics] WebUI: 15s 970.32ms Jan 28 23:07:03 volumio volumio[23776]: info: CoreStateMachine::resetVolumioState Jan 28 23:07:03 volumio volumio[23776]: info: CoreStateMachine::getcurrentVolume Jan 28 23:07:03 volumio volumio[23889]: Forking 3 albumart workers Jan 28 23:07:03 volumio volumio[23776]: info: CoreCommandRouter::volumioRetrievevolume Jan 28 23:07:03 volumio sudo[23906]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 28 23:07:03 volumio sudo[23906]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 23:07:03 volumio sudo[23906]: pam_unix(sudo:session): session closed for user root Jan 28 23:07:03 volumio sudo[23909]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 28 23:07:03 volumio sudo[23909]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 23:07:03 volumio sudo[23909]: pam_unix(sudo:session): session closed for user root Jan 28 23:07:03 volumio volumio[23776]: info: Volumio Network Manager: Network status updated: 1 Jan 28 23:07:03 volumio volumio[23776]: info: VolumeController:: Volume=100 Mute =false Jan 28 23:07:03 volumio volumio[23776]: info: CoreStateMachine::pushState Jan 28 23:07:03 volumio volumio[23776]: info: CorePlayQueue::getTrack 0 Jan 28 23:07:03 volumio volumio[23776]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 28 23:07:03 volumio volumio[23776]: info: CoreCommandRouter::volumioPushState Jan 28 23:07:03 volumio volumio[23776]: info: CoreStateMachine::updateTrackBlock Jan 28 23:07:03 volumio volumio[23776]: info: CorePlayQueue::getTrackBlock Jan 28 23:07:03 volumio volumio[23776]: info: CoreCommandRouter::volumioRetrievevolume Jan 28 23:07:03 volumio volumio-remote-updater[628]: [2026-01-28 23:07:03] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1769616421 101 Jan 28 23:07:03 volumio volumio[23776]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 1 Jan 28 23:07:04 volumio volumio[23776]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 23:07:04 volumio volumio[23776]: info: Reloading queue from file Jan 28 23:07:04 volumio volumio[23776]: info: CoreStateMachine::setRepeat null single undefined Jan 28 23:07:04 volumio volumio[23776]: info: CoreStateMachine::pushState Jan 28 23:07:04 volumio volumio[23776]: info: CorePlayQueue::getTrack 0 Jan 28 23:07:04 volumio volumio[23776]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 28 23:07:04 volumio volumio[23776]: info: CoreCommandRouter::volumioPushState Jan 28 23:07:04 volumio volumio[23776]: info: CoreStateMachine::setRandom null Jan 28 23:07:04 volumio volumio[23776]: info: CoreStateMachine::pushState Jan 28 23:07:04 volumio volumio[23776]: info: CorePlayQueue::getTrack 0 Jan 28 23:07:04 volumio volumio[23776]: info: CoreCommandRouter::volumioPushState Jan 28 23:07:04 volumio volumio[23776]: info: Setting Device type: Raspberry PI Jan 28 23:07:04 volumio volumio[23776]: info: Completed loading Core Plugins Jan 28 23:07:04 volumio volumio[23776]: info: Preparing to generate the ALSA configuration file Jan 28 23:07:04 volumio volumio[23776]: info: VolumeController:: Volume=100 Mute =false Jan 28 23:07:04 volumio volumio[23776]: info: CoreStateMachine::pushState Jan 28 23:07:04 volumio volumio[23776]: info: CorePlayQueue::getTrack 0 Jan 28 23:07:04 volumio volumio[23776]: info: CoreCommandRouter::volumioPushState Jan 28 23:07:04 volumio volumio[23776]: info: Asound.conf file unchanged, so no further update is needed Jan 28 23:07:04 volumio volumio[23776]: info: Output device has changed, restarting MPD Jan 28 23:07:04 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 23:07:04 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 23:07:04 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 23:07:04 volumio volumio[23776]: info: Output device has changed, restarting Shairport Sync Jan 28 23:07:04 volumio volumio[23776]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 23:07:04 volumio volumio[23776]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 23:07:04 volumio sudo[23949]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Jan 28 23:07:04 volumio sudo[23949]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 23:07:04 volumio sudo[23953]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 28 23:07:04 volumio sudo[23953]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 23:07:04 volumio sudo[23951]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 28 23:07:04 volumio sudo[23951]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 23:07:04 volumio sudo[23951]: pam_unix(sudo:session): session closed for user root Jan 28 23:07:04 volumio volumio[23776]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 28 23:07:04 volumio volumio[23776]: info: ___________ START PLUGINS ___________ Jan 28 23:07:04 volumio volumio[23776]: info: ControllerMpd::onStart: Initializing MPD Jan 28 23:07:04 volumio volumio[23776]: info: Creating MPD Configuration file Jan 28 23:07:04 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Jan 28 23:07:04 volumio volumio[23776]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 28 23:07:04 volumio sudo[23949]: pam_unix(sudo:session): session closed for user root Jan 28 23:07:04 volumio volumio[23776]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 23:07:04 volumio volumio[23776]: info: [1769616424616] CoreMusicLibrary::Adding element Media Servers Jan 28 23:07:04 volumio volumio[23776]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 23:07:04 volumio sudo[23962]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 28 23:07:04 volumio volumio[23776]: info: UPNP Browser: Client initialized successfully Jan 28 23:07:04 volumio sudo[23962]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 23:07:04 volumio sudo[23962]: pam_unix(sudo:session): session closed for user root Jan 28 23:07:04 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 28 23:07:04 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 28 23:07:04 volumio sudo[23964]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 28 23:07:04 volumio systemd[1]: mpd.service: Consumed 7.311s CPU time. Jan 28 23:07:04 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 28 23:07:04 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 28 23:07:04 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 28 23:07:04 volumio sudo[23964]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 23:07:04 volumio volumio[23776]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 23:07:04 volumio volumio[23776]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 23:07:04 volumio volumio[23776]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 28 23:07:04 volumio volumio[23776]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 23:07:04 volumio volumio[23776]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 23:07:04 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 28 23:07:04 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 28 23:07:04 volumio volumio[23776]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 28 23:07:04 volumio volumio[23776]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 23:07:04 volumio volumio[23776]: info: [1769616424959] CoreMusicLibrary::Adding element Last_100 Jan 28 23:07:04 volumio volumio[23776]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 23:07:04 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 28 23:07:04 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 28 23:07:04 volumio volumio[23776]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 23:07:04 volumio volumio[23776]: info: [1769616424971] CoreMusicLibrary::Adding element Webradio Jan 28 23:07:04 volumio volumio[23776]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 23:07:04 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 28 23:07:04 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 28 23:07:04 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 28 23:07:04 volumio volumio[23776]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 28 23:07:04 volumio volumio[23776]: info: Initializing BBC Radios Jan 28 23:07:05 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 28 23:07:05 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 28 23:07:05 volumio volumio[23776]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 28 23:07:05 volumio volumio[23776]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 23:07:05 volumio volumio[23776]: info: Creating Spotify config file Jan 28 23:07:05 volumio volumio[23776]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 23:07:05 volumio sudo[23986]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 28 23:07:05 volumio sudo[23986]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jan 28 23:07:05 volumio sudo[23986]: pam_unix(sudo:session): session closed for user root Jan 28 23:07:05 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 30. Jan 28 23:07:05 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 23:07:06 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 23:07:06 volumio go-librespot[23994]: go-librespot daemon starting... Jan 28 23:07:06 volumio go-librespot[23995]: time="2026-01-28T23:07:06+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 23:07:06 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 23:07:06 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 23:07:06 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 23:07:06 volumio volumio[23776]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 23:07:06 volumio volumio[23776]: info: [1769616426633] CoreMusicLibrary::Adding element YouTube Music Jan 28 23:07:06 volumio volumio[23776]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 23:07:06 volumio volumio[23776]: Cannot find translation for source YouTube Music Jan 28 23:07:06 volumio volumio[23776]: info: Volumio Calling Home Jan 28 23:07:06 volumio volumio[23903]: Starting albumart workers Jan 28 23:07:06 volumio volumio[23904]: Starting albumart workers Jan 28 23:07:06 volumio sudo[24004]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Jan 28 23:07:06 volumio sudo[24004]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 23:07:06 volumio go-librespot[23995]: time="2026-01-28T23:07:06+07:00" level=info msg="zeroconf server listening on port 38351" Jan 28 23:07:07 volumio sudo[24004]: pam_unix(sudo:session): session closed for user root Jan 28 23:07:07 volumio volumio[23907]: Starting albumart workers Jan 28 23:07:07 volumio volumio[23776]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Jan 28 23:07:07 volumio volumio[23776]: info: Discovery: Found device Volumio Jan 28 23:07:07 volumio volumio[23776]: info: CoreCommandRouter::volumioGetState Jan 28 23:07:07 volumio volumio[23776]: info: CorePlayQueue::getTrack 0 Jan 28 23:07:07 volumio volumio[23776]: info: MPD Permissions set Jan 28 23:07:07 volumio volumio[23776]: info: MPD Permissions set Jan 28 23:07:07 volumio volumio[23776]: info: Upmpdcli Daemon Started Jan 28 23:07:07 volumio volumio[23776]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Jan 28 23:07:07 volumio volumio[23776]: info: Discovery: Found device Volumio Jan 28 23:07:07 volumio volumio[23776]: info: CoreCommandRouter::volumioGetState Jan 28 23:07:07 volumio volumio[23776]: info: CorePlayQueue::getTrack 0 Jan 28 23:07:07 volumio volumio[23776]: info: Volumio called home Jan 28 23:07:07 volumio volumio[23776]: info: Spotify config file written Jan 28 23:07:07 volumio sudo[24012]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jan 28 23:07:07 volumio sudo[24012]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 23:07:08 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Jan 28 23:07:08 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Jan 28 23:07:08 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 23:07:08 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 23:07:08 volumio go-librespot[24014]: go-librespot daemon starting... Jan 28 23:07:08 volumio sudo[24012]: pam_unix(sudo:session): session closed for user root Jan 28 23:07:08 volumio go-librespot[24015]: time="2026-01-28T23:07:08+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 23:07:08 volumio go-librespot[24015]: time="2026-01-28T23:07:08+07:00" level=debug msg="app state loaded" Jan 28 23:07:08 volumio go-librespot[24015]: time="2026-01-28T23:07:08+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 23:07:08 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 23:07:08 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 23:07:08 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 23:07:08 volumio volumio[23776]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Jan 28 23:07:08 volumio volumio[23776]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 23:07:08 volumio volumio[23776]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 23:07:08 volumio volumio[23776]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 23:07:08 volumio volumio[23776]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 23:07:08 volumio volumio[23776]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 23:07:08 volumio volumio[23776]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 23:07:08 volumio volumio[23776]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 23:07:08 volumio volumio[23776]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 23:07:08 volumio volumio[23776]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 23:07:08 volumio volumio[23776]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 23:07:08 volumio volumio[23776]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 23:07:08 volumio volumio[23776]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 23:07:08 volumio volumio[23776]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 23:07:08 volumio volumio[23776]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 23:07:08 volumio volumio[23776]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 23:07:08 volumio volumio[23776]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 23:07:08 volumio volumio[23776]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 23:07:08 volumio volumio[23776]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 23:07:08 volumio volumio[23776]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 23:07:08 volumio volumio[23776]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 23:07:08 volumio volumio[23776]: info: No need to fix Spotify hosts Jan 28 23:07:09 volumio go-librespot[24015]: time="2026-01-28T23:07:09+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 28 23:07:09 volumio go-librespot[24015]: time="2026-01-28T23:07:09+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Jan 28 23:07:09 volumio go-librespot[24015]: time="2026-01-28T23:07:09+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Jan 28 23:07:09 volumio go-librespot[24015]: time="2026-01-28T23:07:09+07:00" level=info msg="zeroconf server listening on port 46761" Jan 28 23:07:09 volumio go-librespot[24015]: time="2026-01-28T23:07:09+07:00" level=debug msg="obtained new client token: AADmmvefWYbGmTJZuDxcbPqZWJgzZxdsoojgv72/HSUG2uYTWwQmaVbxXMUmB+FTA00LavzR4lWqj+eVV/3abCe3HzCOOtx4wMM5aWPFF4N7B8x6t8j3XdMuo4SDy95Ew+zsgx0nl9Oq0OvuAlpgZyrj4jxRpANtd4lAjozNVoYcj8HKXF/9hDHCqrWlB108eqcgn9RQoLP1LXjYZLxGr+zGQAoK2OroUo1ACqN3boDCfLArAITW65wZPwY=" Jan 28 23:07:09 volumio go-librespot[24015]: time="2026-01-28T23:07:09+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 23:07:09 volumio volumio[23776]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 28 23:07:09 volumio volumio[23776]: SPOTIFY: BQCrkpcX819bJ2j211MwqoIdUlQT8AxPqDk495BxpR-cv79DePIysZbLgrN0POg6zKVOCaAr5uFk3pUkAWqLnI84ZaG3w7xnHkQhjQx_feOhNts-P7cr1MdyvZMsajb0vcR4pxYdgltDXRXb643nGcXu8JgGdtI5DLgCU2oR5hWPZt0k5zbUmFeiQSAB-xQYIzJd1TlxlY0PUQnX3j_hf4tfEDqqYVbElF5WwCMnpyB2x61PFeaMUg2RKQgp6N_9JeWJYNN38l35RjbqKL0JK4Cgs_UOhxaKiSsuY32ASvHxEOMZiKBJm6yZ Jan 28 23:07:09 volumio volumio[23776]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 28 23:07:09 volumio volumio[23776]: info: New Spotify access token = BQCrkpcX819bJ2j211MwqoIdUlQT8AxPqDk495BxpR-cv79DePIysZbLgrN0POg6zKVOCaAr5uFk3pUkAWqLnI84ZaG3w7xnHkQhjQx_feOhNts-P7cr1MdyvZMsajb0vcR4pxYdgltDXRXb643nGcXu8JgGdtI5DLgCU2oR5hWPZt0k5zbUmFeiQSAB-xQYIzJd1TlxlY0PUQnX3j_hf4tfEDqqYVbElF5WwCMnpyB2x61PFeaMUg2RKQgp6N_9JeWJYNN38l35RjbqKL0JK4Cgs_UOhxaKiSsuY32ASvHxEOMZiKBJm6yZ Jan 28 23:07:09 volumio volumio[23776]: info: Spotify credentials grant success - running version from March 24, 2019 Jan 28 23:07:09 volumio go-librespot[24015]: time="2026-01-28T23:07:09+07:00" level=debug msg="completed keyexchange" Jan 28 23:07:09 volumio go-librespot[24015]: time="2026-01-28T23:07:09+07:00" level=debug msg="completed challenge" Jan 28 23:07:09 volumio volumio[23776]: info: Starting Shairport Sync Jan 28 23:07:09 volumio volumio[23776]: info: Starting Shairport Sync Jan 28 23:07:09 volumio go-librespot[24015]: time="2026-01-28T23:07:09+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 23:07:09 volumio volumio[23776]: info: Starting Shairport Sync Jan 28 23:07:09 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 23:07:09 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 23:07:09 volumio sudo[24052]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 28 23:07:09 volumio sudo[24052]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 23:07:09 volumio sudo[24056]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 28 23:07:09 volumio sudo[24056]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 23:07:09 volumio sudo[24054]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 28 23:07:09 volumio sudo[24054]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 23:07:09 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 28 23:07:09 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Jan 28 23:07:09 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 28 23:07:09 volumio systemd[1]: shairport-sync.service: Consumed 2.350s CPU time. Jan 28 23:07:10 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 28 23:07:10 volumio sudo[24054]: pam_unix(sudo:session): session closed for user root Jan 28 23:07:10 volumio sudo[24052]: pam_unix(sudo:session): session closed for user root Jan 28 23:07:10 volumio sudo[24056]: pam_unix(sudo:session): session closed for user root Jan 28 23:07:10 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 23:07:10 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 23:07:10 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 23:07:10 volumio volumio[23776]: info: Shairport-Sync Started Jan 28 23:07:10 volumio volumio[23776]: Error adding Membership: Error: addMembership EINVAL Jan 28 23:07:10 volumio volumio[23776]: info: Shairport-Sync Started Jan 28 23:07:10 volumio volumio[23776]: info: Shairport-Sync Started Jan 28 23:07:10 volumio volumio[23776]: info: CoreCommandRouter::volumioGetState Jan 28 23:07:10 volumio volumio[23776]: info: CorePlayQueue::getTrack 0 Jan 28 23:07:10 volumio volumio[23776]: SPOTIFY: User informations: {"country":"PK","display_name":"215mmgea6kss3jxeqsqdquvji","email":"linh.ngotran@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/215mmgea6kss3jxeqsqdquvji"},"followers":{"href":null,"total":1},"href":"https://api.spotify.com/v1/users/215mmgea6kss3jxeqsqdquvji","id":"215mmgea6kss3jxeqsqdquvji","images":[],"product":"premium","type":"user","uri":"spotify:user:215mmgea6kss3jxeqsqdquvji"} Jan 28 23:07:10 volumio volumio[23776]: info: Spotify Successfully logged in Jan 28 23:07:10 volumio volumio[23776]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 23:07:10 volumio volumio[23776]: info: [1769616430602] CoreMusicLibrary::Adding element Spotify Jan 28 23:07:10 volumio volumio[23776]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 23:07:10 volumio volumio[23776]: Cannot find translation for source YouTube Music Jan 28 23:07:10 volumio volumio[23776]: Cannot find translation for source Spotify Jan 28 23:07:11 volumio volumio[23776]: info: [yt-cast-receiver] DIAL server listening on port 8098 Jan 28 23:07:11 volumio volumio[23776]: info: CoreCommandRouter::volumioRetrievevolume Jan 28 23:07:11 volumio volumio[23776]: info: VolumeController:: Volume=100 Mute =false Jan 28 23:07:11 volumio volumio[23776]: info: CoreCommandRouter::volumioGetState Jan 28 23:07:11 volumio volumio[23776]: info: CorePlayQueue::getTrack 0 Jan 28 23:07:11 volumio volumio[23776]: info: CoreStateMachine::pushState Jan 28 23:07:11 volumio volumio[23776]: info: CorePlayQueue::getTrack 0 Jan 28 23:07:11 volumio volumio[23776]: info: CoreCommandRouter::volumioPushState Jan 28 23:07:12 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 23:07:12 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 23:07:12 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 23:07:12 volumio volumio[23776]: info: go-librespot daemon successfully initialized Jan 28 23:07:12 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Jan 28 23:07:12 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 23:07:12 volumio mpd[23993]: 2026-01-28T23:07:12 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 28 23:07:12 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 23:07:12 volumio go-librespot[24092]: go-librespot daemon starting... Jan 28 23:07:12 volumio systemd[1]: Started mpd.service - Music Player Daemon. Jan 28 23:07:12 volumio sudo[23964]: pam_unix(sudo:session): session closed for user root Jan 28 23:07:12 volumio sudo[23953]: pam_unix(sudo:session): session closed for user root Jan 28 23:07:12 volumio go-librespot[24095]: time="2026-01-28T23:07:12+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 23:07:12 volumio go-librespot[24095]: time="2026-01-28T23:07:12+07:00" level=debug msg="app state loaded" Jan 28 23:07:12 volumio go-librespot[24095]: time="2026-01-28T23:07:12+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 23:07:13 volumio volumio[23776]: error: MPD error: The expression evaluated to a falsy value: Jan 28 23:07:13 volumio volumio[23776]: assert.ok(self.idling) Jan 28 23:07:13 volumio volumio[23776]: error: The expression evaluated to a falsy value: Jan 28 23:07:13 volumio volumio[23776]: assert.ok(self.idling) Jan 28 23:07:13 volumio volumio[23776]: error: updateQueue error: null Jan 28 23:07:13 volumio volumio[23776]: info: Completed starting Core Plugins Jan 28 23:07:13 volumio volumio[23776]: info: ------------------------------------------- Jan 28 23:07:13 volumio volumio[23776]: info: ----- MyVolumio plugins startup ---- Jan 28 23:07:13 volumio volumio[23776]: info: ------------------------------------------- Jan 28 23:07:13 volumio volumio[23776]: info: [MyVolumio PluginManager] Fetching plans data.... Jan 28 23:07:13 volumio volumio[23776]: info: MPD running with PID23993 Jan 28 23:07:13 volumio volumio[23776]: ,establishing connection Jan 28 23:07:13 volumio volumio[23776]: error: updateQueue error: null Jan 28 23:07:13 volumio go-librespot[24095]: time="2026-01-28T23:07:13+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 28 23:07:13 volumio go-librespot[24095]: time="2026-01-28T23:07:13+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Jan 28 23:07:13 volumio go-librespot[24095]: time="2026-01-28T23:07:13+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Jan 28 23:07:13 volumio go-librespot[24095]: time="2026-01-28T23:07:13+07:00" level=info msg="zeroconf server listening on port 34669" Jan 28 23:07:13 volumio go-librespot[24095]: time="2026-01-28T23:07:13+07:00" level=debug msg="obtained new client token: AABqNsi/Xb/WJIGgbvJRyCh83tJ2cRzp1kq5EczB28RRCGelmcWRb69ctWkLudzcXXsYb53iTkbqplMs3ytfh2gTeJcW+QdZ9OvYJVcdVr4bCtmw+QwAw2R+WCB8txCEn1eruY/euyFEczytV7RdF7vf/YAoIXkKLehvvgeLQETrKfnjpZcMV7tU6unmEI8eicjmA7ESi3h4aNDzcq08xxe+CIIwFzuXr0VGchXRmgtryrFAVnWISMFE1yQ=" Jan 28 23:07:13 volumio go-librespot[24095]: time="2026-01-28T23:07:13+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 23:07:13 volumio go-librespot[24095]: time="2026-01-28T23:07:13+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Jan 28 23:07:13 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 23:07:13 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 23:07:14 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 23:07:14 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 23:07:14 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 23:07:15 volumio volumio[23776]: info: Initializing connection to go-librespot Websocket Jan 28 23:07:15 volumio volumio[23776]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 28 23:07:16 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 23:07:16 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 23:07:16 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 23:07:16 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Jan 28 23:07:16 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 23:07:17 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 23:07:17 volumio go-librespot[24104]: go-librespot daemon starting... Jan 28 23:07:17 volumio go-librespot[24105]: time="2026-01-28T23:07:17+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 23:07:17 volumio go-librespot[24105]: time="2026-01-28T23:07:17+07:00" level=debug msg="app state loaded" Jan 28 23:07:17 volumio go-librespot[24105]: time="2026-01-28T23:07:17+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 23:07:17 volumio go-librespot[24105]: time="2026-01-28T23:07:17+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 23:07:17 volumio go-librespot[24105]: time="2026-01-28T23:07:17+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 28 23:07:17 volumio go-librespot[24105]: time="2026-01-28T23:07:17+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 28 23:07:17 volumio go-librespot[24105]: time="2026-01-28T23:07:17+07:00" level=info msg="zeroconf server listening on port 40563" Jan 28 23:07:17 volumio volumio[23776]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Jan 28 23:07:17 volumio go-librespot[24105]: time="2026-01-28T23:07:17+07:00" level=debug msg="obtained new client token: AACQGBIwDJJRtmbzhazc1SHGKWN+q8wm25q8/2cvCgjI2nU21yecGx4uU71CeCG3ljLrqQdew1PLQwNR4e7XryjA582YOC90aSb+/RQbXiWIy2Z7qj8tgxUax6VQ3i38qXJ11aGkFYubLolA7tb4trdFpaQHhM7bo4vg5QqU4aZ/j9fMvvRt4+ZQZxcvBv9/bnGwK89nJb2JaHDqePItOwPEzNi2LuSadJt3M9TVX0lDySm4fgMqdRP79lk=" Jan 28 23:07:18 volumio go-librespot[24105]: time="2026-01-28T23:07:18+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 23:07:18 volumio go-librespot[24105]: time="2026-01-28T23:07:18+07:00" level=debug msg="completed keyexchange" Jan 28 23:07:18 volumio go-librespot[24105]: time="2026-01-28T23:07:18+07:00" level=debug msg="completed challenge" Jan 28 23:07:18 volumio go-librespot[24105]: time="2026-01-28T23:07:18+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 23:07:18 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 23:07:18 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 23:07:18 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 23:07:18 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 23:07:18 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 23:07:18 volumio volumio[23776]: info: Initializing connection to go-librespot Websocket Jan 28 23:07:18 volumio volumio[23776]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 28 23:07:20 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 23:07:20 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 23:07:20 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 23:07:21 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Jan 28 23:07:21 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 23:07:21 volumio volumio[23776]: info: Initializing connection to go-librespot Websocket Jan 28 23:07:21 volumio volumio[23776]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 28 23:07:21 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 23:07:21 volumio go-librespot[24113]: go-librespot daemon starting... Jan 28 23:07:21 volumio go-librespot[24114]: time="2026-01-28T23:07:21+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 23:07:21 volumio go-librespot[24114]: time="2026-01-28T23:07:21+07:00" level=debug msg="app state loaded" Jan 28 23:07:21 volumio go-librespot[24114]: time="2026-01-28T23:07:21+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 23:07:21 volumio volumio[23776]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Jan 28 23:07:21 volumio volumio[23776]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Jan 28 23:07:21 volumio volumio[23776]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Jan 28 23:07:21 volumio volumio[23776]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Jan 28 23:07:21 volumio volumio[23776]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Jan 28 23:07:21 volumio volumio[23776]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Jan 28 23:07:21 volumio volumio[23776]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Jan 28 23:07:21 volumio volumio[23776]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Jan 28 23:07:21 volumio volumio[23776]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Jan 28 23:07:21 volumio volumio[23776]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Jan 28 23:07:21 volumio volumio[23776]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Jan 28 23:07:21 volumio volumio[23776]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Jan 28 23:07:21 volumio volumio[23776]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Jan 28 23:07:21 volumio volumio[23776]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Jan 28 23:07:21 volumio volumio[23776]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Jan 28 23:07:21 volumio volumio[23776]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Jan 28 23:07:21 volumio volumio[23776]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Jan 28 23:07:21 volumio volumio[23776]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Jan 28 23:07:21 volumio volumio[23776]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Jan 28 23:07:21 volumio volumio[23776]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Jan 28 23:07:21 volumio volumio[23776]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Jan 28 23:07:21 volumio volumio[23776]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Jan 28 23:07:21 volumio volumio[23776]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Jan 28 23:07:21 volumio volumio[23776]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Jan 28 23:07:21 volumio volumio[23776]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Jan 28 23:07:21 volumio volumio[23776]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Jan 28 23:07:21 volumio volumio[23776]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Jan 28 23:07:21 volumio volumio[23776]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Jan 28 23:07:21 volumio volumio[23776]: info: Adding plugin bluetooth to MyMusic Plugins Jan 28 23:07:21 volumio volumio[23776]: info: Adding plugin multiroom to MyMusic Plugins Jan 28 23:07:21 volumio volumio[23776]: info: Adding plugin metavolumio to MyMusic Plugins Jan 28 23:07:21 volumio volumio[23776]: info: Adding plugin cd_controller to MyMusic Plugins Jan 28 23:07:21 volumio volumio[23776]: info: Adding plugin qobuzconnect to MyMusic Plugins Jan 28 23:07:21 volumio volumio[23776]: info: Adding plugin smart_inputs to MyMusic Plugins Jan 28 23:07:21 volumio volumio[23776]: info: Adding plugin tidalconnect to MyMusic Plugins Jan 28 23:07:21 volumio volumio[23776]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Jan 28 23:07:22 volumio go-librespot[24114]: time="2026-01-28T23:07:22+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 23:07:22 volumio go-librespot[24114]: time="2026-01-28T23:07:22+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 28 23:07:22 volumio go-librespot[24114]: time="2026-01-28T23:07:22+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 28 23:07:22 volumio go-librespot[24114]: time="2026-01-28T23:07:22+07:00" level=info msg="zeroconf server listening on port 44305" Jan 28 23:07:22 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 23:07:22 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 23:07:22 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 23:07:22 volumio go-librespot[24114]: time="2026-01-28T23:07:22+07:00" level=debug msg="obtained new client token: AADxohDuPngaPlYSiPQF/yOvTPOv/UhySM54Jd2mRM+k9jU+g+bLxbjNOrl/cjKJfQLTQ61pd0lU6y3UO2jHjZpZVXW3gzCdkbG6TjjGebkSDWe+RNZcS88w4oUwWLYO0TKgfOVZfZ+ggYrTZ8SvssX4KATg0JrFeZpeOA98/ao6zx67SuFnHYDWY2r/xXkX2D6ByAamRxwt7/1pmGXcWUtZnYSsHuVJetwX6NbGYUYynLJS+BYtZPPu+jI=" Jan 28 23:07:22 volumio go-librespot[24114]: time="2026-01-28T23:07:22+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 23:07:22 volumio go-librespot[24114]: time="2026-01-28T23:07:22+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Jan 28 23:07:22 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 23:07:22 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 23:07:23 volumio volumio[23776]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Jan 28 23:07:23 volumio volumio[23776]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Jan 28 23:07:23 volumio volumio[23776]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 23:07:23 volumio volumio[23776]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 23:07:23 volumio volumio[23776]: info: Starting MyVolumio Remote Streaming Endpoints Jan 28 23:07:23 volumio volumio[23776]: info: MyVolumio login type: Token Jan 28 23:07:23 volumio volumio[23776]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Jan 28 23:07:23 volumio volumio[23776]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Jan 28 23:07:24 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 23:07:24 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 23:07:24 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 23:07:25 volumio volumio[23776]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Jan 28 23:07:25 volumio volumio[23776]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Jan 28 23:07:25 volumio volumio[23776]: info: Streaming services startup Jan 28 23:07:25 volumio volumio[23776]: info: Starting Streaming Daemon Jan 28 23:07:25 volumio sudo[24136]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jan 28 23:07:25 volumio sudo[24136]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 23:07:25 volumio volumio[23776]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Jan 28 23:07:25 volumio sudo[24136]: pam_unix(sudo:session): session closed for user root Jan 28 23:07:25 volumio volumio[23776]: info: Initializing connection to go-librespot Websocket Jan 28 23:07:25 volumio volumio[23776]: error: Cannot start Volumio Streaming Daemon Jan 28 23:07:25 volumio volumio[23776]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Jan 28 23:07:25 volumio volumio[23776]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Jan 28 23:07:25 volumio volumio[23776]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 28 23:07:25 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Jan 28 23:07:25 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 23:07:25 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 23:07:25 volumio go-librespot[24143]: go-librespot daemon starting... Jan 28 23:07:25 volumio go-librespot[24144]: time="2026-01-28T23:07:25+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 23:07:25 volumio go-librespot[24144]: time="2026-01-28T23:07:25+07:00" level=debug msg="app state loaded" Jan 28 23:07:25 volumio go-librespot[24144]: time="2026-01-28T23:07:25+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 23:07:26 volumio volumio[23776]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Jan 28 23:07:26 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 23:07:26 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 23:07:26 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 23:07:26 volumio go-librespot[24144]: time="2026-01-28T23:07:26+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 23:07:26 volumio go-librespot[24144]: time="2026-01-28T23:07:26+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 28 23:07:26 volumio go-librespot[24144]: time="2026-01-28T23:07:26+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 28 23:07:26 volumio go-librespot[24144]: time="2026-01-28T23:07:26+07:00" level=info msg="zeroconf server listening on port 36213" Jan 28 23:07:26 volumio go-librespot[24144]: time="2026-01-28T23:07:26+07:00" level=debug msg="obtained new client token: AABwWVuyeb8HmytqFEul8PwTRhPMeoiFADGWT/vWeiFQdzr2ufNTIoaYqp0k18TBRy5vfmmHTBUOPpunWBJB+Bu515/F5yAEbNCbDjpSQBmI0FkqJuMdMyltcQ+o8QfXZMfk1aIITP9qSi2kztaD7U9NIEAluKeH7JZ9xR9mbzX/Bw4CUcpVmGho3JZEHq4UQWX1wrosjrrElfeBt5WuP+nAJDZArWkHf2SCqJIbv4M+NjPF32Pafmr1E9A=" Jan 28 23:07:26 volumio go-librespot[24144]: time="2026-01-28T23:07:26+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 23:07:26 volumio go-librespot[24144]: time="2026-01-28T23:07:26+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Jan 28 23:07:26 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 23:07:26 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 23:07:27 volumio volumio[23776]: info: MyVolumio token set successfully Jan 28 23:07:27 volumio volumio[23776]: info: MYVOLUMIO: Adding device Jan 28 23:07:27 volumio volumio[23776]: info: MYVOLUMIO: Evaluating Server Jan 28 23:07:28 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 23:07:28 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 23:07:28 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 23:07:28 volumio volumio[23776]: info: MyVolumio status changed Jan 28 23:07:28 volumio volumio[23776]: info: Streaming services startup Jan 28 23:07:28 volumio volumio[23776]: info: Starting Streaming Daemon Jan 28 23:07:28 volumio volumio[23776]: info: Removing browser output: myVolumio user plan is not superstar Jan 28 23:07:28 volumio volumio[23776]: info: Removing audio output: Jan 28 23:07:28 volumio volumio[23776]: info: Stoppping Tunnel 1 Jan 28 23:07:28 volumio sudo[24175]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jan 28 23:07:28 volumio sudo[24175]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 23:07:28 volumio sudo[24175]: pam_unix(sudo:session): session closed for user root Jan 28 23:07:28 volumio volumio[23776]: info: Initializing connection to go-librespot Websocket Jan 28 23:07:28 volumio volumio[23776]: error: Cannot start Volumio Streaming Daemon Jan 28 23:07:28 volumio volumio[23776]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Jan 28 23:07:28 volumio volumio[23776]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Jan 28 23:07:28 volumio volumio[23776]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 28 23:07:28 volumio sudo[24178]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Jan 28 23:07:28 volumio sudo[24178]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 23:07:28 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 28 23:07:28 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 28 23:07:28 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 28 23:07:28 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 28 23:07:28 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 28 23:07:28 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 28 23:07:28 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 28 23:07:28 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 28 23:07:28 volumio sudo[24178]: pam_unix(sudo:session): session closed for user root Jan 28 23:07:28 volumio volumio[23776]: info: Remote SSH Stopped Jan 28 23:07:29 volumio volumio[23776]: info: Setting Geolocation for MyVolumio to as1 Jan 28 23:07:29 volumio volumio[23776]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 23:07:29 volumio volumio[23776]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 23:07:29 volumio volumio[23776]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 23:07:29 volumio volumio[23776]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Jan 28 23:07:29 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Jan 28 23:07:29 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 23:07:30 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 23:07:30 volumio go-librespot[24180]: go-librespot daemon starting... Jan 28 23:07:30 volumio go-librespot[24181]: time="2026-01-28T23:07:30+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 23:07:30 volumio go-librespot[24181]: time="2026-01-28T23:07:30+07:00" level=debug msg="app state loaded" Jan 28 23:07:30 volumio go-librespot[24181]: time="2026-01-28T23:07:30+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 23:07:30 volumio volumio[23776]: info: Updating MyVolumio device info Jan 28 23:07:30 volumio volumio[23776]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 23:07:30 volumio volumio[23776]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 23:07:30 volumio volumio[23776]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 23:07:30 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 23:07:30 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 23:07:30 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 23:07:30 volumio go-librespot[24181]: time="2026-01-28T23:07:30+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 28 23:07:30 volumio go-librespot[24181]: time="2026-01-28T23:07:30+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Jan 28 23:07:30 volumio go-librespot[24181]: time="2026-01-28T23:07:30+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Jan 28 23:07:30 volumio go-librespot[24181]: time="2026-01-28T23:07:30+07:00" level=info msg="zeroconf server listening on port 46505" Jan 28 23:07:30 volumio go-librespot[24181]: time="2026-01-28T23:07:30+07:00" level=debug msg="obtained new client token: AACnzki2lB35+wIQcikBTOVY0ajeCoJDfRbiaJ2tzE2q7n4a+MrnNApwDdJWDts827bCbIxo5Xb01PpuvYA8DJW5hfruZHuKWUYbqJUicg6Oj+7uwICO2NcdkNvVqeaiRz58xQp80dFZtzh8zoa3sdG2/0i/47DxPk8A3iuzXbTKzhsUgSdw/J8g6/8i1O1aix4SJb5Oo9BQnsbJ98DqPYafH4k1pGBQa/5VeyA9ebBe/VBHZRlPan34a7w=" Jan 28 23:07:30 volumio go-librespot[24181]: time="2026-01-28T23:07:30+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 23:07:31 volumio go-librespot[24181]: time="2026-01-28T23:07:31+07:00" level=debug msg="completed keyexchange" Jan 28 23:07:31 volumio go-librespot[24181]: time="2026-01-28T23:07:31+07:00" level=debug msg="completed challenge" Jan 28 23:07:31 volumio go-librespot[24181]: time="2026-01-28T23:07:31+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 23:07:31 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 23:07:31 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 23:07:31 volumio volumio[23776]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Jan 28 23:07:31 volumio volumio[23776]: info: Initializing connection to go-librespot Websocket Jan 28 23:07:31 volumio volumio[23776]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 28 23:07:32 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 23:07:32 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 23:07:32 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 23:07:33 volumio volumio[23776]: info: MYVOLUMIO: Adding device Jan 28 23:07:33 volumio volumio[23776]: info: MYVOLUMIO: Evaluating Server Jan 28 23:07:34 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Jan 28 23:07:34 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 23:07:34 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 23:07:34 volumio go-librespot[24220]: go-librespot daemon starting... Jan 28 23:07:34 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 23:07:34 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 23:07:34 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 23:07:34 volumio go-librespot[24221]: time="2026-01-28T23:07:34+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 23:07:34 volumio go-librespot[24221]: time="2026-01-28T23:07:34+07:00" level=debug msg="app state loaded" Jan 28 23:07:34 volumio go-librespot[24221]: time="2026-01-28T23:07:34+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 23:07:34 volumio volumio[23776]: info: Initializing connection to go-librespot Websocket Jan 28 23:07:34 volumio go-librespot[24221]: time="2026-01-28T23:07:34+07:00" level=debug msg="new websocket client" Jan 28 23:07:34 volumio volumio[23776]: info: Connection to go-librespot Websocket established Jan 28 23:07:34 volumio go-librespot[24221]: time="2026-01-28T23:07:34+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 28 23:07:34 volumio go-librespot[24221]: time="2026-01-28T23:07:34+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Jan 28 23:07:34 volumio go-librespot[24221]: time="2026-01-28T23:07:34+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Jan 28 23:07:34 volumio volumio[23776]: info: Setting Geolocation for MyVolumio to as1 Jan 28 23:07:34 volumio volumio[23776]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 23:07:34 volumio volumio[23776]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 23:07:34 volumio volumio[23776]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 23:07:34 volumio go-librespot[24221]: time="2026-01-28T23:07:34+07:00" level=info msg="zeroconf server listening on port 45853" Jan 28 23:07:35 volumio go-librespot[24221]: time="2026-01-28T23:07:35+07:00" level=debug msg="obtained new client token: AABj/CC3TaBhzZ0/arrP9BhS/gHE5ZcOUvq+S6/4I8od7E0yOanvQMk0YxbwYryTQDqmjmUfbLnRpsMc0mzaJl0IYmV+5he28017XwloJFNZOJBLBLuoyHD9nlgF9Ygxa5D0oJ+82KpVLcPWVV9VTPx6xWRPweA7HOSrcF5Iip7PW7JXS3fxDsOGPKziz84YiEYUCfwvicbmyP+CqkP1xeb1VwjY8LEAgvDtaNewUUSbbACOB6A4wQit" Jan 28 23:07:35 volumio go-librespot[24221]: time="2026-01-28T23:07:35+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 23:07:35 volumio go-librespot[24221]: time="2026-01-28T23:07:35+07:00" level=debug msg="completed keyexchange" Jan 28 23:07:35 volumio go-librespot[24221]: time="2026-01-28T23:07:35+07:00" level=debug msg="completed challenge" Jan 28 23:07:35 volumio volumio[23776]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Jan 28 23:07:35 volumio go-librespot[24221]: time="2026-01-28T23:07:35+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 23:07:35 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 23:07:35 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 23:07:35 volumio volumio[23776]: info: Connection to go-librespot Websocket closed Jan 28 23:07:35 volumio volumio[23776]: info: Updating MyVolumio device info Jan 28 23:07:35 volumio volumio[23776]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 23:07:35 volumio volumio[23776]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 23:07:35 volumio volumio[23776]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 23:07:36 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 23:07:36 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 23:07:36 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 23:07:36 volumio volumio[23776]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 28 23:07:36 volumio volumio[23776]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 23:07:36 volumio volumio[23776]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Jan 28 23:07:36 volumio volumio[23776]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Jan 28 23:07:36 volumio volumio-remote-updater[628]: Test mode disabled Jan 28 23:07:36 volumio volumio-remote-updater[628]: Alpha mode disabled Jan 28 23:07:36 volumio volumio-remote-updater[628]: Alpha legacy test mode disabled Jan 28 23:07:36 volumio volumio[23776]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled Jan 28 23:07:37 volumio volumio[23776]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Jan 28 23:07:37 volumio volumio[23776]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Jan 28 23:07:37 volumio volumio[23776]: info: Getting Spotify volume Jan 28 23:07:37 volumio volumio[23776]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 28 23:07:37 volumio volumio[23776]: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 28 23:07:37 volumio volumio[23776]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Jan 28 23:07:37 volumio volumio[23776]: errno: -111, Jan 28 23:07:37 volumio volumio[23776]: code: 'ECONNREFUSED', Jan 28 23:07:37 volumio volumio[23776]: syscall: 'connect', Jan 28 23:07:37 volumio volumio[23776]: address: '127.0.0.1', Jan 28 23:07:37 volumio volumio[23776]: port: 9879, Jan 28 23:07:37 volumio volumio[23776]: response: undefined Jan 28 23:07:37 volumio volumio[23776]: } Jan 28 23:07:37 volumio volumio[23776]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 28 23:07:38 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 23:07:38 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 23:07:38 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 23:07:38 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Jan 28 23:07:38 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 23:07:38 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 23:07:38 volumio go-librespot[24244]: go-librespot daemon starting... Jan 28 23:07:38 volumio go-librespot[24245]: time="2026-01-28T23:07:38+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 23:07:38 volumio go-librespot[24245]: time="2026-01-28T23:07:38+07:00" level=debug msg="app state loaded" Jan 28 23:07:38 volumio go-librespot[24245]: time="2026-01-28T23:07:38+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 23:07:39 volumio sudo[24256]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-01-28 23:06' Jan 28 23:07:39 volumio sudo[24256]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 23:07:39 volumio go-librespot[24245]: time="2026-01-28T23:07:39+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 23:07:39 volumio go-librespot[24245]: time="2026-01-28T23:07:39+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 28 23:07:39 volumio go-librespot[24245]: time="2026-01-28T23:07:39+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 28 23:07:39 volumio go-librespot[24245]: time="2026-01-28T23:07:39+07:00" level=info msg="zeroconf server listening on port 38229" Jan 28 23:07:39 volumio go-librespot[24245]: time="2026-01-28T23:07:39+07:00" level=debug msg="obtained new client token: AADHpxnj3T8Fu/Iej/cNtUOMRN6KhnYpKl87TmKUy7QcwQkYADYQrXcxAaH2+Dsfy2anDA9q2Hk1B1g0NINVxaD5iZl6Cdp+syNrYdUd+CUEttOH4+hrpTwqKaq8ESmsPUXxLdNpWzRmy0SovLqG5ANoYjFBfSPenbYzuEuP6Ix7g2XAKlYw9QPhi6XPkHf5T4fvykaYxWnDtLSJpQipoeXxGrl6ryY5RNFd93XDQ+FB/ND30WXiSyu76+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"