Mar 04 08:47:00 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Mar 04 08:47:00 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Mar 04 08:47:00 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Mar 04 08:47:00 loe volumio5-onboarding[2840]: time=2026-03-04T08:47:00.233+01:00 level=WARN msg="reconnection attempt failed" component=volumio/socket error="dial tcp 127.0.0.1:3000: connect: connection refused" Mar 04 08:47:01 loe systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 17. Mar 04 08:47:01 loe systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 04 08:47:01 loe systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 04 08:47:01 loe go-librespot[12833]: go-librespot daemon starting... Mar 04 08:47:01 loe volumio[12811]: info: ------------------------------------------- Mar 04 08:47:01 loe volumio[12811]: info: ----- Volumio3 ---- Mar 04 08:47:01 loe volumio[12811]: info: ------------------------------------------- Mar 04 08:47:01 loe volumio[12811]: info: ----- System startup ---- Mar 04 08:47:01 loe volumio[12811]: info: ------------------------------------------- Mar 04 08:47:01 loe go-librespot[12834]: time="2026-03-04T08:47:01+01:00" level=info msg="running go-librespot 0.4.0" Mar 04 08:47:01 loe go-librespot[12834]: time="2026-03-04T08:47:01+01:00" level=debug msg="app state loaded" Mar 04 08:47:01 loe go-librespot[12834]: time="2026-03-04T08:47:01+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 04 08:47:02 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Mar 04 08:47:02 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Mar 04 08:47:02 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Mar 04 08:47:02 loe go-librespot[12834]: time="2026-03-04T08:47:02+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Mar 04 08:47:02 loe go-librespot[12834]: time="2026-03-04T08:47:02+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Mar 04 08:47:02 loe go-librespot[12834]: time="2026-03-04T08:47:02+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Mar 04 08:47:02 loe go-librespot[12834]: time="2026-03-04T08:47:02+01:00" level=info msg="zeroconf server listening on port 45819" Mar 04 08:47:02 loe go-librespot[12834]: time="2026-03-04T08:47:02+01:00" level=debug msg="obtained new client token: AABMnktFgfo21IY7+FHKIo3M12IVUFfPnhj/XeevbJKUojMaRxjIk7asVD9GW1+CJCB2cmJumyyfH0PKPaJAQB955IYTrGu+neLyCZqbVhiqD5e+1hSjHALO/Dj0iy8ZZIiyPa2PJ41cuvHIwUefs697yy0S38vJCEu9w9GTn1AeCerjoYiQWNAhiW5Ef610DZQe1cGkc9adXEUmrI0ixlLwb1ouuYqkNEiVDtXk8yDCjzaeb7DZJ2Pwiw==" Mar 04 08:47:02 loe go-librespot[12834]: time="2026-03-04T08:47:02+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 04 08:47:02 loe go-librespot[12834]: time="2026-03-04T08:47:02+01:00" level=debug msg="completed keyexchange" Mar 04 08:47:02 loe go-librespot[12834]: time="2026-03-04T08:47:02+01:00" level=debug msg="completed challenge" Mar 04 08:47:02 loe go-librespot[12834]: time="2026-03-04T08:47:02+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 04 08:47:02 loe systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 04 08:47:02 loe systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 04 08:47:03 loe volumio[12811]: info: MYVOLUMIO Environment detected Mar 04 08:47:03 loe volumio-remote-updater[714]: [2026-03-04 08:47:03] [connect] Successful connection Mar 04 08:47:03 loe volumio[12811]: info: Plugin folders cleanup Mar 04 08:47:03 loe volumio[12811]: info: Scanning into folder /volumio/app/plugins/ Mar 04 08:47:03 loe volumio[12811]: info: Scanning category audio_interface Mar 04 08:47:03 loe volumio[12811]: info: Scanning category miscellanea Mar 04 08:47:03 loe volumio[12811]: info: Scanning category music_service Mar 04 08:47:03 loe volumio[12811]: info: Scanning category plugins.json Mar 04 08:47:03 loe volumio[12811]: info: Scanning category system_controller Mar 04 08:47:03 loe volumio[12811]: info: Scanning category user_interface Mar 04 08:47:03 loe volumio[12811]: info: Scanning into folder /data/plugins/ Mar 04 08:47:03 loe volumio[12811]: info: Scanning category music_service Mar 04 08:47:03 loe volumio[12811]: info: Plugin folders cleanup completed Mar 04 08:47:03 loe volumio[12811]: info: ------------------------------------------- Mar 04 08:47:03 loe volumio[12811]: info: ----- Core plugins startup ---- Mar 04 08:47:03 loe volumio[12811]: info: ------------------------------------------- Mar 04 08:47:03 loe volumio[12811]: info: Loading plugins from folder /volumio/app/plugins/ Mar 04 08:47:03 loe volumio[12811]: info: Adding plugin upnp to MyMusic Plugins Mar 04 08:47:03 loe volumio[12811]: info: Adding plugin airplay_emulation to MyMusic Plugins Mar 04 08:47:03 loe volumio[12811]: info: Adding plugin upnp_browser to MyMusic Plugins Mar 04 08:47:03 loe volumio[12811]: info: Loading plugins from folder /data/plugins/ Mar 04 08:47:03 loe volumio[12811]: info: Loading plugin "system"... Mar 04 08:47:03 loe volumio[12811]: info: Loading plugin "appearance"... Mar 04 08:47:04 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Mar 04 08:47:04 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Mar 04 08:47:04 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Mar 04 08:47:05 loe volumio[12811]: info: Loading plugin "network"... Mar 04 08:47:05 loe volumio[12811]: info: Refreshing Cached IP Addresses Mar 04 08:47:05 loe sudo[12848]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 04 08:47:05 loe sudo[12848]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 08:47:05 loe sudo[12848]: pam_unix(sudo:session): session closed for user root Mar 04 08:47:05 loe sudo[12850]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 04 08:47:05 loe sudo[12850]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 08:47:05 loe volumio[12811]: info: Loading plugin "services"... Mar 04 08:47:05 loe volumio[12811]: info: Loading plugin "volumio5onboarding"... Mar 04 08:47:05 loe sudo[12850]: pam_unix(sudo:session): session closed for user root Mar 04 08:47:05 loe sudo[12858]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Mar 04 08:47:05 loe sudo[12858]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 08:47:05 loe volumio[12811]: info: Loading plugin "alsa_controller"... Mar 04 08:47:05 loe volumio[12811]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 04 08:47:05 loe volumio[12811]: info: Loading plugin "wizard"... Mar 04 08:47:05 loe volumio[12811]: info: Loading plugin "networkfs"... Mar 04 08:47:05 loe volumio[12811]: info: Starting Udev Watcher for removable devices Mar 04 08:47:05 loe volumio[12811]: info: Ignoring mount for partition: boot Mar 04 08:47:05 loe volumio[12811]: info: Ignoring mount for partition: volumio Mar 04 08:47:05 loe volumio[12811]: info: Ignoring mount for partition: volumio_data Mar 04 08:47:05 loe volumio[12811]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 04 08:47:05 loe volumio[12811]: info: Loading plugin "volumio_command_line_client"... Mar 04 08:47:05 loe volumio[12811]: info: Loading plugin "upnp"... Mar 04 08:47:05 loe volumio[12811]: info: [1772610425736] Starting Upmpd Daemon Mar 04 08:47:05 loe volumio[12811]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 04 08:47:05 loe volumio[12811]: info: Loading plugin "my_music"... Mar 04 08:47:05 loe volumio[12811]: info: Loading plugin "mpd"... Mar 04 08:47:05 loe systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 18. Mar 04 08:47:05 loe systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 04 08:47:05 loe systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 04 08:47:05 loe go-librespot[12881]: go-librespot daemon starting... Mar 04 08:47:05 loe go-librespot[12882]: time="2026-03-04T08:47:05+01:00" level=info msg="running go-librespot 0.4.0" Mar 04 08:47:05 loe go-librespot[12882]: time="2026-03-04T08:47:05+01:00" level=debug msg="app state loaded" Mar 04 08:47:05 loe go-librespot[12882]: time="2026-03-04T08:47:05+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 04 08:47:06 loe sudo[12858]: pam_unix(sudo:session): session closed for user root Mar 04 08:47:06 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Mar 04 08:47:06 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Mar 04 08:47:06 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Mar 04 08:47:06 loe go-librespot[12882]: time="2026-03-04T08:47:06+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 04 08:47:06 loe go-librespot[12882]: time="2026-03-04T08:47:06+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 04 08:47:06 loe go-librespot[12882]: time="2026-03-04T08:47:06+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 04 08:47:06 loe go-librespot[12882]: time="2026-03-04T08:47:06+01:00" level=info msg="zeroconf server listening on port 37449" Mar 04 08:47:06 loe volumio[12811]: info: Loading plugin "upnp_browser"... Mar 04 08:47:06 loe go-librespot[12882]: time="2026-03-04T08:47:06+01:00" level=debug msg="obtained new client token: AAAXvvxX0TGhLqvVfVWwS0zuu1tyRpobZhPBJJ2H6FTK8l6OpJHzNK7pJyvMdVyMEpuEPqcppF0k6dwHdMTAsh1Xa5gC/je8I7SwgTgcZB+SRu/MkbnMYEVDWeb3veRS8uz84wO1s9BT4XMc5c53OUMR6c2f9D5h00aiqGHTLSnyaIAp2aBBE7Rjg3aNP6BCMX+U7I4Ud8FH9HCLbsJ6OJ8vW5cErJd8/YOAByRo6cfCNPVJMX8Gl/V3/A==" Mar 04 08:47:06 loe go-librespot[12882]: time="2026-03-04T08:47:06+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 04 08:47:06 loe go-librespot[12882]: time="2026-03-04T08:47:06+01:00" level=debug msg="completed keyexchange" Mar 04 08:47:06 loe go-librespot[12882]: time="2026-03-04T08:47:06+01:00" level=debug msg="completed challenge" Mar 04 08:47:06 loe go-librespot[12882]: time="2026-03-04T08:47:06+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 04 08:47:06 loe systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 04 08:47:06 loe systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 04 08:47:08 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Mar 04 08:47:08 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Mar 04 08:47:08 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Mar 04 08:47:09 loe volumio[12811]: info: Starting UPNP Browser Mar 04 08:47:09 loe volumio[12811]: info: Loading plugin "alarm-clock"... Mar 04 08:47:09 loe volumio[12811]: info: Loading plugin "airplay_emulation"... Mar 04 08:47:09 loe volumio[12811]: info: Starting Shairport Sync Mar 04 08:47:09 loe volumio[12811]: info: Loading plugin "last_100"... Mar 04 08:47:09 loe volumio[12811]: info: Loading plugin "webradio"... Mar 04 08:47:09 loe volumio[12811]: info: Loading plugin "i2s_dacs"... Mar 04 08:47:09 loe systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 19. Mar 04 08:47:09 loe volumio[12811]: info: Loading plugin "volumiodiscovery"... Mar 04 08:47:09 loe systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 04 08:47:09 loe volumio[12811]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Mar 04 08:47:09 loe volumio[12811]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 04 08:47:09 loe node[12811]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Mar 04 08:47:09 loe volumio[12811]: *** WARNING *** For more information see Mar 04 08:47:09 loe volumio[12811]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Mar 04 08:47:09 loe volumio[12811]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 04 08:47:09 loe volumio[12811]: *** WARNING *** For more information see Mar 04 08:47:09 loe node[12811]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 04 08:47:09 loe node[12811]: *** WARNING *** For more information see Mar 04 08:47:09 loe node[12811]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Mar 04 08:47:09 loe node[12811]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 04 08:47:09 loe node[12811]: *** WARNING *** For more information see Mar 04 08:47:09 loe systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 04 08:47:09 loe volumio[12811]: info: Applying required configuration parameters for plugin volumiodiscovery Mar 04 08:47:09 loe go-librespot[12889]: go-librespot daemon starting... Mar 04 08:47:09 loe volumio[12811]: info: Discovery: Started advertising with name: Loe Mar 04 08:47:09 loe go-librespot[12890]: time="2026-03-04T08:47:09+01:00" level=info msg="running go-librespot 0.4.0" Mar 04 08:47:09 loe go-librespot[12890]: time="2026-03-04T08:47:09+01:00" level=debug msg="app state loaded" Mar 04 08:47:09 loe go-librespot[12890]: time="2026-03-04T08:47:09+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 04 08:47:09 loe volumio[12811]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 04 08:47:09 loe volumio[12811]: info: Loading plugin "spop"... Mar 04 08:47:10 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Mar 04 08:47:10 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Mar 04 08:47:10 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Mar 04 08:47:10 loe go-librespot[12890]: time="2026-03-04T08:47:10+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Mar 04 08:47:10 loe go-librespot[12890]: time="2026-03-04T08:47:10+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Mar 04 08:47:10 loe go-librespot[12890]: time="2026-03-04T08:47:10+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Mar 04 08:47:10 loe go-librespot[12890]: time="2026-03-04T08:47:10+01:00" level=info msg="zeroconf server listening on port 35427" Mar 04 08:47:10 loe go-librespot[12890]: time="2026-03-04T08:47:10+01:00" level=debug msg="obtained new client token: AADnFWVac0phVjumgWsB4UWDC6ekdWlObiQUYF/sZ0ZhvIVVwfY7Iqmg6fzKCd4AVxmaZyBF6egx+9QTpnFa1R3JLof0ue700vulebkC4a0DYkIUTQNQDAudbDdvaLS0tlSCQIPA9KdLbAxxJ5e22r6oLo1fLfA0wfP1KuoXHtkIEi7uqCFQTirRF/qQ3BObtREGSrjMUXN2Sm4zTbhNNB1VPpTYwO+V7vu04KOyFr7h/qPZvSgXaGqp0g==" Mar 04 08:47:10 loe go-librespot[12890]: time="2026-03-04T08:47:10+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 04 08:47:10 loe go-librespot[12890]: time="2026-03-04T08:47:10+01:00" level=debug msg="completed keyexchange" Mar 04 08:47:10 loe go-librespot[12890]: time="2026-03-04T08:47:10+01:00" level=debug msg="completed challenge" Mar 04 08:47:10 loe go-librespot[12890]: time="2026-03-04T08:47:10+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 04 08:47:10 loe systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 04 08:47:10 loe systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 04 08:47:11 loe volumio5-onboarding[2840]: time=2026-03-04T08:47:11.236+01:00 level=WARN msg="reconnection attempt failed" component=volumio/socket error="read tcp 127.0.0.1:38190->127.0.0.1:3000: i/o timeout" Mar 04 08:47:11 loe volumio[12811]: info: Loading plugin "outputs"... Mar 04 08:47:11 loe volumio[12811]: info: Loading plugin "albumart"... Mar 04 08:47:11 loe volumio[12811]: info: Plugin example_plugin is not enabled Mar 04 08:47:11 loe volumio[12811]: info: Loading plugin "inputs"... Mar 04 08:47:11 loe volumio[12811]: info: Loading plugin "updater_comm"... Mar 04 08:47:12 loe volumio[12811]: info: Plugin mpdemulation is not enabled Mar 04 08:47:12 loe volumio[12811]: info: Loading plugin "rest_api"... Mar 04 08:47:12 loe volumio[12811]: info: Loading plugin "websocket"... Mar 04 08:47:12 loe volumio[12811]: info: Starting Socket.io Server version 1.7.4 Mar 04 08:47:12 loe volumio[12811]: info: Loading i18n strings for locale nl Mar 04 08:47:12 loe volumio[12811]: Updating browse sources language Mar 04 08:47:12 loe volumio[12811]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 04 08:47:12 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Mar 04 08:47:12 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Mar 04 08:47:12 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Mar 04 08:47:12 loe volumio[12811]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 04 08:47:12 loe volumio[12811]: info: CoreCommandRouter::initPlayerControls Mar 04 08:47:12 loe volumio[12811]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 08:47:12 loe volumio[12811]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 08:47:12 loe volumio[12811]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 08:47:12 loe volumio[12811]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 08:47:12 loe volumio[12811]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 08:47:12 loe volumio[12811]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 08:47:12 loe volumio[12811]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 08:47:12 loe volumio[12811]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 08:47:12 loe volumio[12811]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 04 08:47:12 loe volumio[12811]: Express server listening on port 3000 Mar 04 08:47:12 loe volumio[12811]: [Metrics] WebUI: 11s 520.28ms Mar 04 08:47:12 loe volumio[12811]: info: CoreStateMachine::resetVolumioState Mar 04 08:47:12 loe volumio[12811]: info: CoreStateMachine::getcurrentVolume Mar 04 08:47:12 loe volumio[12811]: info: CoreCommandRouter::volumioRetrievevolume Mar 04 08:47:12 loe volumio[12811]: info: Volumio Network Manager: Network status updated: 1 Mar 04 08:47:12 loe volumio[12811]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 08:47:12 loe volumio[12899]: Forking 3 albumart workers Mar 04 08:47:12 loe volumio[12811]: info: Reloading queue from file Mar 04 08:47:12 loe volumio[12811]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 1 Mar 04 08:47:12 loe volumio[12811]: info: VolumeController:: Volume=5 Mute =false Mar 04 08:47:12 loe volumio[12811]: info: CoreStateMachine::pushState Mar 04 08:47:12 loe volumio[12811]: info: CorePlayQueue::getTrack 0 Mar 04 08:47:12 loe volumio[12811]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 04 08:47:12 loe volumio[12811]: info: CoreCommandRouter::volumioPushState Mar 04 08:47:12 loe volumio[12811]: info: CoreStateMachine::updateTrackBlock Mar 04 08:47:12 loe volumio[12811]: info: CorePlayQueue::getTrackBlock Mar 04 08:47:12 loe volumio[12811]: info: CoreCommandRouter::volumioRetrievevolume Mar 04 08:47:12 loe volumio[12811]: info: CoreStateMachine::setRepeat false single undefined Mar 04 08:47:12 loe volumio[12811]: info: CoreStateMachine::pushState Mar 04 08:47:12 loe volumio[12811]: info: CorePlayQueue::getTrack 0 Mar 04 08:47:12 loe volumio[12811]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 04 08:47:12 loe volumio[12811]: info: CoreCommandRouter::volumioPushState Mar 04 08:47:12 loe volumio[12811]: info: CoreStateMachine::setRandom undefined Mar 04 08:47:12 loe volumio[12811]: info: CoreStateMachine::pushState Mar 04 08:47:12 loe volumio[12811]: info: CorePlayQueue::getTrack 0 Mar 04 08:47:12 loe volumio[12811]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 04 08:47:12 loe volumio[12811]: info: CoreCommandRouter::volumioPushState Mar 04 08:47:13 loe volumio[12811]: info: Setting Device type: Raspberry PI Mar 04 08:47:13 loe volumio[12811]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 1 Mar 04 08:47:13 loe volumio[12811]: info: Received Get System Info Mar 04 08:47:13 loe volumio[12811]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 04 08:47:13 loe volumio[12811]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 04 08:47:13 loe volumio[12811]: info: Discovery: Getting this device information Mar 04 08:47:13 loe volumio[12811]: info: CoreCommandRouter::volumioGetState Mar 04 08:47:13 loe volumio[12811]: info: CorePlayQueue::getTrack 0 Mar 04 08:47:13 loe volumio[12811]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 04 08:47:13 loe volumio[12811]: info: Completed loading Core Plugins Mar 04 08:47:13 loe volumio[12811]: info: Preparing to generate the ALSA configuration file Mar 04 08:47:13 loe volumio[12811]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Mar 04 08:47:13 loe volumio[12811]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Mar 04 08:47:13 loe volumio[12811]: info: Asound.conf file unchanged, so no further update is needed Mar 04 08:47:13 loe volumio[12811]: info: Output device has changed, restarting MPD Mar 04 08:47:13 loe volumio[12811]: info: Output device has changed, restarting Shairport Sync Mar 04 08:47:13 loe volumio[12811]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 08:47:13 loe volumio[12811]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 08:47:13 loe volumio[12811]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 04 08:47:13 loe volumio[12811]: info: ___________ START PLUGINS ___________ Mar 04 08:47:13 loe sudo[12955]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 04 08:47:13 loe sudo[12955]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 08:47:13 loe sudo[12957]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 04 08:47:13 loe sudo[12957]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 08:47:13 loe sudo[12955]: pam_unix(sudo:session): session closed for user root Mar 04 08:47:13 loe volumio[12811]: info: ControllerMpd::onStart: Initializing MPD Mar 04 08:47:13 loe volumio[12811]: info: Creating MPD Configuration file Mar 04 08:47:13 loe volumio[12811]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 04 08:47:13 loe sudo[12965]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumio5-onboarding.service Mar 04 08:47:13 loe sudo[12965]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 08:47:13 loe volumio[12811]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 04 08:47:13 loe volumio[12811]: info: [1772610433577] CoreMusicLibrary::Adding element Media Servers Mar 04 08:47:13 loe volumio[12811]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 04 08:47:13 loe sudo[12967]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 04 08:47:13 loe sudo[12967]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 08:47:13 loe systemd[1]: Stopping mpd.service - Music Player Daemon... Mar 04 08:47:13 loe sudo[12967]: pam_unix(sudo:session): session closed for user root Mar 04 08:47:13 loe volumio[12811]: info: UPNP Browser: Client initialized successfully Mar 04 08:47:13 loe sudo[12969]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 04 08:47:13 loe sudo[12969]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 08:47:13 loe volumio[12811]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 08:47:13 loe volumio[12811]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 08:47:13 loe volumio[12811]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 04 08:47:13 loe volumio[12811]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 08:47:13 loe volumio[12811]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 08:47:13 loe systemd[1]: mpd.service: Deactivated successfully. Mar 04 08:47:13 loe systemd[1]: Stopped mpd.service - Music Player Daemon. Mar 04 08:47:13 loe systemd[1]: mpd.service: Consumed 6.756s CPU time. Mar 04 08:47:13 loe systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 20. Mar 04 08:47:13 loe systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 04 08:47:13 loe volumio[12811]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 04 08:47:13 loe volumio[12811]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 04 08:47:13 loe volumio[12811]: info: [1772610433863] CoreMusicLibrary::Adding element Last_100 Mar 04 08:47:13 loe volumio[12811]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 04 08:47:13 loe volumio[12811]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 04 08:47:13 loe volumio[12811]: info: [1772610433880] CoreMusicLibrary::Adding element Webradio Mar 04 08:47:13 loe volumio[12811]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 04 08:47:13 loe volumio[12811]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 04 08:47:13 loe volumio[12811]: info: Initializing BBC Radios Mar 04 08:47:13 loe systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 04 08:47:13 loe go-librespot[12981]: go-librespot daemon starting... Mar 04 08:47:13 loe systemd[1]: mpd.socket: Deactivated successfully. Mar 04 08:47:13 loe systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Mar 04 08:47:13 loe systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Mar 04 08:47:13 loe systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Mar 04 08:47:13 loe systemd[1]: Starting mpd.service - Music Player Daemon... Mar 04 08:47:14 loe sudo[12965]: pam_unix(sudo:session): session closed for user root Mar 04 08:47:14 loe go-librespot[12984]: time="2026-03-04T08:47:14+01:00" level=info msg="running go-librespot 0.4.0" Mar 04 08:47:14 loe go-librespot[12984]: time="2026-03-04T08:47:14+01:00" level=debug msg="app state loaded" Mar 04 08:47:14 loe go-librespot[12984]: time="2026-03-04T08:47:14+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 04 08:47:14 loe volumio[12811]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 04 08:47:14 loe volumio[12811]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 08:47:14 loe volumio[12811]: info: Creating Spotify config file Mar 04 08:47:14 loe volumio[12811]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 08:47:14 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Mar 04 08:47:14 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Mar 04 08:47:14 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Mar 04 08:47:14 loe sudo[12993]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Mar 04 08:47:14 loe sudo[12993]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Mar 04 08:47:14 loe sudo[12993]: pam_unix(sudo:session): session closed for user root Mar 04 08:47:14 loe go-librespot[12984]: time="2026-03-04T08:47:14+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Mar 04 08:47:14 loe go-librespot[12984]: time="2026-03-04T08:47:14+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Mar 04 08:47:14 loe go-librespot[12984]: time="2026-03-04T08:47:14+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Mar 04 08:47:14 loe go-librespot[12984]: time="2026-03-04T08:47:14+01:00" level=info msg="zeroconf server listening on port 36841" Mar 04 08:47:14 loe go-librespot[12984]: time="2026-03-04T08:47:14+01:00" level=debug msg="obtained new client token: AAB18wlb1hHgrZr08Q0VrI2Oa6Q0pstwEzqqxBSDoFvVbqBr5dvrh/wGbeM8TmqHN2rBXuFdJg+nPvk9gYZoAzbQIbklKKpqmKfDlD4JZiRS4c9IyDreh3S+R3qTRbSPZZAvnlme6qtPmKDQfBNvmsQ6+7XYQhtrz0k8CR5F7P7qIB4A5kcUyLgC16fwIRZCcZvi8Z3CWFIQ+WAFhv1OXu2qovWMuR0mabtMQoqVgzJ2r13EeV4iVrLLBA==" Mar 04 08:47:14 loe go-librespot[12984]: time="2026-03-04T08:47:14+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 04 08:47:15 loe go-librespot[12984]: time="2026-03-04T08:47:15+01:00" level=debug msg="completed keyexchange" Mar 04 08:47:15 loe go-librespot[12984]: time="2026-03-04T08:47:15+01:00" level=debug msg="completed challenge" Mar 04 08:47:15 loe go-librespot[12984]: time="2026-03-04T08:47:15+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 04 08:47:15 loe systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 04 08:47:15 loe systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 04 08:47:15 loe volumio[12811]: info: Volumio Calling Home Mar 04 08:47:15 loe volumio-remote-updater[714]: [2026-03-04 08:47:15] [connect] Successful connection Mar 04 08:47:16 loe sudo[13026]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 04 08:47:16 loe sudo[13026]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 08:47:16 loe volumio[12811]: info: Discovery: adding 07fbb113-343c-4b34-af49-444dc3d8fb26 Mar 04 08:47:16 loe volumio[12811]: info: Discovery: Found device Loe Mar 04 08:47:16 loe volumio[12811]: info: CoreCommandRouter::volumioGetState Mar 04 08:47:16 loe sudo[13028]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 04 08:47:16 loe sudo[13028]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 08:47:16 loe volumio[12811]: info: CorePlayQueue::getTrack 0 Mar 04 08:47:16 loe sudo[13026]: pam_unix(sudo:session): session closed for user root Mar 04 08:47:16 loe sudo[13028]: pam_unix(sudo:session): session closed for user root Mar 04 08:47:16 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Mar 04 08:47:16 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Mar 04 08:47:16 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Mar 04 08:47:16 loe volumio[12811]: info: MPD Permissions set Mar 04 08:47:16 loe volumio[12811]: info: MPD Permissions set Mar 04 08:47:16 loe volumio[12811]: info: VolumeController:: Volume=5 Mute =false Mar 04 08:47:16 loe volumio[12811]: info: CoreStateMachine::pushState Mar 04 08:47:16 loe volumio[12811]: info: CorePlayQueue::getTrack 0 Mar 04 08:47:16 loe volumio[12811]: info: CoreCommandRouter::volumioPushState Mar 04 08:47:16 loe volumio[12811]: info: Discovery: this is already registered, 07fbb113-343c-4b34-af49-444dc3d8fb26 Mar 04 08:47:16 loe volumio[12811]: info: Discovery: Found device Loe Mar 04 08:47:16 loe volumio[12811]: info: CoreCommandRouter::volumioGetState Mar 04 08:47:16 loe volumio[12811]: info: CorePlayQueue::getTrack 0 Mar 04 08:47:16 loe volumio-remote-updater[714]: [2026-03-04 08:47:16] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1772610435 101 Mar 04 08:47:16 loe volumio[12811]: 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: 2 Mar 04 08:47:16 loe volumio[12811]: info: Volumio called home Mar 04 08:47:16 loe volumio[12811]: info: Spotify config file written Mar 04 08:47:16 loe sudo[13032]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Mar 04 08:47:16 loe volumio[12922]: Starting albumart workers Mar 04 08:47:16 loe sudo[13032]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 08:47:16 loe systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 04 08:47:16 loe systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 04 08:47:16 loe go-librespot[13034]: go-librespot daemon starting... Mar 04 08:47:16 loe sudo[13032]: pam_unix(sudo:session): session closed for user root Mar 04 08:47:16 loe go-librespot[13035]: time="2026-03-04T08:47:16+01:00" level=info msg="running go-librespot 0.4.0" Mar 04 08:47:16 loe go-librespot[13035]: time="2026-03-04T08:47:16+01:00" level=debug msg="app state loaded" Mar 04 08:47:16 loe go-librespot[13035]: time="2026-03-04T08:47:16+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 04 08:47:16 loe volumio[12921]: Starting albumart workers Mar 04 08:47:16 loe volumio[12811]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Mar 04 08:47:16 loe volumio[12811]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 08:47:16 loe volumio[12811]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 08:47:16 loe volumio[12811]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 08:47:17 loe volumio[12811]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 08:47:17 loe volumio[12811]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 08:47:17 loe volumio[12811]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 08:47:17 loe volumio[12811]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 08:47:17 loe volumio[12811]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 08:47:17 loe volumio[12920]: Starting albumart workers Mar 04 08:47:17 loe volumio[12811]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 08:47:17 loe volumio[12811]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 08:47:17 loe volumio[12811]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 08:47:17 loe volumio[12811]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 08:47:17 loe volumio[12811]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 08:47:17 loe volumio[12811]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 08:47:17 loe volumio[12811]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 08:47:17 loe volumio[12811]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 08:47:17 loe volumio[12811]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 08:47:17 loe volumio[12811]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 08:47:17 loe volumio[12811]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 08:47:17 loe volumio[12811]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 08:47:17 loe volumio[12811]: info: No need to fix Spotify hosts Mar 04 08:47:17 loe go-librespot[13035]: time="2026-03-04T08:47:17+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 04 08:47:17 loe go-librespot[13035]: time="2026-03-04T08:47:17+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 04 08:47:17 loe go-librespot[13035]: time="2026-03-04T08:47:17+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 04 08:47:17 loe go-librespot[13035]: time="2026-03-04T08:47:17+01:00" level=info msg="zeroconf server listening on port 44149" Mar 04 08:47:17 loe go-librespot[13035]: time="2026-03-04T08:47:17+01:00" level=debug msg="obtained new client token: AABMONdo/9cDQ2IIxIX5C7IRX0VV8XPgAAnul7dEOCe/AHpySwfk04UIU9pA2nCguhl5TW5oNlW5Tp0UikmWEN710wiZbMZ2qSEHHwiAm00UonGXLcOiNU/oQ9fPn/dGS8FlDAWQbpTyfAKfn6OSfr+/qeI48VIQ3Zr9p65W2wWnxHjeqHw+01ke+3psvOAU1SjT/4CtSWHB40edO60I26gFpB4kfx45+WgBPseEr3vYyX+UsBij4Sv26w==" Mar 04 08:47:17 loe volumio[12811]: info: An error occurred while refreshing Spotify Token Error: Bad Request Mar 04 08:47:17 loe volumio[12811]: info: Starting Shairport Sync Mar 04 08:47:17 loe go-librespot[13035]: time="2026-03-04T08:47:17+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 04 08:47:17 loe volumio[12811]: info: Starting Shairport Sync Mar 04 08:47:17 loe volumio[12811]: info: Starting Shairport Sync Mar 04 08:47:17 loe go-librespot[13035]: time="2026-03-04T08:47:17+01:00" level=debug msg="completed keyexchange" Mar 04 08:47:17 loe go-librespot[13035]: time="2026-03-04T08:47:17+01:00" level=debug msg="completed challenge" Mar 04 08:47:17 loe sudo[13056]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 04 08:47:17 loe sudo[13056]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 08:47:17 loe go-librespot[13035]: time="2026-03-04T08:47:17+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 04 08:47:17 loe systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 04 08:47:17 loe systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 04 08:47:17 loe sudo[13054]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 04 08:47:17 loe sudo[13054]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 08:47:17 loe sudo[13061]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Mar 04 08:47:17 loe sudo[13061]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 08:47:17 loe volumio[12811]: info: CoreCommandRouter::volumioGetState Mar 04 08:47:17 loe volumio[12811]: info: CorePlayQueue::getTrack 0 Mar 04 08:47:18 loe sudo[13059]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 04 08:47:18 loe sudo[13059]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 08:47:18 loe systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Mar 04 08:47:18 loe sudo[13061]: pam_unix(sudo:session): session closed for user root Mar 04 08:47:18 loe systemd[1]: shairport-sync.service: Deactivated successfully. Mar 04 08:47:18 loe systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 04 08:47:18 loe systemd[1]: shairport-sync.service: Consumed 2.301s CPU time. Mar 04 08:47:18 loe volumio[12811]: info: Upmpdcli Daemon Started Mar 04 08:47:18 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Mar 04 08:47:18 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Mar 04 08:47:18 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Mar 04 08:47:18 loe systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 04 08:47:18 loe sudo[13054]: pam_unix(sudo:session): session closed for user root Mar 04 08:47:18 loe sudo[13056]: pam_unix(sudo:session): session closed for user root Mar 04 08:47:18 loe volumio[12811]: info: Shairport-Sync Started Mar 04 08:47:18 loe volumio[12811]: Error adding Membership: Error: addMembership EINVAL Mar 04 08:47:18 loe volumio[12811]: info: Shairport-Sync Started Mar 04 08:47:18 loe systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Mar 04 08:47:18 loe systemd[1]: shairport-sync.service: Deactivated successfully. Mar 04 08:47:18 loe systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 04 08:47:18 loe systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 04 08:47:18 loe sudo[13059]: pam_unix(sudo:session): session closed for user root Mar 04 08:47:18 loe volumio[12811]: info: Shairport-Sync Started Mar 04 08:47:20 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Mar 04 08:47:20 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Mar 04 08:47:20 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Mar 04 08:47:20 loe volumio[12811]: info: go-librespot daemon successfully initialized Mar 04 08:47:21 loe systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 21. Mar 04 08:47:21 loe systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 04 08:47:21 loe systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 04 08:47:21 loe go-librespot[13113]: go-librespot daemon starting... Mar 04 08:47:21 loe go-librespot[13114]: time="2026-03-04T08:47:21+01:00" level=info msg="running go-librespot 0.4.0" Mar 04 08:47:21 loe go-librespot[13114]: time="2026-03-04T08:47:21+01:00" level=debug msg="app state loaded" Mar 04 08:47:21 loe go-librespot[13114]: time="2026-03-04T08:47:21+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 04 08:47:21 loe mpd[13007]: 2026-03-04T08:47:21 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Mar 04 08:47:21 loe systemd[1]: Started mpd.service - Music Player Daemon. Mar 04 08:47:21 loe sudo[12957]: pam_unix(sudo:session): session closed for user root Mar 04 08:47:21 loe sudo[12969]: pam_unix(sudo:session): session closed for user root Mar 04 08:47:21 loe volumio[12811]: info: Completed starting Core Plugins Mar 04 08:47:21 loe volumio[12811]: info: ------------------------------------------- Mar 04 08:47:21 loe volumio[12811]: info: ----- MyVolumio plugins startup ---- Mar 04 08:47:21 loe volumio[12811]: info: ------------------------------------------- Mar 04 08:47:21 loe volumio[12811]: info: [MyVolumio PluginManager] Fetching plans data.... Mar 04 08:47:21 loe volumio[12811]: error: MPD error: The expression evaluated to a falsy value: Mar 04 08:47:21 loe volumio[12811]: assert.ok(self.idling) Mar 04 08:47:21 loe volumio[12811]: error: The expression evaluated to a falsy value: Mar 04 08:47:21 loe volumio[12811]: assert.ok(self.idling) Mar 04 08:47:21 loe volumio[12811]: error: updateQueue error: null Mar 04 08:47:21 loe volumio[12811]: info: MPD running with PID13007 Mar 04 08:47:21 loe volumio[12811]: ,establishing connection Mar 04 08:47:21 loe volumio[12811]: error: updateQueue error: null Mar 04 08:47:21 loe go-librespot[13114]: time="2026-03-04T08:47:21+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Mar 04 08:47:21 loe go-librespot[13114]: time="2026-03-04T08:47:21+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Mar 04 08:47:21 loe go-librespot[13114]: time="2026-03-04T08:47:21+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Mar 04 08:47:21 loe go-librespot[13114]: time="2026-03-04T08:47:21+01:00" level=info msg="zeroconf server listening on port 46743" Mar 04 08:47:21 loe go-librespot[13114]: time="2026-03-04T08:47:21+01:00" level=debug msg="obtained new client token: AACSJ9EJUeNZRnD+h1CnoS6qQjU23XEPb6ZAn7KIDsAVwFGQNKCROoZ0YllpqBYpuGyThKJGN/J+a9j/YTaegJ25YMf1F2eTKOL9r2a7ZF6MF6H/l1bC+OCzpOnoD54A9EdytQrfqptjbe7aBVUDAP+uIVoJXcuHNKM5XW+20v7TloDDLGA1HBgIOSdMGUoAuOu6QWX0io/Y2Yk2APHKTfqRR5ZJXdoWbXIwt74M241nO7T80nf8R4vkzQ==" Mar 04 08:47:21 loe go-librespot[13114]: time="2026-03-04T08:47:21+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 04 08:47:21 loe go-librespot[13114]: time="2026-03-04T08:47:21+01:00" level=debug msg="completed keyexchange" Mar 04 08:47:21 loe go-librespot[13114]: time="2026-03-04T08:47:21+01:00" level=debug msg="completed challenge" Mar 04 08:47:21 loe go-librespot[13114]: time="2026-03-04T08:47:21+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 04 08:47:21 loe systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 04 08:47:21 loe systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 04 08:47:22 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Mar 04 08:47:22 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Mar 04 08:47:22 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Mar 04 08:47:23 loe volumio[12811]: info: Initializing connection to go-librespot Websocket Mar 04 08:47:23 loe volumio[12811]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 04 08:47:24 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Mar 04 08:47:24 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Mar 04 08:47:24 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Mar 04 08:47:25 loe systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 22. Mar 04 08:47:25 loe systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 04 08:47:25 loe systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 04 08:47:25 loe go-librespot[13126]: go-librespot daemon starting... Mar 04 08:47:25 loe go-librespot[13127]: time="2026-03-04T08:47:25+01:00" level=info msg="running go-librespot 0.4.0" Mar 04 08:47:25 loe go-librespot[13127]: time="2026-03-04T08:47:25+01:00" level=debug msg="app state loaded" Mar 04 08:47:25 loe go-librespot[13127]: time="2026-03-04T08:47:25+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 04 08:47:25 loe go-librespot[13127]: time="2026-03-04T08:47:25+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Mar 04 08:47:25 loe go-librespot[13127]: time="2026-03-04T08:47:25+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Mar 04 08:47:25 loe go-librespot[13127]: time="2026-03-04T08:47:25+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Mar 04 08:47:25 loe go-librespot[13127]: time="2026-03-04T08:47:25+01:00" level=info msg="zeroconf server listening on port 33151" Mar 04 08:47:25 loe go-librespot[13127]: time="2026-03-04T08:47:25+01:00" level=debug msg="obtained new client token: AABF5jTrvteAHMtKrRAvwfvybI2wl9BE+GaOtcIrqPRN+XQCaqIyHzSBnLbWoGfEpogs7Pq+3y6kUbXJUaSwPKOHMtItnoHgx2EhA47cOdiyHX7prUrKscP5+Ttpu2EJ9a+8YsIlcOdYFJFTPaQlBBCGRET0trbOtZnLdqRs1wrvpV4kkzG6JQ2D8gjh+Q7kpe+NML1pWdmskDaOTfriVfULiiXn3mZfap88/Nd/vrjrSIfyXaz8mBiLZA==" Mar 04 08:47:25 loe go-librespot[13127]: time="2026-03-04T08:47:25+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 04 08:47:25 loe go-librespot[13127]: time="2026-03-04T08:47:25+01:00" level=debug msg="completed keyexchange" Mar 04 08:47:25 loe go-librespot[13127]: time="2026-03-04T08:47:25+01:00" level=debug msg="completed challenge" Mar 04 08:47:25 loe go-librespot[13127]: time="2026-03-04T08:47:25+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 04 08:47:25 loe systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 04 08:47:25 loe systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 04 08:47:26 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Mar 04 08:47:26 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Mar 04 08:47:26 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Mar 04 08:47:26 loe volumio[12811]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Mar 04 08:47:26 loe volumio[12811]: info: Initializing connection to go-librespot Websocket Mar 04 08:47:26 loe volumio[12811]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 04 08:47:28 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Mar 04 08:47:28 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Mar 04 08:47:28 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Mar 04 08:47:29 loe systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 23. Mar 04 08:47:29 loe systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 04 08:47:29 loe systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 04 08:47:29 loe go-librespot[13148]: go-librespot daemon starting... Mar 04 08:47:29 loe go-librespot[13149]: time="2026-03-04T08:47:29+01:00" level=info msg="running go-librespot 0.4.0" Mar 04 08:47:29 loe go-librespot[13149]: time="2026-03-04T08:47:29+01:00" level=debug msg="app state loaded" Mar 04 08:47:29 loe go-librespot[13149]: time="2026-03-04T08:47:29+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 04 08:47:29 loe go-librespot[13149]: time="2026-03-04T08:47:29+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 04 08:47:29 loe go-librespot[13149]: time="2026-03-04T08:47:29+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 04 08:47:29 loe go-librespot[13149]: time="2026-03-04T08:47:29+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 04 08:47:29 loe go-librespot[13149]: time="2026-03-04T08:47:29+01:00" level=info msg="zeroconf server listening on port 43289" Mar 04 08:47:29 loe volumio[12811]: info: Initializing connection to go-librespot Websocket Mar 04 08:47:29 loe go-librespot[13149]: time="2026-03-04T08:47:29+01:00" level=debug msg="new websocket client" Mar 04 08:47:29 loe volumio[12811]: info: Connection to go-librespot Websocket established Mar 04 08:47:29 loe go-librespot[13149]: time="2026-03-04T08:47:29+01:00" level=debug msg="obtained new client token: AAABkDyccJZKx1Z5OKZH+0bMq6Rf6HwJml7xJYgmzsGlstUs5qyf4dfwmhgnndQrkKdoEcbHtRMEl8hBKLnz2BRAXZmjw0OFhZgEItlpPMJzh34Rg3DVLh7G269+BYLnNVUXA6Nin/zOl4kqG74rurw6qWrXPmHPCOi5hv7nVyTPvJwojXKZbDhdWpPyDeqdK4/RS8fXIr5JzIOWREJqzv3LMG0h2uVhNix+2gHgAUZAF3JhT7WvUWXovg==" Mar 04 08:47:29 loe volumio[12811]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Mar 04 08:47:29 loe volumio[12811]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Mar 04 08:47:29 loe volumio[12811]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Mar 04 08:47:29 loe volumio[12811]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Mar 04 08:47:29 loe volumio[12811]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Mar 04 08:47:29 loe volumio[12811]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Mar 04 08:47:29 loe volumio[12811]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Mar 04 08:47:29 loe volumio[12811]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Mar 04 08:47:29 loe volumio[12811]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Mar 04 08:47:29 loe volumio[12811]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Mar 04 08:47:29 loe volumio[12811]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Mar 04 08:47:29 loe volumio[12811]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Mar 04 08:47:29 loe volumio[12811]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Mar 04 08:47:29 loe volumio[12811]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Mar 04 08:47:29 loe volumio[12811]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Mar 04 08:47:29 loe volumio[12811]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Mar 04 08:47:29 loe volumio[12811]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Mar 04 08:47:29 loe volumio[12811]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Mar 04 08:47:29 loe volumio[12811]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Mar 04 08:47:29 loe volumio[12811]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Mar 04 08:47:29 loe volumio[12811]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Mar 04 08:47:29 loe volumio[12811]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Mar 04 08:47:29 loe volumio[12811]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Mar 04 08:47:29 loe volumio[12811]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Mar 04 08:47:29 loe volumio[12811]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Mar 04 08:47:29 loe volumio[12811]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Mar 04 08:47:29 loe volumio[12811]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Mar 04 08:47:29 loe volumio[12811]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Mar 04 08:47:29 loe volumio[12811]: info: Adding plugin bluetooth to MyMusic Plugins Mar 04 08:47:29 loe volumio[12811]: info: Adding plugin multiroom to MyMusic Plugins Mar 04 08:47:29 loe volumio[12811]: info: Adding plugin metavolumio to MyMusic Plugins Mar 04 08:47:29 loe volumio[12811]: info: Adding plugin cd_controller to MyMusic Plugins Mar 04 08:47:29 loe volumio[12811]: info: Adding plugin qobuzconnect to MyMusic Plugins Mar 04 08:47:29 loe volumio[12811]: info: Adding plugin smart_inputs to MyMusic Plugins Mar 04 08:47:29 loe volumio[12811]: info: Adding plugin tidalconnect to MyMusic Plugins Mar 04 08:47:29 loe volumio[12811]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Mar 04 08:47:29 loe go-librespot[13149]: time="2026-03-04T08:47:29+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 04 08:47:29 loe go-librespot[13149]: time="2026-03-04T08:47:29+01:00" level=debug msg="completed keyexchange" Mar 04 08:47:29 loe go-librespot[13149]: time="2026-03-04T08:47:29+01:00" level=debug msg="completed challenge" Mar 04 08:47:29 loe go-librespot[13149]: time="2026-03-04T08:47:29+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 04 08:47:29 loe systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 04 08:47:29 loe systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 04 08:47:30 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Mar 04 08:47:30 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Mar 04 08:47:30 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Mar 04 08:47:31 loe volumio[12811]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Mar 04 08:47:31 loe volumio[12811]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Mar 04 08:47:31 loe volumio[12811]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 08:47:31 loe volumio[12811]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 08:47:31 loe volumio[12811]: info: Starting MyVolumio Remote Streaming Endpoints Mar 04 08:47:31 loe volumio[12811]: info: MyVolumio login type: Token Mar 04 08:47:31 loe volumio[12811]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Mar 04 08:47:31 loe volumio[12811]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Mar 04 08:47:32 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Mar 04 08:47:32 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Mar 04 08:47:32 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Mar 04 08:47:33 loe systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 24. Mar 04 08:47:33 loe systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 04 08:47:33 loe systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 04 08:47:33 loe go-librespot[13156]: go-librespot daemon starting... Mar 04 08:47:33 loe go-librespot[13157]: time="2026-03-04T08:47:33+01:00" level=info msg="running go-librespot 0.4.0" Mar 04 08:47:33 loe go-librespot[13157]: time="2026-03-04T08:47:33+01:00" level=debug msg="app state loaded" Mar 04 08:47:33 loe go-librespot[13157]: time="2026-03-04T08:47:33+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 04 08:47:33 loe volumio[12811]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Mar 04 08:47:33 loe volumio[12811]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Mar 04 08:47:33 loe volumio[12811]: info: Streaming services startup Mar 04 08:47:33 loe volumio[12811]: info: Starting Streaming Daemon Mar 04 08:47:33 loe sudo[13166]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Mar 04 08:47:33 loe sudo[13166]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 08:47:33 loe volumio[12811]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Mar 04 08:47:33 loe sudo[13166]: pam_unix(sudo:session): session closed for user root Mar 04 08:47:33 loe volumio[12811]: info: Getting Spotify volume Mar 04 08:47:33 loe volumio[12811]: info: Connection to go-librespot Websocket closed Mar 04 08:47:33 loe volumio[12811]: error: Cannot start Volumio Streaming Daemon Mar 04 08:47:33 loe volumio[12811]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Mar 04 08:47:33 loe volumio[12811]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Mar 04 08:47:33 loe volumio[12811]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 4 Mar 04 08:47:33 loe go-librespot[13157]: time="2026-03-04T08:47:33+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 04 08:47:33 loe go-librespot[13157]: time="2026-03-04T08:47:33+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 04 08:47:33 loe go-librespot[13157]: time="2026-03-04T08:47:33+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 04 08:47:33 loe go-librespot[13157]: time="2026-03-04T08:47:33+01:00" level=info msg="zeroconf server listening on port 41959" Mar 04 08:47:33 loe volumio[12811]: info: CoreCommandRouter::volumioGetState Mar 04 08:47:33 loe volumio[12811]: info: CorePlayQueue::getTrack 0 Mar 04 08:47:33 loe go-librespot[13157]: time="2026-03-04T08:47:33+01:00" level=debug msg="obtained new client token: AADqvXwVG8rREusCuUIzly9qlT64dbEeGV9AZc9+mMz9kQ+8Q/RgeAN1QBY77zFQKgMlqR3xrXh5Ge2UVZ2twyeYAJtxAJSqnAgynPnE+sDHQWkQSTSVGl/kMb5kPIPpegNmzNX3BQ20/5loHFX/r18EFZgD3rDLemuHG6XT+gHlv/lWVhTaidJiykF43OZ8FDsJUWpN61tKVdG/qx/9GKQVFsvKR5h0BZceV3l0LYiPZ1RXDJ8eHmhASw==" Mar 04 08:47:33 loe volumio[12811]: SPOTIFY: RECEIVED VOLUMIO VOLUME 5 Mar 04 08:47:33 loe volumio[12811]: SPOTIFY: SPOTIFY VOLUME undefined Mar 04 08:47:33 loe volumio[12811]: SPOTIFY: VOLUMIO VOLUME 5 Mar 04 08:47:33 loe volumio[12811]: info: Aligning Spotify Volume to Volumio Volume Mar 04 08:47:33 loe volumio[12811]: info: CoreCommandRouter::volumioGetState Mar 04 08:47:33 loe volumio[12811]: info: CorePlayQueue::getTrack 0 Mar 04 08:47:33 loe volumio[12811]: info: Setting Spotify Volume from Volumio: 5 Mar 04 08:47:33 loe go-librespot[13157]: time="2026-03-04T08:47:33+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 04 08:47:33 loe go-librespot[13157]: time="2026-03-04T08:47:33+01:00" level=debug msg="completed keyexchange" Mar 04 08:47:33 loe go-librespot[13157]: time="2026-03-04T08:47:33+01:00" level=debug msg="completed challenge" Mar 04 08:47:33 loe go-librespot[13157]: time="2026-03-04T08:47:33+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 04 08:47:33 loe systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 04 08:47:33 loe systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 04 08:47:33 loe volumio[12811]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 04 08:47:33 loe volumio[12811]: Error: socket hang up Mar 04 08:47:33 loe volumio[12811]: at connResetException (node:internal/errors:720:14) Mar 04 08:47:33 loe volumio[12811]: at Socket.socketOnEnd (node:_http_client:519:23) Mar 04 08:47:33 loe volumio[12811]: at Socket.emit (node:events:526:35) Mar 04 08:47:33 loe volumio[12811]: at endReadableNT (node:internal/streams/readable:1376:12) Mar 04 08:47:33 loe volumio[12811]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Mar 04 08:47:33 loe volumio[12811]: code: 'ECONNRESET', Mar 04 08:47:33 loe volumio[12811]: response: undefined Mar 04 08:47:33 loe volumio[12811]: } Mar 04 08:47:34 loe volumio[12811]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 04 08:47:34 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Mar 04 08:47:34 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Mar 04 08:47:34 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Mar 04 08:47:35 loe sudo[13186]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-03-04 08:46' Mar 04 08:47:35 loe sudo[13186]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 08:47:35 loe sudo[13186]: pam_unix(sudo:session): session closed for user root Mar 04 08:47:36 loe volumio-remote-updater[714]: [2026-03-04 08:47:36] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Mar 04 08:47:36 loe volumio-remote-updater[714]: [2026-03-04 08:47:36] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Mar 04 08:47:36 loe volumio5-onboarding[2840]: time=2026-03-04T08:47:36.242+01:00 level=ERROR msg="failed reading message" component=volumio/socket error="websocket: close 1006 (abnormal closure): unexpected EOF" Mar 04 08:47:36 loe systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Mar 04 08:47:36 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Mar 04 08:47:36 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Mar 04 08:47:36 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Mar 04 08:47:36 loe volumio5-onboarding[2840]: time=2026-03-04T08:47:36.248+01:00 level=WARN msg="reconnection attempt failed" component=volumio/socket error="dial tcp 127.0.0.1:3000: connect: connection refused" Mar 04 08:47:36 loe systemd[1]: volumio.service: Failed with result 'exit-code'. Mar 04 08:47:36 loe systemd[1]: volumio.service: Consumed 44.994s CPU time. Mar 04 08:47:36 loe systemd[1]: Started dynamicswap.service - dynamicswap service. Mar 04 08:47:36 loe systemd[1]: dynamicswap.service: Deactivated successfully. Mar 04 08:47:36 loe systemd[1]: volumio.service: Scheduled restart job, restart counter is at 555. Mar 04 08:47:36 loe systemd[1]: Started dynamicswap.service - dynamicswap service. Mar 04 08:47:36 loe systemd[1]: Stopped volumio.service - Volumio Backend Module. Mar 04 08:47:36 loe systemd[1]: volumio.service: Consumed 44.994s CPU time. Mar 04 08:47:36 loe systemd[1]: Started volumio.service - Volumio Backend Module. Mar 04 08:47:36 loe systemd[1]: dynamicswap.service: Deactivated successfully. Mar 04 08:47:37 loe systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 25. Mar 04 08:47:37 loe systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 04 08:47:37 loe systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 04 08:47:37 loe go-librespot[13230]: go-librespot daemon starting... Mar 04 08:47:37 loe go-librespot[13231]: time="2026-03-04T08:47:37+01:00" level=info msg="running go-librespot 0.4.0" Mar 04 08:47:37 loe go-librespot[13231]: time="2026-03-04T08:47:37+01:00" level=debug msg="app state loaded" Mar 04 08:47:37 loe go-librespot[13231]: time="2026-03-04T08:47:37+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 04 08:47:37 loe volumio5-onboarding[2840]: time=2026-03-04T08:47:37.252+01:00 level=WARN msg="reconnection attempt failed" component=volumio/socket error="dial tcp 127.0.0.1:3000: connect: connection refused" Mar 04 08:47:37 loe go-librespot[13231]: time="2026-03-04T08:47:37+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 04 08:47:37 loe go-librespot[13231]: time="2026-03-04T08:47:37+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 04 08:47:37 loe go-librespot[13231]: time="2026-03-04T08:47:37+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 04 08:47:37 loe go-librespot[13231]: time="2026-03-04T08:47:37+01:00" level=info msg="zeroconf server listening on port 40123" Mar 04 08:47:37 loe go-librespot[13231]: time="2026-03-04T08:47:37+01:00" level=debug msg="obtained new client token: AAC+yXSlAtEPmArQN+KkLCZHxa70xnmdNgN5QUHzDOjUo7CPys3Z7v75peK+diU0wodWaQVPEX+2KaU8viDMNjZX+OXK5y+cDfaDoCXLWjR+mSpPFbwDKjsG/Twz+KJpWuRTMGiLwcbysrmwqTY9A3TzXhnBYAF7DqVS7EFxLmJYX0hsWoPeLTLMigBqyMPjaC9KsaBOMQgwRdYEDVxIAy7gkCrQpq5GNeZfVxEB5Roui5xWKpcrZhbekQ==" Mar 04 08:47:37 loe go-librespot[13231]: time="2026-03-04T08:47:37+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 04 08:47:37 loe go-librespot[13231]: time="2026-03-04T08:47:37+01:00" level=debug msg="completed keyexchange" Mar 04 08:47:37 loe go-librespot[13231]: time="2026-03-04T08:47:37+01:00" level=debug msg="completed challenge" Mar 04 08:47:37 loe go-librespot[13231]: time="2026-03-04T08:47:37+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 04 08:47:37 loe systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 04 08:47:37 loe systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 04 08:47:38 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Mar 04 08:47:38 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Mar 04 08:47:38 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Mar 04 08:47:38 loe volumio5-onboarding[2840]: time=2026-03-04T08:47:38.254+01:00 level=WARN msg="reconnection attempt failed" component=volumio/socket error="dial tcp 127.0.0.1:3000: connect: connection refused" Mar 04 08:47:39 loe volumio[13215]: info: ------------------------------------------- Mar 04 08:47:39 loe volumio[13215]: info: ----- Volumio3 ---- Mar 04 08:47:39 loe volumio[13215]: info: ------------------------------------------- Mar 04 08:47:39 loe volumio[13215]: info: ----- System startup ---- Mar 04 08:47:39 loe volumio[13215]: info: ------------------------------------------- Mar 04 08:47:40 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Mar 04 08:47:40 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Mar 04 08:47:40 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Mar 04 08:47:41 loe systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 26. Mar 04 08:47:41 loe systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 04 08:47:41 loe systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 04 08:47:41 loe go-librespot[13245]: go-librespot daemon starting... Mar 04 08:47:41 loe volumio[13215]: info: MYVOLUMIO Environment detected Mar 04 08:47:41 loe go-librespot[13249]: time="2026-03-04T08:47:41+01:00" level=info msg="running go-librespot 0.4.0" Mar 04 08:47:41 loe go-librespot[13249]: time="2026-03-04T08:47:41+01:00" level=debug msg="app state loaded" Mar 04 08:47:41 loe go-librespot[13249]: time="2026-03-04T08:47:41+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 04 08:47:41 loe volumio-remote-updater[714]: [2026-03-04 08:47:41] [connect] Successful connection Mar 04 08:47:41 loe volumio[13215]: info: Plugin folders cleanup Mar 04 08:47:41 loe volumio[13215]: info: Scanning into folder /volumio/app/plugins/ Mar 04 08:47:41 loe volumio[13215]: info: Scanning category audio_interface Mar 04 08:47:41 loe volumio[13215]: info: Scanning category miscellanea Mar 04 08:47:41 loe volumio[13215]: info: Scanning category music_service Mar 04 08:47:41 loe volumio[13215]: info: Scanning category plugins.json Mar 04 08:47:41 loe volumio[13215]: info: Scanning category system_controller Mar 04 08:47:41 loe volumio[13215]: info: Scanning category user_interface Mar 04 08:47:41 loe volumio[13215]: info: Scanning into folder /data/plugins/ Mar 04 08:47:41 loe volumio[13215]: info: Scanning category music_service Mar 04 08:47:41 loe volumio[13215]: info: Plugin folders cleanup completed Mar 04 08:47:41 loe volumio[13215]: info: ------------------------------------------- Mar 04 08:47:41 loe volumio[13215]: info: ----- Core plugins startup ---- Mar 04 08:47:41 loe volumio[13215]: info: ------------------------------------------- Mar 04 08:47:41 loe volumio[13215]: info: Loading plugins from folder /volumio/app/plugins/ Mar 04 08:47:41 loe volumio[13215]: info: Adding plugin upnp to MyMusic Plugins Mar 04 08:47:41 loe volumio[13215]: info: Adding plugin airplay_emulation to MyMusic Plugins Mar 04 08:47:41 loe volumio[13215]: info: Adding plugin upnp_browser to MyMusic Plugins Mar 04 08:47:41 loe volumio[13215]: info: Loading plugins from folder /data/plugins/ Mar 04 08:47:41 loe volumio[13215]: info: Loading plugin "system"... Mar 04 08:47:41 loe volumio[13215]: info: Loading plugin "appearance"... Mar 04 08:47:41 loe go-librespot[13249]: time="2026-03-04T08:47:41+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 04 08:47:41 loe go-librespot[13249]: time="2026-03-04T08:47:41+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 04 08:47:41 loe go-librespot[13249]: time="2026-03-04T08:47:41+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 04 08:47:41 loe go-librespot[13249]: time="2026-03-04T08:47:41+01:00" level=info msg="zeroconf server listening on port 33665" Mar 04 08:47:41 loe go-librespot[13249]: time="2026-03-04T08:47:41+01:00" level=debug msg="obtained new client token: AABvhH4pQ++84xXH/IHDqY6mH0/V0n9V3OyTC4gBsesEcmeRyDQp1mfufy2GkB3+qN1MxIzOovhbZirjgZGcOViv0e8jhWYE6fmySOUVKxHJxFvespNIPNbc/0JJxXGJXP7q0YHsoSsgYZL9QPlzacShkfIRWsJYg96rsd4aaY5UnY4ehMQp1g/e4AVbqrpHwQ0FCTvEkVHtW8jKBcOmZM3skosE/iZNJQgp7b5PtOjeTtrqDrOmOiGMnA==" Mar 04 08:47:41 loe go-librespot[13249]: time="2026-03-04T08:47:41+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 04 08:47:41 loe go-librespot[13249]: time="2026-03-04T08:47:41+01:00" level=debug msg="completed keyexchange" Mar 04 08:47:41 loe go-librespot[13249]: time="2026-03-04T08:47:41+01:00" level=debug msg="completed challenge" Mar 04 08:47:41 loe go-librespot[13249]: time="2026-03-04T08:47:41+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 04 08:47:41 loe systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 04 08:47:41 loe systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 04 08:47:42 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Mar 04 08:47:42 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Mar 04 08:47:42 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Mar 04 08:47:43 loe volumio[13215]: info: Loading plugin "network"... Mar 04 08:47:43 loe volumio[13215]: info: Refreshing Cached IP Addresses Mar 04 08:47:43 loe sudo[13261]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 04 08:47:43 loe sudo[13261]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 08:47:43 loe sudo[13263]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 04 08:47:43 loe sudo[13261]: pam_unix(sudo:session): session closed for user root Mar 04 08:47:43 loe sudo[13263]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 08:47:43 loe volumio[13215]: info: Loading plugin "services"... Mar 04 08:47:43 loe volumio[13215]: info: Loading plugin "volumio5onboarding"... Mar 04 08:47:43 loe sudo[13263]: pam_unix(sudo:session): session closed for user root Mar 04 08:47:43 loe sudo[13270]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Mar 04 08:47:43 loe sudo[13270]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 08:47:43 loe volumio[13215]: info: Loading plugin "alsa_controller"... Mar 04 08:47:43 loe volumio[13215]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 04 08:47:43 loe volumio[13215]: info: Loading plugin "wizard"... Mar 04 08:47:43 loe volumio[13215]: info: Loading plugin "networkfs"... Mar 04 08:47:43 loe volumio[13215]: info: Starting Udev Watcher for removable devices Mar 04 08:47:43 loe volumio[13215]: info: Ignoring mount for partition: boot Mar 04 08:47:43 loe volumio[13215]: info: Ignoring mount for partition: volumio Mar 04 08:47:43 loe volumio[13215]: info: Ignoring mount for partition: volumio_data Mar 04 08:47:43 loe volumio[13215]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 04 08:47:43 loe volumio[13215]: info: Loading plugin "volumio_command_line_client"... Mar 04 08:47:43 loe volumio[13215]: info: Loading plugin "upnp"... Mar 04 08:47:43 loe volumio[13215]: info: [1772610463778] Starting Upmpd Daemon Mar 04 08:47:43 loe volumio[13215]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 04 08:47:43 loe volumio[13215]: info: Loading plugin "my_music"... Mar 04 08:47:43 loe volumio[13215]: info: Loading plugin "mpd"... Mar 04 08:47:44 loe sudo[13270]: pam_unix(sudo:session): session closed for user root Mar 04 08:47:44 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Mar 04 08:47:44 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Mar 04 08:47:44 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Mar 04 08:47:44 loe volumio[13215]: info: Loading plugin "upnp_browser"... Mar 04 08:47:45 loe systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 27. Mar 04 08:47:45 loe systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 04 08:47:45 loe systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 04 08:47:45 loe go-librespot[13294]: go-librespot daemon starting... Mar 04 08:47:45 loe go-librespot[13295]: time="2026-03-04T08:47:45+01:00" level=info msg="running go-librespot 0.4.0" Mar 04 08:47:45 loe go-librespot[13295]: time="2026-03-04T08:47:45+01:00" level=debug msg="app state loaded" Mar 04 08:47:45 loe go-librespot[13295]: time="2026-03-04T08:47:45+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 04 08:47:45 loe go-librespot[13295]: time="2026-03-04T08:47:45+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Mar 04 08:47:45 loe go-librespot[13295]: time="2026-03-04T08:47:45+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Mar 04 08:47:45 loe go-librespot[13295]: time="2026-03-04T08:47:45+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Mar 04 08:47:45 loe go-librespot[13295]: time="2026-03-04T08:47:45+01:00" level=info msg="zeroconf server listening on port 33103" Mar 04 08:47:45 loe go-librespot[13295]: time="2026-03-04T08:47:45+01:00" level=debug msg="obtained new client token: AAATO70JWm6jc1HTyGm3N4tEINec9KmDaMlzmQmHuLuOHgofMTP+pUTlO4kVVDk90HyTots6mJ7XLncHQm2v1jA7SHBQfv48MEeAlO75kM+b5B3h3/TO9xCRawbxx4IkrxEtHQkzA85VmFLxuL7VhRklDIXeaypkzsd9H8Da07BxF4TrLrbNgJp0MrO4BZH40B+fI2fuaEtTbl/3yzOmNDnMH2LgIPd6q7tDnV19aeclnOQtJ53rvbH68A==" Mar 04 08:47:45 loe go-librespot[13295]: time="2026-03-04T08:47:45+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 04 08:47:45 loe go-librespot[13295]: time="2026-03-04T08:47:45+01:00" level=debug msg="completed keyexchange" Mar 04 08:47:45 loe go-librespot[13295]: time="2026-03-04T08:47:45+01:00" level=debug msg="completed challenge" Mar 04 08:47:45 loe go-librespot[13295]: time="2026-03-04T08:47:45+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 04 08:47:45 loe systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 04 08:47:45 loe systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 04 08:47:46 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Mar 04 08:47:46 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Mar 04 08:47:46 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Mar 04 08:47:47 loe volumio[13215]: info: Starting UPNP Browser Mar 04 08:47:47 loe volumio[13215]: info: Loading plugin "alarm-clock"... Mar 04 08:47:47 loe volumio[13215]: info: Loading plugin "airplay_emulation"... Mar 04 08:47:47 loe volumio[13215]: info: Starting Shairport Sync Mar 04 08:47:47 loe volumio[13215]: info: Loading plugin "last_100"... Mar 04 08:47:47 loe volumio[13215]: info: Loading plugin "webradio"... Mar 04 08:47:47 loe volumio[13215]: info: Loading plugin "i2s_dacs"... Mar 04 08:47:47 loe volumio[13215]: info: Loading plugin "volumiodiscovery"... Mar 04 08:47:47 loe volumio[13215]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Mar 04 08:47:47 loe volumio[13215]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 04 08:47:47 loe node[13215]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Mar 04 08:47:47 loe volumio[13215]: *** WARNING *** For more information see Mar 04 08:47:47 loe volumio[13215]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Mar 04 08:47:47 loe volumio[13215]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 04 08:47:47 loe volumio[13215]: *** WARNING *** For more information see Mar 04 08:47:47 loe node[13215]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 04 08:47:47 loe node[13215]: *** WARNING *** For more information see Mar 04 08:47:47 loe node[13215]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Mar 04 08:47:47 loe node[13215]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 04 08:47:47 loe node[13215]: *** WARNING *** For more information see Mar 04 08:47:47 loe volumio[13215]: info: Applying required configuration parameters for plugin volumiodiscovery Mar 04 08:47:47 loe volumio[13215]: info: Discovery: Started advertising with name: Loe Mar 04 08:47:47 loe volumio[13215]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 04 08:47:47 loe volumio[13215]: info: Loading plugin "spop"... Mar 04 08:47:48 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Mar 04 08:47:48 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Mar 04 08:47:48 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Mar 04 08:47:49 loe systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 28. Mar 04 08:47:49 loe systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 04 08:47:49 loe systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 04 08:47:49 loe go-librespot[13305]: go-librespot daemon starting... Mar 04 08:47:49 loe go-librespot[13306]: time="2026-03-04T08:47:49+01:00" level=info msg="running go-librespot 0.4.0" Mar 04 08:47:49 loe go-librespot[13306]: time="2026-03-04T08:47:49+01:00" level=debug msg="app state loaded" Mar 04 08:47:49 loe go-librespot[13306]: time="2026-03-04T08:47:49+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 04 08:47:49 loe volumio5-onboarding[2840]: time=2026-03-04T08:47:49.257+01:00 level=WARN msg="reconnection attempt failed" component=volumio/socket error="read tcp 127.0.0.1:36904->127.0.0.1:3000: i/o timeout" Mar 04 08:47:49 loe go-librespot[13306]: time="2026-03-04T08:47:49+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 04 08:47:49 loe go-librespot[13306]: time="2026-03-04T08:47:49+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 04 08:47:49 loe go-librespot[13306]: time="2026-03-04T08:47:49+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 04 08:47:49 loe go-librespot[13306]: time="2026-03-04T08:47:49+01:00" level=info msg="zeroconf server listening on port 34703" Mar 04 08:47:49 loe go-librespot[13306]: time="2026-03-04T08:47:49+01:00" level=debug msg="obtained new client token: AADweBp+B2Pf5r5ttu4H0BrAJZuCUbGramny817gp1TtF9Q8Um5B/YhpMJx/gTsfQalGRwGhY9BwK2IoDC70jI8h0qFrwkxeOmrt4soqiydeCNba5dO3TQocIxY3lRoZBovI9fikQ0QRZGuoXQezZgjksaGrYfWKmoGerXcul6T59mrfrTqOR181tJPUHMnibhwiWG+KcmYcFxtOayIBaxrzEgChvB1lz020StxiMXugTaI2ttId2w5zaw==" Mar 04 08:47:49 loe volumio[13215]: info: Loading plugin "outputs"... Mar 04 08:47:49 loe go-librespot[13306]: time="2026-03-04T08:47:49+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 04 08:47:49 loe volumio[13215]: info: Loading plugin "albumart"... Mar 04 08:47:49 loe go-librespot[13306]: time="2026-03-04T08:47:49+01:00" level=debug msg="completed keyexchange" Mar 04 08:47:49 loe go-librespot[13306]: time="2026-03-04T08:47:49+01:00" level=debug msg="completed challenge" Mar 04 08:47:49 loe volumio[13215]: info: Plugin example_plugin is not enabled Mar 04 08:47:49 loe volumio[13215]: info: Loading plugin "inputs"... Mar 04 08:47:49 loe volumio[13215]: info: Loading plugin "updater_comm"... Mar 04 08:47:49 loe go-librespot[13306]: time="2026-03-04T08:47:49+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 04 08:47:49 loe systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 04 08:47:49 loe systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 04 08:47:50 loe volumio[13215]: info: Plugin mpdemulation is not enabled Mar 04 08:47:50 loe volumio[13215]: info: Loading plugin "rest_api"... Mar 04 08:47:50 loe volumio[13215]: info: Loading plugin "websocket"... Mar 04 08:47:50 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Mar 04 08:47:50 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Mar 04 08:47:50 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Mar 04 08:47:50 loe volumio[13215]: info: Starting Socket.io Server version 1.7.4 Mar 04 08:47:50 loe volumio[13215]: info: Loading i18n strings for locale nl Mar 04 08:47:50 loe volumio[13215]: Updating browse sources language Mar 04 08:47:50 loe volumio[13215]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 04 08:47:50 loe volumio[13215]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 04 08:47:50 loe volumio[13215]: info: CoreCommandRouter::initPlayerControls Mar 04 08:47:50 loe volumio[13215]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 08:47:50 loe volumio[13215]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 08:47:50 loe volumio[13215]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 08:47:50 loe volumio[13215]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 08:47:50 loe volumio[13215]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 08:47:50 loe volumio[13215]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 08:47:50 loe volumio[13215]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 08:47:50 loe volumio[13215]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 08:47:50 loe volumio[13215]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 04 08:47:50 loe volumio[13215]: Express server listening on port 3000 Mar 04 08:47:50 loe volumio[13215]: [Metrics] WebUI: 11s 678.18ms Mar 04 08:47:50 loe volumio[13215]: info: CoreStateMachine::resetVolumioState Mar 04 08:47:50 loe volumio[13215]: info: CoreStateMachine::getcurrentVolume Mar 04 08:47:50 loe volumio[13215]: info: CoreCommandRouter::volumioRetrievevolume Mar 04 08:47:50 loe volumio[13215]: info: Volumio Network Manager: Network status updated: 1 Mar 04 08:47:50 loe volumio[13314]: Forking 3 albumart workers Mar 04 08:47:50 loe volumio[13215]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 08:47:50 loe volumio[13215]: info: Reloading queue from file Mar 04 08:47:51 loe volumio[13215]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 1 Mar 04 08:47:51 loe volumio[13215]: info: CoreStateMachine::setRepeat false single undefined Mar 04 08:47:51 loe volumio[13215]: info: CoreStateMachine::pushState Mar 04 08:47:51 loe volumio[13215]: info: CorePlayQueue::getTrack 0 Mar 04 08:47:51 loe volumio[13215]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 04 08:47:51 loe volumio[13215]: info: CoreCommandRouter::volumioPushState Mar 04 08:47:51 loe volumio[13215]: info: CoreStateMachine::setRandom undefined Mar 04 08:47:51 loe volumio[13215]: info: CoreStateMachine::pushState Mar 04 08:47:51 loe volumio[13215]: info: CorePlayQueue::getTrack 0 Mar 04 08:47:51 loe volumio[13215]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 04 08:47:51 loe volumio[13215]: info: CoreCommandRouter::volumioPushState Mar 04 08:47:51 loe volumio[13215]: info: Setting Device type: Raspberry PI Mar 04 08:47:51 loe volumio[13215]: info: Completed loading Core Plugins Mar 04 08:47:51 loe volumio[13215]: info: Preparing to generate the ALSA configuration file Mar 04 08:47:51 loe volumio[13215]: info: VolumeController:: Volume=5 Mute =false Mar 04 08:47:51 loe volumio[13215]: info: CoreStateMachine::pushState Mar 04 08:47:51 loe volumio[13215]: info: CorePlayQueue::getTrack 0 Mar 04 08:47:51 loe volumio[13215]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 04 08:47:51 loe volumio[13215]: info: CoreCommandRouter::volumioPushState Mar 04 08:47:51 loe volumio[13215]: info: CoreStateMachine::updateTrackBlock Mar 04 08:47:51 loe volumio[13215]: info: CorePlayQueue::getTrackBlock Mar 04 08:47:51 loe volumio[13215]: info: CoreCommandRouter::volumioRetrievevolume Mar 04 08:47:51 loe volumio[13215]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 1 Mar 04 08:47:51 loe volumio[13215]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 1 Mar 04 08:47:51 loe volumio[13215]: info: Asound.conf file unchanged, so no further update is needed Mar 04 08:47:51 loe volumio[13215]: info: Output device has changed, restarting MPD Mar 04 08:47:51 loe volumio[13215]: info: Output device has changed, restarting Shairport Sync Mar 04 08:47:51 loe volumio[13215]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 08:47:51 loe volumio[13215]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 08:47:51 loe volumio[13215]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 04 08:47:51 loe sudo[13368]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 04 08:47:51 loe volumio[13215]: info: ___________ START PLUGINS ___________ Mar 04 08:47:51 loe sudo[13368]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 08:47:51 loe sudo[13370]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 04 08:47:51 loe sudo[13368]: pam_unix(sudo:session): session closed for user root Mar 04 08:47:51 loe sudo[13370]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 08:47:51 loe volumio[13215]: info: ControllerMpd::onStart: Initializing MPD Mar 04 08:47:51 loe volumio[13215]: info: Creating MPD Configuration file Mar 04 08:47:51 loe volumio[13215]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 04 08:47:51 loe volumio[13215]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 04 08:47:51 loe volumio[13215]: info: [1772610471684] CoreMusicLibrary::Adding element Media Servers Mar 04 08:47:51 loe volumio[13215]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 04 08:47:51 loe volumio[13215]: info: UPNP Browser: Client initialized successfully Mar 04 08:47:51 loe sudo[13377]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumio5-onboarding.service Mar 04 08:47:51 loe sudo[13377]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 08:47:51 loe sudo[13382]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 04 08:47:51 loe sudo[13381]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 04 08:47:51 loe sudo[13382]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 08:47:51 loe sudo[13381]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 08:47:51 loe sudo[13381]: pam_unix(sudo:session): session closed for user root Mar 04 08:47:51 loe systemd[1]: Stopping mpd.service - Music Player Daemon... Mar 04 08:47:51 loe volumio[13215]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 08:47:51 loe volumio[13215]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 08:47:51 loe sudo[13377]: pam_unix(sudo:session): session closed for user root Mar 04 08:47:51 loe systemd[1]: mpd.service: Deactivated successfully. Mar 04 08:47:51 loe systemd[1]: Stopped mpd.service - Music Player Daemon. Mar 04 08:47:51 loe systemd[1]: mpd.service: Consumed 6.800s CPU time. Mar 04 08:47:51 loe systemd[1]: mpd.socket: Deactivated successfully. Mar 04 08:47:51 loe systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Mar 04 08:47:51 loe volumio[13215]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 04 08:47:51 loe volumio[13215]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 08:47:51 loe volumio[13215]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 08:47:51 loe systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Mar 04 08:47:52 loe volumio[13215]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 04 08:47:52 loe volumio[13215]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 04 08:47:52 loe volumio[13215]: info: [1772610472044] CoreMusicLibrary::Adding element Last_100 Mar 04 08:47:52 loe volumio[13215]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 04 08:47:52 loe volumio[13215]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 04 08:47:52 loe volumio[13215]: info: [1772610472063] CoreMusicLibrary::Adding element Webradio Mar 04 08:47:52 loe volumio[13215]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 04 08:47:52 loe volumio[13215]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 04 08:47:52 loe volumio[13215]: info: Initializing BBC Radios Mar 04 08:47:52 loe systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Mar 04 08:47:52 loe systemd[1]: Starting mpd.service - Music Player Daemon... Mar 04 08:47:52 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Mar 04 08:47:52 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Mar 04 08:47:52 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Mar 04 08:47:52 loe volumio[13215]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 04 08:47:52 loe volumio[13215]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 08:47:52 loe volumio[13215]: info: Creating Spotify config file Mar 04 08:47:52 loe volumio[13215]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 08:47:52 loe sudo[13398]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Mar 04 08:47:52 loe sudo[13398]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Mar 04 08:47:52 loe sudo[13398]: pam_unix(sudo:session): session closed for user root Mar 04 08:47:53 loe systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 29. Mar 04 08:47:53 loe systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 04 08:47:53 loe systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 04 08:47:53 loe go-librespot[13411]: go-librespot daemon starting... Mar 04 08:47:53 loe go-librespot[13412]: time="2026-03-04T08:47:53+01:00" level=info msg="running go-librespot 0.4.0" Mar 04 08:47:53 loe volumio[13215]: info: Volumio Calling Home Mar 04 08:47:53 loe volumio-remote-updater[714]: [2026-03-04 08:47:53] [connect] Successful connection Mar 04 08:47:53 loe go-librespot[13412]: time="2026-03-04T08:47:53+01:00" level=info msg="zeroconf server listening on port 40583" Mar 04 08:47:54 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Mar 04 08:47:54 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Mar 04 08:47:54 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Mar 04 08:47:54 loe volumio[13329]: Starting albumart workers Mar 04 08:47:54 loe volumio[13215]: info: Discovery: adding 07fbb113-343c-4b34-af49-444dc3d8fb26 Mar 04 08:47:54 loe volumio[13215]: info: Discovery: Found device Loe Mar 04 08:47:54 loe volumio[13215]: info: CoreCommandRouter::volumioGetState Mar 04 08:47:54 loe volumio[13215]: info: CorePlayQueue::getTrack 0 Mar 04 08:47:54 loe volumio[13332]: Starting albumart workers Mar 04 08:47:54 loe volumio[13215]: info: VolumeController:: Volume=5 Mute =false Mar 04 08:47:54 loe volumio[13215]: info: CoreStateMachine::pushState Mar 04 08:47:54 loe volumio[13215]: info: CorePlayQueue::getTrack 0 Mar 04 08:47:54 loe volumio[13215]: info: CoreCommandRouter::volumioPushState Mar 04 08:47:54 loe volumio[13215]: info: Discovery: this is already registered, 07fbb113-343c-4b34-af49-444dc3d8fb26 Mar 04 08:47:54 loe volumio[13215]: info: Discovery: Found device Loe Mar 04 08:47:54 loe volumio[13215]: info: CoreCommandRouter::volumioGetState Mar 04 08:47:54 loe volumio[13215]: info: CorePlayQueue::getTrack 0 Mar 04 08:47:54 loe volumio5-onboarding[2840]: time=2026-03-04T08:47:54.606+01:00 level=ERROR msg="failed to update discovery on Wi-Fi info change" error="failed to get system info: could not get system info: context deadline exceeded" Mar 04 08:47:54 loe sudo[13437]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 04 08:47:54 loe sudo[13437]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 08:47:54 loe sudo[13439]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 04 08:47:54 loe sudo[13439]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 08:47:54 loe sudo[13439]: pam_unix(sudo:session): session closed for user root Mar 04 08:47:54 loe volumio[13334]: Starting albumart workers Mar 04 08:47:54 loe sudo[13437]: pam_unix(sudo:session): session closed for user root Mar 04 08:47:54 loe volumio[13215]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 1 Mar 04 08:47:54 loe volumio[13215]: info: MPD Permissions set Mar 04 08:47:54 loe volumio[13215]: info: MPD Permissions set Mar 04 08:47:55 loe volumio-remote-updater[714]: [2026-03-04 08:47:55] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1772610473 101 Mar 04 08:47:55 loe volumio[13215]: 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 Mar 04 08:47:55 loe volumio[13215]: info: Volumio called home Mar 04 08:47:55 loe volumio[13215]: info: Spotify config file written Mar 04 08:47:55 loe sudo[13443]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Mar 04 08:47:55 loe sudo[13443]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 08:47:55 loe systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Mar 04 08:47:55 loe systemd[1]: go-librespot-daemon.service: Deactivated successfully. Mar 04 08:47:55 loe systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 04 08:47:55 loe systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 04 08:47:55 loe go-librespot[13445]: go-librespot daemon starting... Mar 04 08:47:55 loe sudo[13443]: pam_unix(sudo:session): session closed for user root Mar 04 08:47:55 loe volumio[13215]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Mar 04 08:47:55 loe go-librespot[13446]: time="2026-03-04T08:47:55+01:00" level=info msg="running go-librespot 0.4.0" Mar 04 08:47:55 loe go-librespot[13446]: time="2026-03-04T08:47:55+01:00" level=debug msg="app state loaded" Mar 04 08:47:55 loe volumio[13215]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 08:47:55 loe volumio[13215]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 08:47:55 loe volumio[13215]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 08:47:55 loe volumio[13215]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 08:47:55 loe volumio[13215]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 08:47:55 loe volumio[13215]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 08:47:55 loe volumio[13215]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 08:47:55 loe go-librespot[13446]: time="2026-03-04T08:47:55+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 04 08:47:55 loe volumio[13215]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 08:47:55 loe volumio[13215]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 08:47:55 loe volumio[13215]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 08:47:55 loe volumio[13215]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 08:47:55 loe volumio[13215]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 08:47:55 loe volumio[13215]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 08:47:55 loe volumio[13215]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 08:47:55 loe volumio[13215]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 08:47:55 loe volumio[13215]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 08:47:55 loe volumio[13215]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 08:47:55 loe volumio[13215]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 08:47:55 loe volumio[13215]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 08:47:55 loe volumio[13215]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 08:47:55 loe volumio[13215]: info: No need to fix Spotify hosts Mar 04 08:47:56 loe go-librespot[13446]: time="2026-03-04T08:47:56+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 04 08:47:56 loe go-librespot[13446]: time="2026-03-04T08:47:56+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 04 08:47:56 loe go-librespot[13446]: time="2026-03-04T08:47:56+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 04 08:47:56 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Mar 04 08:47:56 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Mar 04 08:47:56 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Mar 04 08:47:56 loe go-librespot[13446]: time="2026-03-04T08:47:56+01:00" level=info msg="zeroconf server listening on port 40833" Mar 04 08:47:56 loe volumio[13215]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 3 Mar 04 08:47:56 loe go-librespot[13446]: time="2026-03-04T08:47:56+01:00" level=debug msg="obtained new client token: AAAsML7iA/cPcIahznqu43ttrS2csnZb0c7lu3CAnbWurRGXNv102vtzTna9FPJXO86eewSmT0wrsdC7zse9FamZNJISeMiUPJYwZAlkaS3b/dC/88hONS2fuluHLtIfz5HJhiM8lmpZ44kdF++hhAt3kBvMzEmeQwxm/hwQHJuGJwMefnYeBLeuslDk7ceVyRg/mvbXbseL+xsJ34wq2LC+o/aIGdvgWXn1jZl7erHj2yVydBeVVNBTOw==" Mar 04 08:47:56 loe volumio[13215]: info: An error occurred while refreshing Spotify Token Error: Bad Request Mar 04 08:47:56 loe volumio[13215]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 3 Mar 04 08:47:56 loe go-librespot[13446]: time="2026-03-04T08:47:56+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 04 08:47:56 loe volumio[13215]: info: Starting Shairport Sync Mar 04 08:47:56 loe volumio[13215]: info: Starting Shairport Sync Mar 04 08:47:56 loe go-librespot[13446]: time="2026-03-04T08:47:56+01:00" level=debug msg="completed keyexchange" Mar 04 08:47:56 loe volumio[13215]: info: Starting Shairport Sync Mar 04 08:47:56 loe go-librespot[13446]: time="2026-03-04T08:47:56+01:00" level=debug msg="completed challenge" Mar 04 08:47:56 loe go-librespot[13446]: time="2026-03-04T08:47:56+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 04 08:47:56 loe systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 04 08:47:56 loe systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 04 08:47:56 loe sudo[13478]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 04 08:47:56 loe sudo[13476]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 04 08:47:56 loe sudo[13476]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 08:47:56 loe sudo[13478]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 08:47:56 loe sudo[13482]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Mar 04 08:47:56 loe sudo[13482]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 08:47:56 loe sudo[13480]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 04 08:47:56 loe sudo[13480]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 08:47:56 loe volumio[13215]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 3 Mar 04 08:47:56 loe volumio[13215]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 3 Mar 04 08:47:56 loe systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Mar 04 08:47:56 loe sudo[13482]: pam_unix(sudo:session): session closed for user root Mar 04 08:47:57 loe systemd[1]: shairport-sync.service: Deactivated successfully. Mar 04 08:47:57 loe systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 04 08:47:57 loe systemd[1]: shairport-sync.service: Consumed 2.160s CPU time. Mar 04 08:47:57 loe volumio[13215]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 3 Mar 04 08:47:57 loe volumio[13215]: info: CoreCommandRouter::volumioGetState Mar 04 08:47:57 loe volumio[13215]: info: CorePlayQueue::getTrack 0 Mar 04 08:47:57 loe volumio[13215]: info: Upmpdcli Daemon Started Mar 04 08:47:57 loe systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 04 08:47:57 loe sudo[13476]: pam_unix(sudo:session): session closed for user root Mar 04 08:47:57 loe sudo[13478]: pam_unix(sudo:session): session closed for user root Mar 04 08:47:57 loe volumio[13215]: info: Shairport-Sync Started Mar 04 08:47:57 loe volumio[13215]: Error adding Membership: Error: addMembership EINVAL Mar 04 08:47:57 loe sudo[13480]: pam_unix(sudo:session): session closed for user root Mar 04 08:47:57 loe volumio[13215]: info: Shairport-Sync Started Mar 04 08:47:57 loe volumio[13215]: info: Shairport-Sync Started Mar 04 08:47:58 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Mar 04 08:47:58 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Mar 04 08:47:58 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Mar 04 08:47:59 loe mpd[13410]: 2026-03-04T08:47:59 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Mar 04 08:47:59 loe systemd[1]: Started mpd.service - Music Player Daemon. Mar 04 08:47:59 loe sudo[13370]: pam_unix(sudo:session): session closed for user root Mar 04 08:47:59 loe sudo[13382]: pam_unix(sudo:session): session closed for user root Mar 04 08:47:59 loe volumio[13215]: info: Completed starting Core Plugins Mar 04 08:47:59 loe volumio[13215]: info: ------------------------------------------- Mar 04 08:47:59 loe volumio[13215]: info: ----- MyVolumio plugins startup ---- Mar 04 08:47:59 loe volumio[13215]: info: ------------------------------------------- Mar 04 08:47:59 loe volumio[13215]: info: [MyVolumio PluginManager] Fetching plans data.... Mar 04 08:47:59 loe volumio[13215]: error: MPD error: The expression evaluated to a falsy value: Mar 04 08:47:59 loe volumio[13215]: assert.ok(self.idling) Mar 04 08:47:59 loe volumio[13215]: error: The expression evaluated to a falsy value: Mar 04 08:47:59 loe volumio[13215]: assert.ok(self.idling) Mar 04 08:47:59 loe volumio[13215]: info: go-librespot daemon successfully initialized Mar 04 08:47:59 loe volumio[13215]: info: MPD running with PID13410 Mar 04 08:47:59 loe volumio[13215]: ,establishing connection Mar 04 08:47:59 loe volumio[13215]: error: updateQueue error: null Mar 04 08:47:59 loe volumio[13215]: error: updateQueue error: null Mar 04 08:47:59 loe systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Mar 04 08:47:59 loe systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 04 08:47:59 loe systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 04 08:47:59 loe go-librespot[13513]: go-librespot daemon starting... Mar 04 08:47:59 loe go-librespot[13514]: time="2026-03-04T08:47:59+01:00" level=info msg="running go-librespot 0.4.0" Mar 04 08:47:59 loe go-librespot[13514]: time="2026-03-04T08:47:59+01:00" level=debug msg="app state loaded" Mar 04 08:47:59 loe go-librespot[13514]: time="2026-03-04T08:47:59+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 04 08:48:00 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Mar 04 08:48:00 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Mar 04 08:48:00 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Mar 04 08:48:00 loe go-librespot[13514]: time="2026-03-04T08:48:00+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Mar 04 08:48:00 loe go-librespot[13514]: time="2026-03-04T08:48:00+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Mar 04 08:48:00 loe go-librespot[13514]: time="2026-03-04T08:48:00+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Mar 04 08:48:00 loe go-librespot[13514]: time="2026-03-04T08:48:00+01:00" level=info msg="zeroconf server listening on port 33185" Mar 04 08:48:00 loe go-librespot[13514]: time="2026-03-04T08:48:00+01:00" level=debug msg="obtained new client token: AABHMpGRxHLn7F0DGeGLGPNuR1yU9yrDswDGJtC7HjnICVcfwodQW+IICj27memma7rRcL66tRQC7Gpiwu4555K8UxGHxCM+6FtM0LD6Np7ghLJYMlTIsFYiYFTyOs3Lj7X+d5B9wbXjVtNAMUk2vSoLGBnLKKkMaBZsVG6SvlnnaVUTaX8n+aH4CPZihTee4RQyjNdG1u5oca6FJShc67JvXc8bWdla6Tl/C0c3aBTzhuPjDzrcZppkZA==" Mar 04 08:48:00 loe go-librespot[13514]: time="2026-03-04T08:48:00+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 04 08:48:00 loe go-librespot[13514]: time="2026-03-04T08:48:00+01:00" level=debug msg="completed keyexchange" Mar 04 08:48:00 loe go-librespot[13514]: time="2026-03-04T08:48:00+01:00" level=debug msg="completed challenge" Mar 04 08:48:00 loe go-librespot[13514]: time="2026-03-04T08:48:00+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 04 08:48:00 loe systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 04 08:48:00 loe systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 04 08:48:02 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Mar 04 08:48:02 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Mar 04 08:48:02 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Mar 04 08:48:02 loe volumio[13215]: info: Initializing connection to go-librespot Websocket Mar 04 08:48:02 loe volumio[13215]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 04 08:48:03 loe systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Mar 04 08:48:03 loe systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 04 08:48:03 loe systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 04 08:48:03 loe go-librespot[13535]: go-librespot daemon starting... Mar 04 08:48:03 loe go-librespot[13537]: time="2026-03-04T08:48:03+01:00" level=info msg="running go-librespot 0.4.0" Mar 04 08:48:03 loe go-librespot[13537]: time="2026-03-04T08:48:03+01:00" level=debug msg="app state loaded" Mar 04 08:48:03 loe go-librespot[13537]: time="2026-03-04T08:48:03+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 04 08:48:04 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Mar 04 08:48:04 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Mar 04 08:48:04 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Mar 04 08:48:04 loe go-librespot[13537]: time="2026-03-04T08:48:04+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Mar 04 08:48:04 loe go-librespot[13537]: time="2026-03-04T08:48:04+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Mar 04 08:48:04 loe go-librespot[13537]: time="2026-03-04T08:48:04+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Mar 04 08:48:04 loe go-librespot[13537]: time="2026-03-04T08:48:04+01:00" level=info msg="zeroconf server listening on port 45097" Mar 04 08:48:04 loe volumio[13215]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Mar 04 08:48:04 loe go-librespot[13537]: time="2026-03-04T08:48:04+01:00" level=debug msg="obtained new client token: AAA/jQ2tVqZFFbCRiyUBgfwc/58Acd9riHPJGy16L3NR0YgpO2Zmmd2w9lc0kFxzVV9khG5n45bIHyXwl5xZFUc4RvntI1aV7B7j7CBfxFNWv6VEhcYk0ymDpqhZxMg8gxEwEJ52Zr+k+CUCgbpHJnonRzxYMnGIKEnENQFqT3OttL6PSV0ZPzbdukRmta5/kN6VRJvDamzr+SqqqepbUXm6MUJiws2o5rngB8/CHvimzMejRNlO16gAjA==" Mar 04 08:48:04 loe go-librespot[13537]: time="2026-03-04T08:48:04+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 04 08:48:04 loe go-librespot[13537]: time="2026-03-04T08:48:04+01:00" level=debug msg="completed keyexchange" Mar 04 08:48:04 loe go-librespot[13537]: time="2026-03-04T08:48:04+01:00" level=debug msg="completed challenge" Mar 04 08:48:04 loe go-librespot[13537]: time="2026-03-04T08:48:04+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 04 08:48:04 loe systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 04 08:48:04 loe systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 04 08:48:05 loe volumio[13215]: info: Initializing connection to go-librespot Websocket Mar 04 08:48:05 loe volumio[13215]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 04 08:48:06 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Mar 04 08:48:06 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Mar 04 08:48:06 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Mar 04 08:48:07 loe volumio[13215]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Mar 04 08:48:07 loe volumio[13215]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Mar 04 08:48:07 loe volumio[13215]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Mar 04 08:48:07 loe volumio[13215]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Mar 04 08:48:07 loe volumio[13215]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Mar 04 08:48:07 loe volumio[13215]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Mar 04 08:48:07 loe volumio[13215]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Mar 04 08:48:07 loe volumio[13215]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Mar 04 08:48:07 loe volumio[13215]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Mar 04 08:48:07 loe volumio[13215]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Mar 04 08:48:07 loe volumio[13215]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Mar 04 08:48:07 loe volumio[13215]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Mar 04 08:48:07 loe volumio[13215]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Mar 04 08:48:07 loe volumio[13215]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Mar 04 08:48:07 loe volumio[13215]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Mar 04 08:48:07 loe volumio[13215]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Mar 04 08:48:07 loe volumio[13215]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Mar 04 08:48:07 loe volumio[13215]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Mar 04 08:48:07 loe volumio[13215]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Mar 04 08:48:07 loe volumio[13215]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Mar 04 08:48:07 loe volumio[13215]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Mar 04 08:48:07 loe volumio[13215]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Mar 04 08:48:07 loe volumio[13215]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Mar 04 08:48:07 loe volumio[13215]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Mar 04 08:48:07 loe volumio[13215]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Mar 04 08:48:07 loe volumio[13215]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Mar 04 08:48:07 loe volumio[13215]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Mar 04 08:48:07 loe volumio[13215]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Mar 04 08:48:07 loe volumio[13215]: info: Adding plugin bluetooth to MyMusic Plugins Mar 04 08:48:07 loe volumio[13215]: info: Adding plugin multiroom to MyMusic Plugins Mar 04 08:48:07 loe volumio[13215]: info: Adding plugin metavolumio to MyMusic Plugins Mar 04 08:48:07 loe volumio[13215]: info: Adding plugin cd_controller to MyMusic Plugins Mar 04 08:48:07 loe volumio[13215]: info: Adding plugin qobuzconnect to MyMusic Plugins Mar 04 08:48:07 loe volumio[13215]: info: Adding plugin smart_inputs to MyMusic Plugins Mar 04 08:48:07 loe volumio[13215]: info: Adding plugin tidalconnect to MyMusic Plugins Mar 04 08:48:07 loe volumio[13215]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Mar 04 08:48:07 loe systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Mar 04 08:48:07 loe systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 04 08:48:07 loe systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 04 08:48:07 loe go-librespot[13544]: go-librespot daemon starting... Mar 04 08:48:07 loe go-librespot[13545]: time="2026-03-04T08:48:07+01:00" level=info msg="running go-librespot 0.4.0" Mar 04 08:48:07 loe go-librespot[13545]: time="2026-03-04T08:48:07+01:00" level=debug msg="app state loaded" Mar 04 08:48:07 loe go-librespot[13545]: time="2026-03-04T08:48:07+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 04 08:48:08 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Mar 04 08:48:08 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Mar 04 08:48:08 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Mar 04 08:48:08 loe go-librespot[13545]: time="2026-03-04T08:48:08+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 04 08:48:08 loe go-librespot[13545]: time="2026-03-04T08:48:08+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 04 08:48:08 loe go-librespot[13545]: time="2026-03-04T08:48:08+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 04 08:48:08 loe go-librespot[13545]: time="2026-03-04T08:48:08+01:00" level=info msg="zeroconf server listening on port 43395" Mar 04 08:48:08 loe go-librespot[13545]: time="2026-03-04T08:48:08+01:00" level=debug msg="obtained new client token: AABetq0FgLgcgSf7MzVD+zNGOw7cE/f6SQSmIDCQ0vJwb7AEnFohdq3Zqwnt5hH42EwCYpiEscIzSkJbHM/FVzP0lYuePmE1+stjhZ8fysjEakc+VL6GNQVX5ayCiMdE3iT9iAl/G4sNk8LsGS5cGtx6jSPdxmR31ChEsoeOaabP+DYaJuMIlfU1zBv2YR/WRuqFNB5nV+UHyvNFBZcUW9RisYZXdzeSd7RSS/0m+iBOYseeL+Ol6kKAGQ==" Mar 04 08:48:08 loe go-librespot[13545]: time="2026-03-04T08:48:08+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 04 08:48:08 loe go-librespot[13545]: time="2026-03-04T08:48:08+01:00" level=debug msg="completed keyexchange" Mar 04 08:48:08 loe go-librespot[13545]: time="2026-03-04T08:48:08+01:00" level=debug msg="completed challenge" Mar 04 08:48:08 loe go-librespot[13545]: time="2026-03-04T08:48:08+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 04 08:48:08 loe systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 04 08:48:08 loe systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 04 08:48:09 loe volumio[13215]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Mar 04 08:48:09 loe volumio[13215]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Mar 04 08:48:09 loe volumio[13215]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 08:48:09 loe volumio[13215]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 08:48:09 loe volumio[13215]: info: Starting MyVolumio Remote Streaming Endpoints Mar 04 08:48:09 loe volumio[13215]: info: MyVolumio login type: Token Mar 04 08:48:09 loe volumio[13215]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Mar 04 08:48:09 loe volumio[13215]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Mar 04 08:48:10 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Mar 04 08:48:10 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Mar 04 08:48:10 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Mar 04 08:48:11 loe volumio[13215]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Mar 04 08:48:11 loe volumio[13215]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Mar 04 08:48:11 loe volumio[13215]: info: Streaming services startup Mar 04 08:48:11 loe volumio[13215]: info: Starting Streaming Daemon Mar 04 08:48:11 loe sudo[13554]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Mar 04 08:48:11 loe volumio[13215]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Mar 04 08:48:11 loe sudo[13554]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 08:48:11 loe sudo[13554]: pam_unix(sudo:session): session closed for user root Mar 04 08:48:11 loe volumio[13215]: info: Initializing connection to go-librespot Websocket Mar 04 08:48:11 loe volumio[13215]: error: Cannot start Volumio Streaming Daemon Mar 04 08:48:11 loe volumio[13215]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Mar 04 08:48:11 loe volumio[13215]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Mar 04 08:48:11 loe volumio[13215]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 04 08:48:11 loe systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Mar 04 08:48:11 loe systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 04 08:48:11 loe systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 04 08:48:11 loe go-librespot[13561]: go-librespot daemon starting... Mar 04 08:48:11 loe go-librespot[13562]: time="2026-03-04T08:48:11+01:00" level=info msg="running go-librespot 0.4.0" Mar 04 08:48:11 loe go-librespot[13562]: time="2026-03-04T08:48:11+01:00" level=debug msg="app state loaded" Mar 04 08:48:11 loe go-librespot[13562]: time="2026-03-04T08:48:11+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 04 08:48:12 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Mar 04 08:48:12 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Mar 04 08:48:12 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Mar 04 08:48:12 loe go-librespot[13562]: time="2026-03-04T08:48:12+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 04 08:48:12 loe go-librespot[13562]: time="2026-03-04T08:48:12+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 04 08:48:12 loe go-librespot[13562]: time="2026-03-04T08:48:12+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 04 08:48:12 loe go-librespot[13562]: time="2026-03-04T08:48:12+01:00" level=info msg="zeroconf server listening on port 37719" Mar 04 08:48:12 loe volumio[13215]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Mar 04 08:48:12 loe go-librespot[13562]: time="2026-03-04T08:48:12+01:00" level=debug msg="obtained new client token: AACWPYTlJDTkM3G0g8ftqYhOjb3e8e3Y55lSV4RivmBanS3BzDk+2/8SQraXvUtRygYxDvYCF2pr/5V0Zvki1/Kjrcsp2p5i3Ee4WMstYl/YCU4XepEgiAHl+h30V3728KLC3gV/ViV7nAqJJRd6XYwPQk9rOolypji2w6GJ2piriP9gnxeIv5SiEw8Rf4ao1lapLGaWIHDvcIOf6SetOfUpsR5HuuwLuC2aWWG5gjK7wwEjvQwVC63nxw==" Mar 04 08:48:12 loe go-librespot[13562]: time="2026-03-04T08:48:12+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 04 08:48:12 loe go-librespot[13562]: time="2026-03-04T08:48:12+01:00" level=debug msg="completed keyexchange" Mar 04 08:48:12 loe go-librespot[13562]: time="2026-03-04T08:48:12+01:00" level=debug msg="completed challenge" Mar 04 08:48:12 loe go-librespot[13562]: time="2026-03-04T08:48:12+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 04 08:48:12 loe systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 04 08:48:12 loe systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 04 08:48:12 loe volumio[13215]: info: MyVolumio token set successfully Mar 04 08:48:12 loe volumio[13215]: info: MYVOLUMIO: Adding device Mar 04 08:48:12 loe volumio[13215]: info: MYVOLUMIO: Evaluating Server Mar 04 08:48:13 loe volumio[13215]: info: MyVolumio Plan changed: premium Mar 04 08:48:13 loe volumio[13215]: info: [MyVolumio PluginManager] Subscribed plan changed to premium Mar 04 08:48:13 loe volumio[13215]: info: Removing browser output: myVolumio user plan is not superstar Mar 04 08:48:13 loe volumio[13215]: info: Removing audio output: Mar 04 08:48:13 loe volumio[13215]: info: MYVOLUMIO: Adding device Mar 04 08:48:13 loe volumio[13215]: info: MYVOLUMIO: Evaluating Server Mar 04 08:48:13 loe volumio[13215]: info: Remote config written successfully Mar 04 08:48:13 loe volumio[13215]: info: Starting Tunnel 1 Mar 04 08:48:13 loe volumio[13215]: info: Starting Tunnel Connection Checker Mar 04 08:48:13 loe volumio[13215]: info: Completed starting MyVolumio Plugin Mar 04 08:48:13 loe volumio[13215]: info: MYVolumio Device enabled Mar 04 08:48:13 loe volumio[13215]: info: [MyVolumio PluginManager] Device activated, enabling myvolumio plugins... Mar 04 08:48:13 loe volumio[13215]: info: MyVolumio status changed Mar 04 08:48:13 loe volumio[13215]: info: Streaming services startup Mar 04 08:48:13 loe volumio[13215]: info: Starting Streaming Daemon Mar 04 08:48:13 loe volumio[13215]: info: Setting Geolocation for MyVolumio to eu8 Mar 04 08:48:13 loe sudo[13609]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Mar 04 08:48:13 loe volumio[13215]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 08:48:13 loe volumio[13215]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 08:48:13 loe volumio[13215]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 08:48:13 loe sudo[13609]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 08:48:13 loe volumio[13215]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getHwuuid Mar 04 08:48:13 loe volumio[13215]: info: [MyVolumio PluginManager] Loading plugin "bluetooth"... Mar 04 08:48:13 loe sudo[13609]: pam_unix(sudo:session): session closed for user root Mar 04 08:48:14 loe volumio[13215]: ------------------------------------ BT MESSAGE: [FUNC] onVolumioStart Mar 04 08:48:14 loe volumio[13215]: info: [MyVolumio PluginManager] Loading plugin "multiroom"... Mar 04 08:48:14 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Mar 04 08:48:14 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Mar 04 08:48:14 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Mar 04 08:48:15 loe systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Mar 04 08:48:15 loe systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 04 08:48:15 loe systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 04 08:48:15 loe go-librespot[13625]: go-librespot daemon starting... Mar 04 08:48:15 loe go-librespot[13626]: time="2026-03-04T08:48:15+01:00" level=info msg="running go-librespot 0.4.0" Mar 04 08:48:15 loe go-librespot[13626]: time="2026-03-04T08:48:15+01:00" level=debug msg="app state loaded" Mar 04 08:48:15 loe go-librespot[13626]: time="2026-03-04T08:48:15+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 04 08:48:16 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Mar 04 08:48:16 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Mar 04 08:48:16 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Mar 04 08:48:16 loe go-librespot[13626]: time="2026-03-04T08:48:16+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 04 08:48:16 loe go-librespot[13626]: time="2026-03-04T08:48:16+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 04 08:48:16 loe go-librespot[13626]: time="2026-03-04T08:48:16+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 04 08:48:16 loe go-librespot[13626]: time="2026-03-04T08:48:16+01:00" level=info msg="zeroconf server listening on port 34557" Mar 04 08:48:16 loe go-librespot[13626]: time="2026-03-04T08:48:16+01:00" level=debug msg="obtained new client token: AADJSQ+rkIumChseQ4cV1WKxGwGwvQhbWdxuIMyqI0FTJOKDkBNmj15LA4mubQUuPzH/LFqvNqgItnIo3VVPMNoPQkNBrWUiw7Q7dHuOEzLR3yt4CJVHHNPoz2GrtrU/Ahk2Ye2YwvCtRcF6O/gRg1FZKZgvvp2NMjuhV1gj5lXG32vjwd6tjgzKVUxy5UrapfTujYMfqaZWN4bs2lH+a7keKRll/Tx0aBWfxX6Ox2Db4HqBPzq+QxMNRw==" Mar 04 08:48:16 loe volumio[13215]: info: [MyVolumio PluginManager] Applying required configuration parameters for plugin multiroom Mar 04 08:48:16 loe go-librespot[13626]: time="2026-03-04T08:48:16+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 04 08:48:16 loe sudo[13635]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/rm -rf /tmp/multiroom Mar 04 08:48:16 loe sudo[13635]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 08:48:16 loe sudo[13635]: pam_unix(sudo:session): session closed for user root Mar 04 08:48:16 loe go-librespot[13626]: time="2026-03-04T08:48:16+01:00" level=debug msg="completed keyexchange" Mar 04 08:48:16 loe go-librespot[13626]: time="2026-03-04T08:48:16+01:00" level=debug msg="completed challenge" Mar 04 08:48:16 loe volumio[13215]: /usr/bin/mkdir: cannot create directory ‘/tmp/hls’: File exists Mar 04 08:48:16 loe go-librespot[13626]: time="2026-03-04T08:48:16+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 04 08:48:16 loe systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 04 08:48:16 loe systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 04 08:48:16 loe volumio[13215]: info: MRS: MultiRoom plugin initialized Mar 04 08:48:16 loe volumio[13215]: info: MRS: STOPPING SNAPCLIENT Mar 04 08:48:16 loe volumio[13215]: info: MRS: Snap server stop Mar 04 08:48:16 loe volumio[13215]: info: MRS: STOPPING volumioStreaming Mar 04 08:48:16 loe sudo[13652]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioSnapclient Mar 04 08:48:16 loe sudo[13652]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 08:48:16 loe volumio[13215]: info: [MyVolumio PluginManager] Loading plugin "metavolumio"... Mar 04 08:48:16 loe sudo[13654]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioSnapserver Mar 04 08:48:16 loe sudo[13654]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 08:48:16 loe sudo[13656]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioStreaming Mar 04 08:48:16 loe sudo[13656]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 08:48:16 loe volumio[13215]: info: [MyVolumio PluginManager] Loading plugin "manifestui"... Mar 04 08:48:16 loe sudo[13659]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/rm -f /tmp/hls/* Mar 04 08:48:16 loe sudo[13659]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 08:48:16 loe volumio[13215]: info: [MyVolumio PluginManager] Loading plugin "cd_controller"... Mar 04 08:48:16 loe sudo[13659]: pam_unix(sudo:session): session closed for user root Mar 04 08:48:16 loe volumio[13215]: info: [MyVolumio PluginManager] Loading plugin "smart_inputs"... Mar 04 08:48:16 loe volumio[13215]: info: [MyVolumio PluginManager] Loading plugin "hi_res_audio"... Mar 04 08:48:16 loe volumio[13215]: info: [MyVolumio PluginManager] Applying required configuration parameters for plugin hi_res_audio Mar 04 08:48:16 loe volumio[13215]: info: [MyVolumio PluginManager] Loading plugin "tidal"... Mar 04 08:48:17 loe volumio[13215]: info: [MyVolumio PluginManager] Loading plugin "qobuz"... Mar 04 08:48:17 loe volumio[13215]: info: [MyVolumio PluginManager] Loading plugin "tidalconnect"... Mar 04 08:48:17 loe sudo[13652]: pam_unix(sudo:session): session closed for user root Mar 04 08:48:17 loe volumio[13215]: info: [MyVolumio PluginManager] Loading plugin "qobuzconnect"... Mar 04 08:48:17 loe sudo[13654]: pam_unix(sudo:session): session closed for user root Mar 04 08:48:17 loe sudo[13656]: pam_unix(sudo:session): session closed for user root Mar 04 08:48:17 loe volumio[13215]: info: Preparing to generate the ALSA configuration file Mar 04 08:48:17 loe volumio[13215]: info: Initializing connection to go-librespot Websocket Mar 04 08:48:17 loe volumio[13215]: info: Updating MyVolumio device info Mar 04 08:48:17 loe volumio[13215]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 08:48:17 loe volumio[13215]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 08:48:17 loe volumio[13215]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 08:48:17 loe volumio[13215]: info: Setting Geolocation for MyVolumio to eu12 Mar 04 08:48:17 loe volumio[13215]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 08:48:17 loe volumio[13215]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 08:48:17 loe volumio[13215]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 08:48:17 loe volumio[13215]: info: Successfully Added MyVolumio device Mar 04 08:48:17 loe volumio[13215]: info: The plugin multiroom has an ALSA contribution file volumioMultiRoomServer.postMultiRoom.1000.conf Mar 04 08:48:17 loe volumio[13215]: info: Reading ALSA contributions from plugins. Mar 04 08:48:17 loe volumio[13215]: info: MRS: Removed streaming files Mar 04 08:48:17 loe volumio[13215]: info: MRS: volumioStreaming STOPPED Mar 04 08:48:17 loe volumio[13215]: info: MRS: SNAPSERVER STOPPED Mar 04 08:48:17 loe volumio[13215]: info: MRS: SNAPCLIENT STOPPED Mar 04 08:48:17 loe volumio[13215]: error: Cannot start Volumio Streaming Daemon Mar 04 08:48:17 loe volumio[13215]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Mar 04 08:48:17 loe volumio[13215]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Mar 04 08:48:17 loe volumio[13215]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 04 08:48:17 loe volumio[13215]: info: Asound.conf file written Mar 04 08:48:17 loe sudo[13667]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf Mar 04 08:48:17 loe sudo[13667]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 08:48:17 loe sudo[13667]: pam_unix(sudo:session): session closed for user root Mar 04 08:48:17 loe volumio[13215]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:0 use case configuration -2 Mar 04 08:48:17 loe volumio[13215]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:1 use case configuration -2 Mar 04 08:48:17 loe volumio[13215]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:2 use case configuration -2 Mar 04 08:48:17 loe volumio[13215]: No state is present for card vc4hdmi Mar 04 08:48:17 loe volumio[13215]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:2 use case configuration -2 Mar 04 08:48:17 loe volumio[13215]: Found hardware: "vc4-hdmi" "" "" "" "" Mar 04 08:48:17 loe volumio[13215]: Hardware is initialized using a generic method Mar 04 08:48:17 loe volumio[13215]: No state is present for card vc4hdmi Mar 04 08:48:17 loe volumio[13215]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:3 use case configuration -2 Mar 04 08:48:17 loe volumio[13215]: info: Output device has changed, restarting MPD Mar 04 08:48:17 loe sudo[13673]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 04 08:48:17 loe sudo[13673]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 08:48:17 loe sudo[13673]: pam_unix(sudo:session): session closed for user root Mar 04 08:48:17 loe volumio[13215]: info: Output device has changed, restarting Shairport Sync Mar 04 08:48:17 loe volumio[13215]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 08:48:17 loe volumio[13215]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 08:48:17 loe sudo[13676]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 04 08:48:17 loe sudo[13676]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 08:48:17 loe volumio[13215]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 04 08:48:17 loe volumio[13215]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Mar 04 08:48:17 loe volumio[13215]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 08:48:17 loe volumio[13215]: info: [MyVolumio PluginManager] Starting plugin audio_interface.bluetooth Mar 04 08:48:17 loe volumio[13215]: ------------------------------------ BT MESSAGE: [FUNC] onStart Mar 04 08:48:18 loe volumio[13215]: ------------------------------------ BT MESSAGE: Starting Volumio Bluetooth Service Mar 04 08:48:18 loe volumio[13215]: ------------------------------------ BT MESSAGE: Boot config /etc/bluetooth/volumio.conf: cache mode = tmp Mar 04 08:48:18 loe volumio[13215]: ------------------------------------ BT MESSAGE: [metaCache] Directory exists and is ready. Mar 04 08:48:18 loe systemd[1]: Stopping mpd.service - Music Player Daemon... Mar 04 08:48:18 loe volumio[13215]: info: [MyVolumio PluginManager] Starting plugin audio_interface.multiroom Mar 04 08:48:18 loe volumio[13215]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , pushMultiRoomStatus Mar 04 08:48:18 loe volumio[13215]: info: MRS: Pushing multiroomSync output for this device Mar 04 08:48:18 loe volumio[13215]: info: MRS: Pushing multiroomSync output Mar 04 08:48:18 loe volumio[13215]: info: Adding audio output: Mar 04 08:48:18 loe volumio[13215]: info: Adding audio output: Mar 04 08:48:18 loe systemd[1]: mpd.service: Deactivated successfully. Mar 04 08:48:18 loe volumio[13215]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Mar 04 08:48:18 loe systemd[1]: Stopped mpd.service - Music Player Daemon. Mar 04 08:48:18 loe systemd[1]: mpd.service: Consumed 6.710s CPU time. Mar 04 08:48:18 loe systemd[1]: mpd.socket: Deactivated successfully. Mar 04 08:48:18 loe volumio[13215]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 08:48:18 loe systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Mar 04 08:48:18 loe systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Mar 04 08:48:18 loe volumio[13215]: info: [MyVolumio PluginManager] Starting plugin miscellanea.metavolumio Mar 04 08:48:18 loe bluetoothd[980]: Path / reserved for Adv Monitor app :1.5766 Mar 04 08:48:18 loe volumio[13215]: info: Adding METAVOLUMIO REST API Endpoints Mar 04 08:48:18 loe volumio[13215]: info: Adding metavolumio REST Endpoint for plugin: miscellanea/metavolumio Mar 04 08:48:18 loe volumio[13215]: info: Adding getSimilarArtists REST Endpoint for plugin: miscellanea/metavolumio Mar 04 08:48:18 loe volumio[13215]: info: Adding getSimilarAlbums REST Endpoint for plugin: miscellanea/metavolumio Mar 04 08:48:18 loe volumio[13215]: info: Adding getSimilarTracks REST Endpoint for plugin: miscellanea/metavolumio Mar 04 08:48:18 loe volumio[13215]: info: [MyVolumio PluginManager] Starting plugin miscellanea.manifestui Mar 04 08:48:18 loe volumio[13215]: info: [MyVolumio PluginManager] Starting plugin music_service.cd_controller Mar 04 08:48:18 loe volumio[13215]: info: Preparing CD Folders Mar 04 08:48:18 loe volumio[13215]: info: Adding CD REST API Endpoints Mar 04 08:48:18 loe volumio[13215]: info: Adding cdPostRip REST Endpoint for plugin: music_service/cd_controller Mar 04 08:48:18 loe volumio[13215]: info: Starting UDEV Watcher for CD Mar 04 08:48:18 loe volumio[13215]: info: Detecting CD presence with UDEV Mar 04 08:48:18 loe volumio[13215]: info: CoreCommandRouter::executeOnPlugin: networkfs , getUdevDevices Mar 04 08:48:18 loe bluetoothd[980]: Adv Monitor app :1.5766 disconnected from D-Bus Mar 04 08:48:18 loe systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Mar 04 08:48:18 loe systemd[1]: Starting mpd.service - Music Player Daemon... Mar 04 08:48:18 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Mar 04 08:48:18 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Mar 04 08:48:18 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Mar 04 08:48:18 loe sudo[13693]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Mar 04 08:48:18 loe sudo[13693]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Mar 04 08:48:18 loe sudo[13693]: pam_unix(sudo:session): session closed for user root Mar 04 08:48:19 loe systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Mar 04 08:48:19 loe systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 04 08:48:19 loe systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 04 08:48:19 loe go-librespot[13696]: go-librespot daemon starting... Mar 04 08:48:19 loe go-librespot[13697]: time="2026-03-04T08:48:19+01:00" level=info msg="running go-librespot 0.4.0" Mar 04 08:48:19 loe go-librespot[13697]: time="2026-03-04T08:48:19+01:00" level=debug msg="app state loaded" Mar 04 08:48:19 loe go-librespot[13697]: time="2026-03-04T08:48:19+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 04 08:48:20 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Mar 04 08:48:20 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Mar 04 08:48:20 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Mar 04 08:48:20 loe go-librespot[13697]: time="2026-03-04T08:48:20+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 04 08:48:20 loe go-librespot[13697]: time="2026-03-04T08:48:20+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 04 08:48:20 loe go-librespot[13697]: time="2026-03-04T08:48:20+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 04 08:48:20 loe go-librespot[13697]: time="2026-03-04T08:48:20+01:00" level=info msg="zeroconf server listening on port 43675" Mar 04 08:48:20 loe go-librespot[13697]: time="2026-03-04T08:48:20+01:00" level=debug msg="obtained new client token: AABmRKdsSqdqaNB01kZAqhO9GHw3kwDBBo3X9oSFDeneijCKn5rDDHR4kykwRnIq7D6TYhCXsbQI515wXF3mJQ4Qgfa46X2KMHX7Xj/3319qFy+1O7qH3CC1u5X8cFQBZIpN/fjVZdR0P59IpV8+7cbT9l2Y6dEnofo3TTOUZ5sl63WLIdCnRlybswvpZrAPtXXPFu2541I6D5eG0/S2FkeTE0EhvomcDTaXI6yJZzqAFesULpBL+gWbqA==" Mar 04 08:48:20 loe go-librespot[13697]: time="2026-03-04T08:48:20+01:00" level=warning msg="failed to connect to AP ap-gew4.spotify.com:4070, retrying with a different AP" error="dial tcp 34.158.1.133:4070: connect: connection refused" Mar 04 08:48:20 loe go-librespot[13697]: time="2026-03-04T08:48:20+01:00" level=debug msg="connected to ap-gew4.spotify.com:443" Mar 04 08:48:20 loe go-librespot[13697]: time="2026-03-04T08:48:20+01:00" level=debug msg="completed keyexchange" Mar 04 08:48:20 loe go-librespot[13697]: time="2026-03-04T08:48:20+01:00" level=debug msg="completed challenge" Mar 04 08:48:20 loe go-librespot[13697]: time="2026-03-04T08:48:20+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 04 08:48:20 loe systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 04 08:48:20 loe systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 04 08:48:22 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Mar 04 08:48:22 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Mar 04 08:48:22 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Mar 04 08:48:23 loe mpd[13695]: 2026-03-04T08:48:23 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Mar 04 08:48:23 loe systemd[1]: Started mpd.service - Music Player Daemon. Mar 04 08:48:23 loe sudo[13676]: pam_unix(sudo:session): session closed for user root Mar 04 08:48:23 loe volumio[13215]: warn: [cd-plugin] cdspeedctl: device or media not ready Mar 04 08:48:23 loe volumio[13215]: info: [MyVolumio PluginManager] Starting plugin music_service.smart_inputs Mar 04 08:48:23 loe volumio[13215]: info: Adding inputs REST Endpoints Mar 04 08:48:23 loe volumio[13215]: info: Adding scanAudioInputs REST Endpoint for plugin: music_service/smart_inputs Mar 04 08:48:23 loe volumio[13215]: info: Scanning Audio Inputs Mar 04 08:48:23 loe volumio[13215]: info: Checking against Known Cards name Mar 04 08:48:23 loe volumio[13215]: info: Adding Server instance for streaming Mar 04 08:48:23 loe volumio[13215]: info: [MyVolumio PluginManager] Starting plugin music_service.hi_res_audio Mar 04 08:48:23 loe volumio[13215]: info: Adding HIGHRESAUDIO REST API Endpoints Mar 04 08:48:23 loe volumio[13215]: info: Adding saveAccountData_hi_res_audio REST Endpoint for plugin: music_service/hi_res_audio Mar 04 08:48:23 loe volumio[13215]: info: [MyVolumio PluginManager] Starting plugin music_service.tidal Mar 04 08:48:23 loe volumio[13215]: info: Refreshing TIDAL token Mar 04 08:48:23 loe volumio[13215]: info: [MyVolumio PluginManager] Starting plugin music_service.qobuz Mar 04 08:48:23 loe volumio[13215]: info: [MyVolumio PluginManager] Starting plugin music_service.tidalconnect Mar 04 08:48:23 loe volumio[13215]: info: [MyVolumio PluginManager] Starting plugin music_service.qobuzconnect Mar 04 08:48:23 loe volumio[13215]: info: Adding qc_getconfig REST Endpoint for plugin: music_service/qobuzconnect Mar 04 08:48:23 loe volumio[13215]: info: QobuzConnect: Starting Qobuz Connect socket and service Mar 04 08:48:23 loe sudo[13710]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Mar 04 08:48:23 loe sudo[13710]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 08:48:23 loe volumio[13215]: info: QobuzConnect: Opened /tmp/qbz-connect.socket socket, listening for connections Mar 04 08:48:23 loe volumio[13215]: info: Stopping AccessToken refresher cron for QOBUZ Mar 04 08:48:23 loe sudo[13717]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service Mar 04 08:48:23 loe sudo[13717]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 08:48:23 loe sudo[13710]: pam_unix(sudo:session): session closed for user root Mar 04 08:48:23 loe sudo[13717]: pam_unix(sudo:session): session closed for user root Mar 04 08:48:23 loe volumio[13215]: info: AccessToken refresher cron started for QOBUZ Mar 04 08:48:23 loe volumio[13215]: info: Adding QOBUZ REST API Endpoints Mar 04 08:48:23 loe sudo[13720]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service Mar 04 08:48:23 loe sudo[13720]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 08:48:23 loe volumio[13215]: info: MRS: Getting audio outputs on start Mar 04 08:48:23 loe volumio[13215]: info: MRS: Requesting all other devices output Mar 04 08:48:23 loe volumio[13215]: info: Updating MyVolumio device info Mar 04 08:48:23 loe volumio[13215]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 08:48:23 loe volumio[13215]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 08:48:23 loe volumio[13215]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 08:48:23 loe volumio[13215]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 04 08:48:23 loe volumio[13215]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 08:48:23 loe systemd[1]: Stopping qobuz-connect.service - Volumio Qobuz Connect Service... Mar 04 08:48:23 loe volumio[13215]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Mar 04 08:48:23 loe qobuz-connect[11739]: 20260304 08:48:23.639 [11739.11739] INFO SampleApp: Stopping Local configuration server Mar 04 08:48:23 loe volumio[13215]: info: Initializing connection to go-librespot Websocket Mar 04 08:48:23 loe volumio[13215]: info: Successfully Updated MyVolumio device Mar 04 08:48:23 loe systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Mar 04 08:48:23 loe systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 04 08:48:23 loe volumio[13215]: info: Successfully Added MyVolumio device Mar 04 08:48:23 loe volumio[13215]: ------------------------------------ BT MESSAGE: Bluetooth adapter powered on Mar 04 08:48:23 loe systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 04 08:48:23 loe go-librespot[13725]: go-librespot daemon starting... Mar 04 08:48:23 loe volumio[13215]: info: MPD Permissions set Mar 04 08:48:23 loe sudo[13728]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumiobt.service Mar 04 08:48:23 loe sudo[13728]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 08:48:23 loe go-librespot[13727]: time="2026-03-04T08:48:23+01:00" level=info msg="running go-librespot 0.4.0" Mar 04 08:48:23 loe go-librespot[13727]: time="2026-03-04T08:48:23+01:00" level=debug msg="app state loaded" Mar 04 08:48:23 loe go-librespot[13727]: time="2026-03-04T08:48:23+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 04 08:48:24 loe sudo[13728]: pam_unix(sudo:session): session closed for user root Mar 04 08:48:24 loe volumio[13215]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 04 08:48:24 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Mar 04 08:48:24 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Mar 04 08:48:24 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Mar 04 08:48:24 loe volumio[13215]: info: Successfully Updated MyVolumio device Mar 04 08:48:24 loe volumio[13215]: ------------------------------------ BT MESSAGE: volumiobt.service started successfully Mar 04 08:48:24 loe volumio[13215]: info: CoreCommandRouter::volumioStop Mar 04 08:48:24 loe volumio[13215]: info: CoreStateMachine::stop Mar 04 08:48:24 loe volumio[13215]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 04 08:48:24 loe volumio[13215]: ------------------------------------ BT MESSAGE: [FUNC] dbusStart Mar 04 08:48:24 loe volumio[13215]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 04 08:48:24 loe volumio[13215]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 08:48:24 loe volumio[13215]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 08:48:24 loe volumio[13215]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 08:48:24 loe volumio[13215]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 08:48:24 loe volumio[13215]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 08:48:24 loe volumio[13215]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 08:48:24 loe volumio[13215]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 08:48:24 loe volumio[13215]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 08:48:24 loe volumio[13215]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 08:48:24 loe volumio[13215]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 08:48:24 loe volumio-remote-updater[714]: Test mode disabled Mar 04 08:48:24 loe volumio-remote-updater[714]: Alpha mode disabled Mar 04 08:48:24 loe volumio-remote-updater[714]: Alpha legacy test mode disabled Mar 04 08:48:24 loe volumio[13215]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled Mar 04 08:48:24 loe volumio[13215]: error: updateQueue error: null Mar 04 08:48:24 loe go-librespot[13727]: time="2026-03-04T08:48:24+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 04 08:48:24 loe go-librespot[13727]: time="2026-03-04T08:48:24+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 04 08:48:24 loe go-librespot[13727]: time="2026-03-04T08:48:24+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 04 08:48:24 loe go-librespot[13727]: time="2026-03-04T08:48:24+01:00" level=info msg="zeroconf server listening on port 44689" Mar 04 08:48:24 loe systemd[1]: qobuz-connect.service: Deactivated successfully. Mar 04 08:48:24 loe systemd[1]: Stopped qobuz-connect.service - Volumio Qobuz Connect Service. Mar 04 08:48:24 loe go-librespot[13727]: time="2026-03-04T08:48:24+01:00" level=debug msg="obtained new client token: AADRbhBWaE9mp3SUpza4onR2x7cBUKJq9Jll556SLj3DEADKxYMmUmTPUk1rOeXstjMkkEdUpX8/vypkMD1CrwIxxMys+s2fBuLrSZ2sFV/t0fLvWm5BLmqKPthYW5QAqvK3mhyiFK6p0GasqhlidNJSxS5uujtImZ4iRbY/rhfwDkbD69hxtp1nqDiDArqxenCQ48kvravRT8dZjN0cgcejx5WqhPEBPdfh4KXOfxD4f8rAXGqGa/7CBA==" Mar 04 08:48:24 loe volumio[13215]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Mar 04 08:48:24 loe systemd[1]: Started qobuz-connect.service - Volumio Qobuz Connect Service. Mar 04 08:48:24 loe go-librespot[13727]: time="2026-03-04T08:48:24+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 04 08:48:24 loe sudo[13720]: pam_unix(sudo:session): session closed for user root Mar 04 08:48:24 loe volumio[13215]: error: Hi Res Audio Failed Login: [object Object] Mar 04 08:48:24 loe sudo[13765]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart sshtunnel.service Mar 04 08:48:24 loe volumio[13215]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Mar 04 08:48:24 loe volumio[13215]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Mar 04 08:48:24 loe sudo[13765]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 08:48:24 loe go-librespot[13727]: time="2026-03-04T08:48:24+01:00" level=debug msg="completed keyexchange" Mar 04 08:48:24 loe go-librespot[13727]: time="2026-03-04T08:48:24+01:00" level=debug msg="completed challenge" Mar 04 08:48:24 loe volumio[13215]: info: MRS: Found cast device: Chromecast-84d0dcfc86c31e08fb7722859cd1fe00 Mar 04 08:48:24 loe volumio[13215]: info: Adding audio output: Mar 04 08:48:24 loe go-librespot[13727]: time="2026-03-04T08:48:24+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 04 08:48:24 loe volumio[13215]: info: Starting Shairport Sync Mar 04 08:48:24 loe systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 04 08:48:24 loe systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 04 08:48:24 loe autossh[11748]: received signal to exit (15) Mar 04 08:48:24 loe systemd[1]: Stopping sshtunnel.service - MyVolumio SSH Tunnel... Mar 04 08:48:24 loe systemd[1]: sshtunnel.service: Deactivated successfully. Mar 04 08:48:24 loe systemd[1]: Stopped sshtunnel.service - MyVolumio SSH Tunnel. Mar 04 08:48:24 loe sudo[13769]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 04 08:48:24 loe sudo[13769]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 08:48:24 loe systemd[1]: Started sshtunnel.service - MyVolumio SSH Tunnel. Mar 04 08:48:24 loe sudo[13765]: pam_unix(sudo:session): session closed for user root Mar 04 08:48:24 loe autossh[13772]: port set to 0, monitoring disabled Mar 04 08:48:24 loe autossh[13772]: starting ssh (count 1) Mar 04 08:48:24 loe autossh[13772]: ssh child pid is 13775 Mar 04 08:48:25 loe systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Mar 04 08:48:25 loe systemd[1]: shairport-sync.service: Deactivated successfully. Mar 04 08:48:25 loe systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 04 08:48:25 loe systemd[1]: shairport-sync.service: Consumed 1.991s CPU time. Mar 04 08:48:25 loe systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 04 08:48:25 loe sudo[13769]: pam_unix(sudo:session): session closed for user root Mar 04 08:48:25 loe volumio[13215]: info: Access Token successfully retrieved Mar 04 08:48:25 loe volumio[13215]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 4 Mar 04 08:48:25 loe volumio[13215]: info: Executing endpoint qc_getconfig Mar 04 08:48:25 loe volumio[13215]: info: CoreCommandRouter::executeOnPlugin: qobuzconnect , onGetConfig Mar 04 08:48:25 loe volumiossh-tunnel[13775]: Warning: Permanently added '[eu12.myvolumio.org]:2222' (ED25519) to the list of known hosts. Mar 04 08:48:25 loe qobuz-connect[13763]: 20260304 08:48:25.314 [13763.13763] INFO SampleApp: Started connection to /tmp/qbz-connect.socket UNIX socket Mar 04 08:48:25 loe qobuz-connect[13763]: 20260304 08:48:25.329 [13763.13763] INFO VolumeManager: [0x13d8408]: Setting new playback volume: 75 Mar 04 08:48:25 loe qobuz-connect[13763]: 20260304 08:48:25.330 [13763.13763] INFO VolumeManager: [0x13d8408]: Setting new mute state: 0 Mar 04 08:48:25 loe qobuz-connect[13763]: 20260304 08:48:25.330 [13763.13763] INFO QobuzConnect: [0x13d8dd8]: Client initialized! Mar 04 08:48:25 loe qobuz-connect[13763]: 20260304 08:48:25.331 [13763.13763] INFO SampleApp: Starting Avahi advertising, name: Loe, service name: _qobuz-connect._tcp Mar 04 08:48:25 loe volumio[13215]: info: Shairport-Sync Started Mar 04 08:48:25 loe volumio[13215]: info: Remote SSH Started Mar 04 08:48:25 loe qobuz-connect[13763]: 20260304 08:48:25.386 [13763.13763] INFO LocalConfigManager: [0x13d7ce8]: Starting Local Configuration server Mar 04 08:48:25 loe qobuz-connect[13763]: 20260304 08:48:25.386 [13763.13763] INFO SampleApp: Starting Local configuration server Mar 04 08:48:25 loe qobuz-connect[13763]: 20260304 08:48:25.387 [13763.13763] INFO SampleApp: Connected to UNIX socket client 0x13c2818 Mar 04 08:48:25 loe qobuz-connect[13763]: 20260304 08:48:25.464 [13763.13763] INFO SampleApp: Playback volume changed: 75 Mar 04 08:48:25 loe volumio[13215]: info: QobuzConnect: Qobuz Connect socket /tmp/qbz-connect.socket connected to client [object Object] Mar 04 08:48:25 loe volumio[13215]: info: QobuzConnect: QOBUZ Connect daemon connected Mar 04 08:48:25 loe volumio[13215]: info: CoreCommandRouter::volumioGetState Mar 04 08:48:25 loe volumio[13215]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 5 Mar 04 08:48:25 loe volumio[13215]: info: CoreCommandRouter::volumioGetState Mar 04 08:48:25 loe volumio[13215]: info: Successfully retrieved User Session From TIDAL Mar 04 08:48:25 loe volumio[13215]: info: CoreCommandRouter::volumioGetState Mar 04 08:48:26 loe volumio[13215]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.mjORZRjMx8YIlyGajvB2CXSYA5r2.a53384b16fd4d7a180fdac1b5068092c.state.status' Mar 04 08:48:26 loe volumio[13215]: info: Successfully retrieved User Subscription From TIDAL Mar 04 08:48:26 loe volumio[13215]: info: Adding TIDAL to Browse Sources Mar 04 08:48:26 loe volumio[13215]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 04 08:48:26 loe volumio[13215]: info: [1772610506118] CoreMusicLibrary::Adding element TIDAL Mar 04 08:48:26 loe volumio[13215]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 04 08:48:26 loe volumio[13215]: Cannot find translation for source TIDAL Mar 04 08:48:26 loe volumio[13215]: info: Adding TIDAL REST API Endpoints Mar 04 08:48:26 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Mar 04 08:48:26 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Mar 04 08:48:26 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Mar 04 08:48:26 loe volumio[13215]: info: TidalConnect service stoped! Mar 04 08:48:26 loe volumio[13215]: info: Adding tc_getconfig REST Endpoint for plugin: music_service/tidalconnect Mar 04 08:48:26 loe volumio[13215]: info: Adding tc_connect REST Endpoint for plugin: music_service/tidalconnect Mar 04 08:48:26 loe sudo[13805]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start vtcs.service Mar 04 08:48:26 loe sudo[13805]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 08:48:26 loe systemd[1]: Started vtcs.service - Volumio Tidal Connect Service. Mar 04 08:48:26 loe sudo[13805]: pam_unix(sudo:session): session closed for user root Mar 04 08:48:27 loe volumio[13215]: info: Executing endpoint tc_getconfig Mar 04 08:48:27 loe volumio[13215]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onGetConfig Mar 04 08:48:27 loe volumio[13215]: info: Initializing connection to go-librespot Websocket Mar 04 08:48:27 loe vtcs[13808]: STARTING TidalConnect services, version: 1.6.1 Mar 04 08:48:27 loe volumio[13215]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 04 08:48:27 loe vtcs[13808]: STARTED TidalConnect services. Mar 04 08:48:27 loe volumio[13215]: info: Executing endpoint tc_connect Mar 04 08:48:27 loe volumio[13215]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onConnect Mar 04 08:48:27 loe volumio[13215]: info: Connecting to TidalConnect Mar 04 08:48:27 loe volumio[13215]: info: CoreCommandRouter::servicePushState Mar 04 08:48:27 loe volumio[13215]: info: CoreStateMachine::pushState Mar 04 08:48:27 loe volumio[13215]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 04 08:48:27 loe volumio[13215]: info: CoreCommandRouter::volumioPushState Mar 04 08:48:27 loe volumio[13215]: info: MRS: Pushing multiroomSync output update for this device Mar 04 08:48:27 loe volumio[13215]: info: MRS: Pushing multiroomSync output Mar 04 08:48:27 loe volumio[13215]: info: CoreCommandRouter::volumioGetState Mar 04 08:48:27 loe volumio[13215]: info: CorePlayQueue::getTrack 0 Mar 04 08:48:27 loe volumio[13215]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current tidal Received tidalconnect Mar 04 08:48:27 loe volumio[13215]: info: CoreCommandRouter::servicePushState Mar 04 08:48:27 loe volumio[13215]: info: CoreStateMachine::pushState Mar 04 08:48:27 loe volumio[13215]: info: CoreCommandRouter::volumioPushState Mar 04 08:48:27 loe volumio[13215]: info: MRS: Pushing multiroomSync output update for this device Mar 04 08:48:27 loe volumio[13215]: info: MRS: Pushing multiroomSync output Mar 04 08:48:27 loe volumio[13215]: info: CoreCommandRouter::volumioGetState Mar 04 08:48:27 loe volumio[13215]: info: CorePlayQueue::getTrack 0 Mar 04 08:48:27 loe volumio[13215]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current tidal Received tidalconnect Mar 04 08:48:27 loe volumio[13215]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.mjORZRjMx8YIlyGajvB2CXSYA5r2.a53384b16fd4d7a180fdac1b5068092c.state.status' Mar 04 08:48:28 loe systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Mar 04 08:48:28 loe systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 04 08:48:28 loe systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 04 08:48:28 loe go-librespot[13824]: go-librespot daemon starting... Mar 04 08:48:28 loe go-librespot[13825]: time="2026-03-04T08:48:28+01:00" level=info msg="running go-librespot 0.4.0" Mar 04 08:48:28 loe go-librespot[13825]: time="2026-03-04T08:48:28+01:00" level=debug msg="app state loaded" Mar 04 08:48:28 loe go-librespot[13825]: time="2026-03-04T08:48:28+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 04 08:48:28 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Mar 04 08:48:28 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Mar 04 08:48:28 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Mar 04 08:48:28 loe go-librespot[13825]: time="2026-03-04T08:48:28+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 04 08:48:28 loe go-librespot[13825]: time="2026-03-04T08:48:28+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 04 08:48:28 loe go-librespot[13825]: time="2026-03-04T08:48:28+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 04 08:48:28 loe go-librespot[13825]: time="2026-03-04T08:48:28+01:00" level=info msg="zeroconf server listening on port 36869" Mar 04 08:48:28 loe go-librespot[13825]: time="2026-03-04T08:48:28+01:00" level=debug msg="obtained new client token: AABmkOruFzeKqlIP4I6MYuLaNjUUctTlQj1QvZ+FpV/BWuVnUoOAVvw98CzUbjihC/bvCYZCIc7UCvUDbROkzWarqnIz9V6r2skvvNQKRxtm/W/aFiFIwYAGsm27GGe0/Shi0KJFakfE8rlrpXjlGxXYGAcPQiKs38HJXDhGPRl/VL80qHvaYeNRoR0CSDI5QhhtuCnlvusSG46CBEvKq2dUFdGYlntDwPUFcVMoT/EDQYtuLgX1YCzWWQ==" Mar 04 08:48:28 loe go-librespot[13825]: time="2026-03-04T08:48:28+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 04 08:48:28 loe go-librespot[13825]: time="2026-03-04T08:48:28+01:00" level=debug msg="completed keyexchange" Mar 04 08:48:28 loe go-librespot[13825]: time="2026-03-04T08:48:28+01:00" level=debug msg="completed challenge" Mar 04 08:48:28 loe go-librespot[13825]: time="2026-03-04T08:48:28+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 04 08:48:28 loe systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 04 08:48:28 loe systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 04 08:48:29 loe volumio[13215]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 08:48:29 loe volumio[13215]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 08:48:29 loe volumio[13215]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Mar 04 08:48:29 loe volumio[13215]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Mar 04 08:48:29 loe volumio[13215]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Mar 04 08:48:29 loe volumio[13215]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Mar 04 08:48:29 loe volumio[13215]: info: CoreCommandRouter::volumioGetBrowseSources Mar 04 08:48:29 loe volumio[13215]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 04 08:48:29 loe volumio[13215]: info: TidalConnect service started! Mar 04 08:48:29 loe volumio[13215]: [Metrics] CommandRouter: 49s 953.70ms Mar 04 08:48:29 loe volumio[13215]: info: CoreCommandRouter::volumiosetStartupVolume Mar 04 08:48:29 loe volumio[13215]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 04 08:48:29 loe volumio[13215]: info: VolumeController:: Setting startup Volume 5 Mar 04 08:48:29 loe volumio[13215]: info: VolumeController::SetAlsaVolume5 Mar 04 08:48:29 loe volumio[13215]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 04 08:48:29 loe volumio[13215]: info: CoreCommandRouter::Close All Modals sent Mar 04 08:48:29 loe volumio[13215]: info: CoreCommandRouter::Close All Modals sent Mar 04 08:48:29 loe volumio[13215]: info: CoreStateMachine::pushState Mar 04 08:48:29 loe volumio[13215]: info: CoreCommandRouter::volumioPushState Mar 04 08:48:29 loe volumio[13215]: info: MRS: Pushing multiroomSync output update for this device Mar 04 08:48:29 loe volumio[13215]: info: MRS: Pushing multiroomSync output Mar 04 08:48:29 loe volumio[13215]: info: CoreCommandRouter::volumioGetState Mar 04 08:48:29 loe volumio[13215]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.mjORZRjMx8YIlyGajvB2CXSYA5r2.a53384b16fd4d7a180fdac1b5068092c.state.status' Mar 04 08:48:30 loe volumio[13215]: info: Initializing connection to go-librespot Websocket Mar 04 08:48:30 loe volumio[13215]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 04 08:48:30 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Mar 04 08:48:30 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Mar 04 08:48:30 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Mar 04 08:48:30 loe volumio[13215]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Mar 04 08:48:30 loe volumio[13215]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Mar 04 08:48:30 loe volumio[13215]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Mar 04 08:48:32 loe systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Mar 04 08:48:32 loe systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 04 08:48:32 loe systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 04 08:48:32 loe go-librespot[13838]: go-librespot daemon starting... Mar 04 08:48:32 loe go-librespot[13839]: time="2026-03-04T08:48:32+01:00" level=info msg="running go-librespot 0.4.0" Mar 04 08:48:32 loe go-librespot[13839]: time="2026-03-04T08:48:32+01:00" level=debug msg="app state loaded" Mar 04 08:48:32 loe go-librespot[13839]: time="2026-03-04T08:48:32+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 04 08:48:32 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Mar 04 08:48:32 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Mar 04 08:48:32 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Mar 04 08:48:32 loe go-librespot[13839]: time="2026-03-04T08:48:32+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 04 08:48:32 loe go-librespot[13839]: time="2026-03-04T08:48:32+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 04 08:48:32 loe go-librespot[13839]: time="2026-03-04T08:48:32+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 04 08:48:32 loe go-librespot[13839]: time="2026-03-04T08:48:32+01:00" level=info msg="zeroconf server listening on port 37555" Mar 04 08:48:32 loe go-librespot[13839]: time="2026-03-04T08:48:32+01:00" level=debug msg="obtained new client token: AACJQupSIHbcLTXzRPY5FEaRfIU6f95Hugq/AyiPR7AzL1Gc/NIqPH+Q15A10gx5nk334AqbAhMdZPY/R+Ljfe0JdGV/Nc1j/VvAPfDPdluYs0bFG0uc2/Qm9n6lTJb3mNBUQMEaLRbCnFkP0p0ewrSOEu0bePC+8Er8LcQQH0+t3kjiFaB98d4QsU5nPnaC1N9Y6/e9u+U9J7qTfDJhTJBRVZmms1O2+0KUAKPPh3F4id22FDrb+V1cjQ==" Mar 04 08:48:32 loe go-librespot[13839]: time="2026-03-04T08:48:32+01:00" level=warning msg="failed to connect to AP ap-gew4.spotify.com:4070, retrying with a different AP" error="dial tcp 34.158.1.133:4070: connect: connection refused" Mar 04 08:48:32 loe go-librespot[13839]: time="2026-03-04T08:48:32+01:00" level=debug msg="connected to ap-gew4.spotify.com:443" Mar 04 08:48:32 loe go-librespot[13839]: time="2026-03-04T08:48:32+01:00" level=debug msg="completed keyexchange" Mar 04 08:48:32 loe go-librespot[13839]: time="2026-03-04T08:48:32+01:00" level=debug msg="completed challenge" Mar 04 08:48:32 loe go-librespot[13839]: time="2026-03-04T08:48:32+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 04 08:48:32 loe systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 04 08:48:32 loe systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 04 08:48:33 loe volumio[13215]: info: Initializing connection to go-librespot Websocket Mar 04 08:48:33 loe volumio[13215]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 04 08:48:34 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Mar 04 08:48:34 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Mar 04 08:48:34 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Mar 04 08:48:36 loe systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Mar 04 08:48:36 loe systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 04 08:48:36 loe systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 04 08:48:36 loe go-librespot[13860]: go-librespot daemon starting... Mar 04 08:48:36 loe go-librespot[13861]: time="2026-03-04T08:48:36+01:00" level=info msg="running go-librespot 0.4.0" Mar 04 08:48:36 loe go-librespot[13861]: time="2026-03-04T08:48:36+01:00" level=debug msg="app state loaded" Mar 04 08:48:36 loe go-librespot[13861]: time="2026-03-04T08:48:36+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 04 08:48:36 loe volumio[13215]: info: Initializing connection to go-librespot Websocket Mar 04 08:48:36 loe go-librespot[13861]: time="2026-03-04T08:48:36+01:00" level=debug msg="new websocket client" Mar 04 08:48:36 loe volumio[13215]: info: Connection to go-librespot Websocket established Mar 04 08:48:36 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Mar 04 08:48:36 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Mar 04 08:48:36 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Mar 04 08:48:36 loe go-librespot[13861]: time="2026-03-04T08:48:36+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 04 08:48:36 loe go-librespot[13861]: time="2026-03-04T08:48:36+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 04 08:48:36 loe go-librespot[13861]: time="2026-03-04T08:48:36+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 04 08:48:36 loe go-librespot[13861]: time="2026-03-04T08:48:36+01:00" level=info msg="zeroconf server listening on port 33665" Mar 04 08:48:36 loe go-librespot[13861]: time="2026-03-04T08:48:36+01:00" level=debug msg="obtained new client token: AACswX2qb8RAxCxSxjKNCX8j8IcyZXjb0/eZplBX88ZTr6DVVqHTwcZSWU2xQg7zi0nVtFeQnOYqblPTIBxPL8ML/BMFEp4jlU/cqYVWAe8xVcBGWhVv8RArVk3cnR520DBP2B27lUrIPolDZ5xweU1et+sZgYRxjavKyOfaxUR98WtTwo1yq+9hecc1nA+xskuR8lEocdABso4BgKDukml9ZJPLR5tAS7bgKR+qWj3FqIZIJkbSrzmeEw==" Mar 04 08:48:36 loe go-librespot[13861]: time="2026-03-04T08:48:36+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 04 08:48:36 loe go-librespot[13861]: time="2026-03-04T08:48:36+01:00" level=debug msg="completed keyexchange" Mar 04 08:48:36 loe go-librespot[13861]: time="2026-03-04T08:48:36+01:00" level=debug msg="completed challenge" Mar 04 08:48:36 loe go-librespot[13861]: time="2026-03-04T08:48:36+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 04 08:48:36 loe volumio[13215]: info: BOOT COMPLETED Mar 04 08:48:36 loe systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 04 08:48:36 loe systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 04 08:48:36 loe volumio[13215]: info: Connection to go-librespot Websocket closed Mar 04 08:48:38 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Mar 04 08:48:38 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Mar 04 08:48:38 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Mar 04 08:48:39 loe volumio[13215]: info: Getting Spotify volume Mar 04 08:48:39 loe volumio[13215]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 04 08:48:39 loe volumio[13215]: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 04 08:48:39 loe volumio[13215]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Mar 04 08:48:39 loe volumio[13215]: errno: -111, Mar 04 08:48:39 loe volumio[13215]: code: 'ECONNREFUSED', Mar 04 08:48:39 loe volumio[13215]: syscall: 'connect', Mar 04 08:48:39 loe volumio[13215]: address: '127.0.0.1', Mar 04 08:48:39 loe volumio[13215]: port: 9879, Mar 04 08:48:39 loe volumio[13215]: response: undefined Mar 04 08:48:39 loe volumio[13215]: } Mar 04 08:48:39 loe volumio[13215]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 04 08:48:40 loe systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 11. Mar 04 08:48:40 loe systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 04 08:48:40 loe systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 04 08:48:40 loe go-librespot[13880]: go-librespot daemon starting... Mar 04 08:48:40 loe go-librespot[13881]: time="2026-03-04T08:48:40+01:00" level=info msg="running go-librespot 0.4.0" Mar 04 08:48:40 loe go-librespot[13881]: time="2026-03-04T08:48:40+01:00" level=debug msg="app state loaded" Mar 04 08:48:40 loe go-librespot[13881]: time="2026-03-04T08:48:40+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 04 08:48:40 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Mar 04 08:48:40 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Mar 04 08:48:40 loe upmpdcli[1410]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Mar 04 08:48:40 loe go-librespot[13881]: time="2026-03-04T08:48:40+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 04 08:48:40 loe go-librespot[13881]: time="2026-03-04T08:48:40+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 04 08:48:40 loe go-librespot[13881]: time="2026-03-04T08:48:40+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 04 08:48:40 loe go-librespot[13881]: time="2026-03-04T08:48:40+01:00" level=info msg="zeroconf server listening on port 46341" Mar 04 08:48:40 loe sudo[13890]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-03-04 08:47' Mar 04 08:48:40 loe sudo[13890]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 04 08:48:40 loe go-librespot[13881]: time="2026-03-04T08:48:40+01:00" level=debug msg="obtained new client token: AAA6/YOXSZlf8ucrbs+rd1xNia/pRagE8UT6crFKw8WxkLg0wjfNjG8n5jj+AXpjwfYDQtta7QV/09GSfH+jcittGnvg4m4K6oDSRP31D1eDVQsS4c4aue9EK6Fm0Yr6M4aMwWgogxTXYwu6nMembQIaJQIjGm9P3qTn2CaxZikrI12gd1g3hv7wHt2bLE3OIQBaJF0XU2eash+rXgS8Bq938VhITEviukm8nWmPstlmF2hvMoW+sA+DBA==" Mar 04 08:48:40 loe go-librespot[13881]: time="2026-03-04T08:48:40+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 04 08:48:40 loe go-librespot[13881]: time="2026-03-04T08:48:40+01:00" level=debug msg="completed keyexchange" Mar 04 08:48:40 loe go-librespot[13881]: time="2026-03-04T08:48:40+01:00" level=debug msg="completed challenge" Mar 04 08:48:40 loe go-librespot[13881]: time="2026-03-04T08:48:40+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 04 08:48:40 loe systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 04 08:48:40 loe systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. 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="a78d359cf1dc63ac74e9d151015afd30d31a709a" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="c1ffe93b2136013fc1b5903a4ed7e3f34e0a7bec" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu Feb 5 14:07:07 UTC 2026" VOLUMIO_VERSION="4.096" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="5e37060f9823263a753eb5e84030104f"