Mar 25 06:45:00 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Mar 25 06:45:00 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 06:45:00 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 06:45:00 katarynka go-librespot[13508]: go-librespot daemon starting... Mar 25 06:45:00 katarynka go-librespot[13509]: time="2026-03-25T06:45:00+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 06:45:00 katarynka go-librespot[13509]: time="2026-03-25T06:45:00+01:00" level=debug msg="app state loaded" Mar 25 06:45:00 katarynka go-librespot[13509]: time="2026-03-25T06:45:00+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 06:45:00 katarynka go-librespot[13509]: time="2026-03-25T06:45: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-gae2.spotify.com:80]" Mar 25 06:45:00 katarynka go-librespot[13509]: time="2026-03-25T06:45:00+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 25 06:45:00 katarynka go-librespot[13509]: time="2026-03-25T06:45:00+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 25 06:45:00 katarynka go-librespot[13509]: time="2026-03-25T06:45:00+01:00" level=info msg="zeroconf server listening on port 39805" Mar 25 06:45:01 katarynka go-librespot[13509]: time="2026-03-25T06:45:01+01:00" level=debug msg="obtained new client token: AADqwnaeKtz0cVwW4a8KGOlmPEde3gHEcZb++dDgux+dLXzbWWwgw+8HNcqh5KjIcM7ci/otFgEWH8dUSmcO7aHFSQx8iQjpEYEX7kTSO45J8ba0ybtcejJySpLknkPO4RLPV1Zm50aXC5QqAurTpCBdRqnA8vezo5aQTzrivNobPXvWTRWWPpKBA5l1LE9uQXRO/gI0AmonJOsnDcXkXAvKQFm7NZuZWAadmRLYKTtF1jgUhaEizmH2" Mar 25 06:45:01 katarynka go-librespot[13509]: time="2026-03-25T06:45:01+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 25 06:45:01 katarynka go-librespot[13509]: time="2026-03-25T06:45:01+01:00" level=debug msg="connected to ap-gew4.spotify.com:443" Mar 25 06:45:01 katarynka go-librespot[13509]: time="2026-03-25T06:45:01+01:00" level=debug msg="completed keyexchange" Mar 25 06:45:01 katarynka go-librespot[13509]: time="2026-03-25T06:45:01+01:00" level=debug msg="completed challenge" Mar 25 06:45:01 katarynka go-librespot[13509]: time="2026-03-25T06:45:01+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 25 06:45:01 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 06:45:01 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 06:45:01 katarynka volumio[13432]: info: Starting UPNP Browser Mar 25 06:45:01 katarynka volumio[13432]: info: Loading plugin "alarm-clock"... Mar 25 06:45:01 katarynka volumio[13432]: info: Loading plugin "airplay_emulation"... Mar 25 06:45:02 katarynka volumio[13432]: info: Starting Shairport Sync Mar 25 06:45:02 katarynka volumio[13432]: info: Loading plugin "last_100"... Mar 25 06:45:02 katarynka volumio[13432]: info: Loading plugin "webradio"... Mar 25 06:45:02 katarynka volumio[13432]: info: Loading plugin "i2s_dacs"... Mar 25 06:45:02 katarynka volumio[13432]: info: Loading plugin "volumiodiscovery"... Mar 25 06:45:02 katarynka volumio[13432]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Mar 25 06:45:02 katarynka volumio[13432]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 25 06:45:02 katarynka node[13432]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Mar 25 06:45:02 katarynka volumio[13432]: *** WARNING *** For more information see Mar 25 06:45:02 katarynka volumio[13432]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Mar 25 06:45:02 katarynka volumio[13432]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 25 06:45:02 katarynka volumio[13432]: *** WARNING *** For more information see Mar 25 06:45:02 katarynka node[13432]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 25 06:45:02 katarynka node[13432]: *** WARNING *** For more information see Mar 25 06:45:02 katarynka node[13432]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Mar 25 06:45:02 katarynka node[13432]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 25 06:45:02 katarynka node[13432]: *** WARNING *** For more information see Mar 25 06:45:02 katarynka volumio[13432]: info: Applying required configuration parameters for plugin volumiodiscovery Mar 25 06:45:02 katarynka volumio[13432]: info: Discovery: Started advertising with name: katarynka Mar 25 06:45:02 katarynka volumio[13432]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 25 06:45:02 katarynka volumio[13432]: info: Loading plugin "spop"... Mar 25 06:45:04 katarynka volumio[13432]: info: Loading plugin "outputs"... Mar 25 06:45:04 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Mar 25 06:45:04 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 06:45:04 katarynka volumio[13432]: info: Loading plugin "albumart"... Mar 25 06:45:04 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 06:45:04 katarynka go-librespot[13518]: go-librespot daemon starting... Mar 25 06:45:04 katarynka volumio[13432]: info: Plugin example_plugin is not enabled Mar 25 06:45:04 katarynka volumio[13432]: info: Loading plugin "inputs"... Mar 25 06:45:04 katarynka volumio[13432]: info: Loading plugin "updater_comm"... Mar 25 06:45:04 katarynka go-librespot[13520]: time="2026-03-25T06:45:04+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 06:45:04 katarynka go-librespot[13520]: time="2026-03-25T06:45:04+01:00" level=debug msg="app state loaded" Mar 25 06:45:04 katarynka go-librespot[13520]: time="2026-03-25T06:45:04+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 06:45:04 katarynka volumio[13432]: info: Plugin mpdemulation is not enabled Mar 25 06:45:04 katarynka volumio[13432]: info: Loading plugin "rest_api"... Mar 25 06:45:04 katarynka volumio[13432]: info: Loading plugin "websocket"... Mar 25 06:45:04 katarynka volumio[13432]: info: Starting Socket.io Server version 1.7.4 Mar 25 06:45:04 katarynka volumio[13432]: info: Loading i18n strings for locale pl Mar 25 06:45:04 katarynka volumio[13432]: Updating browse sources language Mar 25 06:45:04 katarynka volumio[13432]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 25 06:45:05 katarynka go-librespot[13520]: time="2026-03-25T06:45:05+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 25 06:45:05 katarynka go-librespot[13520]: time="2026-03-25T06:45:05+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 25 06:45:05 katarynka go-librespot[13520]: time="2026-03-25T06:45:05+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 25 06:45:05 katarynka go-librespot[13520]: time="2026-03-25T06:45:05+01:00" level=info msg="zeroconf server listening on port 44317" Mar 25 06:45:05 katarynka volumio[13432]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 25 06:45:05 katarynka volumio[13432]: info: CoreCommandRouter::initPlayerControls Mar 25 06:45:05 katarynka volumio[13432]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 06:45:05 katarynka volumio[13432]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 06:45:05 katarynka volumio[13432]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 06:45:05 katarynka volumio[13432]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 06:45:05 katarynka volumio[13432]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 06:45:05 katarynka volumio[13432]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 06:45:05 katarynka volumio[13432]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 06:45:05 katarynka volumio[13432]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 06:45:05 katarynka volumio[13432]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 25 06:45:05 katarynka volumio[13432]: Express server listening on port 3000 Mar 25 06:45:05 katarynka volumio[13432]: [Metrics] WebUI: 12s 480.69ms Mar 25 06:45:05 katarynka go-librespot[13520]: time="2026-03-25T06:45:05+01:00" level=debug msg="obtained new client token: AADG5EpKZlIh8F0X6X/oMgqKLuEURYLTZq86OIme1cX9Y26MeGpsAwKKxahuMtVjsYGIG0O+YEKkbw23N+5GzGPyP/p+rulhvXaPzHyUR6mZRIgj83nqvR9NW6ntfRDdjSRrA0g5sLX3gODhZiPfOECELZZMvbqSsn5uXGe7fE66pt1mQm5Pxt0ZG1RK1CpTtcvClbfSLKogKJfUjUsrKOg/EV5jGTPBokH1LHyTDdJPyS5Auhi1jMWB" Mar 25 06:45:05 katarynka volumio[13432]: info: CoreStateMachine::resetVolumioState Mar 25 06:45:05 katarynka volumio[13432]: info: CoreStateMachine::getcurrentVolume Mar 25 06:45:05 katarynka volumio[13432]: info: CoreCommandRouter::volumioRetrievevolume Mar 25 06:45:05 katarynka go-librespot[13520]: time="2026-03-25T06:45:05+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 06:45:05 katarynka volumio[13432]: info: Cannot read play queue from file Mar 25 06:45:05 katarynka go-librespot[13520]: time="2026-03-25T06:45:05+01:00" level=debug msg="completed keyexchange" Mar 25 06:45:05 katarynka go-librespot[13520]: time="2026-03-25T06:45:05+01:00" level=debug msg="completed challenge" Mar 25 06:45:05 katarynka volumio[13432]: info: Volumio Network Manager: Network status updated: 2 Mar 25 06:45:05 katarynka go-librespot[13520]: time="2026-03-25T06:45:05+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 25 06:45:05 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 06:45:05 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 06:45:05 katarynka volumio[13519]: Forking 3 albumart workers Mar 25 06:45:05 katarynka volumio[13432]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 06:45:05 katarynka volumio[13432]: info: CoreStateMachine::setRepeat null single undefined Mar 25 06:45:05 katarynka volumio[13432]: info: CoreStateMachine::pushState Mar 25 06:45:05 katarynka volumio[13432]: info: CorePlayQueue::getTrack 0 Mar 25 06:45:05 katarynka volumio[13432]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 25 06:45:05 katarynka volumio[13432]: info: CoreCommandRouter::volumioPushState Mar 25 06:45:05 katarynka volumio[13432]: info: CoreStateMachine::setRandom null Mar 25 06:45:05 katarynka volumio[13432]: info: CoreStateMachine::pushState Mar 25 06:45:05 katarynka volumio[13432]: info: CorePlayQueue::getTrack 0 Mar 25 06:45:05 katarynka volumio[13432]: info: CoreCommandRouter::volumioPushState Mar 25 06:45:05 katarynka volumio[13432]: info: Setting Device type: Raspberry PI Mar 25 06:45:05 katarynka volumio[13432]: info: Completed loading Core Plugins Mar 25 06:45:05 katarynka volumio[13432]: info: Preparing to generate the ALSA configuration file Mar 25 06:45:05 katarynka volumio[13432]: info: VolumeController:: Volume=96 Mute =false Mar 25 06:45:05 katarynka volumio[13432]: info: CoreStateMachine::pushState Mar 25 06:45:05 katarynka volumio[13432]: info: CorePlayQueue::getTrack 0 Mar 25 06:45:05 katarynka volumio[13432]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 25 06:45:05 katarynka volumio[13432]: info: CoreCommandRouter::volumioPushState Mar 25 06:45:05 katarynka volumio[13432]: info: CoreStateMachine::updateTrackBlock Mar 25 06:45:05 katarynka volumio[13432]: info: CorePlayQueue::getTrackBlock Mar 25 06:45:05 katarynka volumio[13432]: info: CoreCommandRouter::volumioRetrievevolume Mar 25 06:45:05 katarynka volumio[13432]: info: Asound.conf file unchanged, so no further update is needed Mar 25 06:45:05 katarynka volumio[13432]: info: Output device has changed, restarting MPD Mar 25 06:45:06 katarynka volumio[13432]: info: Output device has changed, restarting Shairport Sync Mar 25 06:45:06 katarynka volumio[13432]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 06:45:06 katarynka volumio[13432]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 06:45:06 katarynka sudo[13581]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 25 06:45:06 katarynka sudo[13581]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 06:45:06 katarynka sudo[13583]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 25 06:45:06 katarynka sudo[13583]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 06:45:06 katarynka volumio[13432]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 25 06:45:06 katarynka sudo[13581]: pam_unix(sudo:session): session closed for user root Mar 25 06:45:06 katarynka volumio[13432]: info: ___________ START PLUGINS ___________ Mar 25 06:45:06 katarynka volumio[13432]: info: ControllerMpd::onStart: Initializing MPD Mar 25 06:45:06 katarynka volumio[13432]: info: Creating MPD Configuration file Mar 25 06:45:06 katarynka volumio[13432]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 25 06:45:06 katarynka volumio[13432]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 25 06:45:06 katarynka volumio[13432]: info: [1774417506247] CoreMusicLibrary::Adding element Serwery Mediów Mar 25 06:45:06 katarynka volumio[13432]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 25 06:45:06 katarynka systemd[1]: Stopping mpd.service - Music Player Daemon... Mar 25 06:45:06 katarynka sudo[13591]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 25 06:45:06 katarynka sudo[13591]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 06:45:06 katarynka sudo[13591]: pam_unix(sudo:session): session closed for user root Mar 25 06:45:06 katarynka volumio[13432]: info: UPNP Browser: Client initialized successfully Mar 25 06:45:06 katarynka sudo[13593]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 25 06:45:06 katarynka sudo[13593]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 06:45:06 katarynka volumio[13432]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 06:45:06 katarynka volumio[13432]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 06:45:06 katarynka systemd[1]: mpd.service: Deactivated successfully. Mar 25 06:45:06 katarynka systemd[1]: Stopped mpd.service - Music Player Daemon. Mar 25 06:45:06 katarynka systemd[1]: mpd.service: Consumed 7.641s CPU time. Mar 25 06:45:06 katarynka systemd[1]: mpd.socket: Deactivated successfully. Mar 25 06:45:06 katarynka systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Mar 25 06:45:06 katarynka systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Mar 25 06:45:06 katarynka volumio[13432]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 25 06:45:06 katarynka volumio[13432]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 06:45:06 katarynka volumio[13432]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 06:45:06 katarynka systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Mar 25 06:45:06 katarynka volumio[13432]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 25 06:45:06 katarynka volumio[13432]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 25 06:45:06 katarynka volumio[13432]: info: [1774417506533] CoreMusicLibrary::Adding element Last_100 Mar 25 06:45:06 katarynka volumio[13432]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 25 06:45:06 katarynka systemd[1]: Starting mpd.service - Music Player Daemon... Mar 25 06:45:06 katarynka volumio[13432]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 25 06:45:06 katarynka volumio[13432]: info: [1774417506544] CoreMusicLibrary::Adding element Webradio Mar 25 06:45:06 katarynka volumio[13432]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 25 06:45:06 katarynka systemd[1]: mpd.service: Deactivated successfully. Mar 25 06:45:06 katarynka systemd[1]: Stopped mpd.service - Music Player Daemon. Mar 25 06:45:06 katarynka systemd[1]: mpd.socket: Deactivated successfully. Mar 25 06:45:06 katarynka volumio[13432]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 25 06:45:06 katarynka systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Mar 25 06:45:06 katarynka systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Mar 25 06:45:06 katarynka volumio[13432]: info: Initializing BBC Radios Mar 25 06:45:06 katarynka systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Mar 25 06:45:06 katarynka systemd[1]: Starting mpd.service - Music Player Daemon... Mar 25 06:45:06 katarynka volumio[13432]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 25 06:45:06 katarynka volumio[13432]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 06:45:06 katarynka volumio[13432]: info: Creating Spotify config file Mar 25 06:45:06 katarynka volumio[13432]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 06:45:07 katarynka sudo[13608]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Mar 25 06:45:07 katarynka sudo[13608]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Mar 25 06:45:07 katarynka sudo[13608]: pam_unix(sudo:session): session closed for user root Mar 25 06:45:07 katarynka volumio-remote-updater[622]: [2026-03-25 06:45:07] [connect] Successful connection Mar 25 06:45:08 katarynka volumio[13432]: info: Volumio Calling Home Mar 25 06:45:08 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Mar 25 06:45:08 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 06:45:08 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 06:45:08 katarynka go-librespot[13641]: go-librespot daemon starting... Mar 25 06:45:08 katarynka go-librespot[13642]: time="2026-03-25T06:45:08+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 06:45:09 katarynka volumio[13432]: info: Discovery: adding 4d616d77-6a8c-4da2-85a4-840d70f98e51 Mar 25 06:45:09 katarynka volumio[13432]: info: Discovery: Found device katarynka Mar 25 06:45:09 katarynka sudo[13650]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 25 06:45:09 katarynka sudo[13650]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 06:45:09 katarynka sudo[13650]: pam_unix(sudo:session): session closed for user root Mar 25 06:45:09 katarynka volumio[13432]: info: CoreCommandRouter::volumioGetState Mar 25 06:45:09 katarynka volumio[13432]: info: CorePlayQueue::getTrack 0 Mar 25 06:45:09 katarynka sudo[13652]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 25 06:45:09 katarynka sudo[13652]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 06:45:09 katarynka sudo[13652]: pam_unix(sudo:session): session closed for user root Mar 25 06:45:09 katarynka volumio[13432]: info: Discovery: this is already registered, 4d616d77-6a8c-4da2-85a4-840d70f98e51 Mar 25 06:45:09 katarynka volumio[13432]: info: Discovery: Found device katarynka Mar 25 06:45:09 katarynka volumio[13432]: info: CoreCommandRouter::volumioGetState Mar 25 06:45:09 katarynka volumio[13432]: info: CorePlayQueue::getTrack 0 Mar 25 06:45:09 katarynka go-librespot[13642]: time="2026-03-25T06:45:09+01:00" level=info msg="zeroconf server listening on port 34841" Mar 25 06:45:09 katarynka volumio[13432]: info: MPD Permissions set Mar 25 06:45:09 katarynka volumio[13432]: info: MPD Permissions set Mar 25 06:45:09 katarynka volumio[13432]: info: VolumeController:: Volume=96 Mute =false Mar 25 06:45:09 katarynka volumio[13432]: info: CoreStateMachine::pushState Mar 25 06:45:09 katarynka volumio[13432]: info: CorePlayQueue::getTrack 0 Mar 25 06:45:09 katarynka volumio[13432]: info: CoreCommandRouter::volumioPushState Mar 25 06:45:09 katarynka volumio-remote-updater[622]: [2026-03-25 06:45:09] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1774417507 101 Mar 25 06:45:09 katarynka volumio[13432]: 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 25 06:45:09 katarynka volumio[13432]: info: Volumio called home Mar 25 06:45:09 katarynka volumio[13432]: info: Spotify config file written Mar 25 06:45:09 katarynka sudo[13656]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Mar 25 06:45:09 katarynka sudo[13656]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 06:45:09 katarynka volumio[13432]: 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 25 06:45:09 katarynka systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Mar 25 06:45:09 katarynka systemd[1]: go-librespot-daemon.service: Deactivated successfully. Mar 25 06:45:09 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 06:45:09 katarynka volumio[13547]: Starting albumart workers Mar 25 06:45:09 katarynka volumio[13432]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 06:45:09 katarynka volumio[13432]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 06:45:09 katarynka volumio[13432]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 06:45:09 katarynka volumio[13432]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 06:45:09 katarynka volumio[13432]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 06:45:09 katarynka volumio[13432]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 06:45:09 katarynka volumio[13432]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 06:45:09 katarynka volumio[13432]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 06:45:09 katarynka volumio[13548]: Starting albumart workers Mar 25 06:45:09 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 06:45:09 katarynka go-librespot[13658]: go-librespot daemon starting... Mar 25 06:45:09 katarynka sudo[13656]: pam_unix(sudo:session): session closed for user root Mar 25 06:45:10 katarynka volumio[13432]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 06:45:10 katarynka volumio[13432]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 06:45:10 katarynka go-librespot[13661]: time="2026-03-25T06:45:10+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 06:45:10 katarynka go-librespot[13661]: time="2026-03-25T06:45:10+01:00" level=debug msg="app state loaded" Mar 25 06:45:10 katarynka go-librespot[13661]: time="2026-03-25T06:45:10+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 06:45:10 katarynka volumio[13432]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 06:45:10 katarynka volumio[13432]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 06:45:10 katarynka volumio[13432]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 06:45:10 katarynka volumio[13432]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 06:45:10 katarynka volumio[13432]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 06:45:10 katarynka volumio[13432]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 06:45:10 katarynka volumio[13432]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 06:45:10 katarynka volumio[13432]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 06:45:10 katarynka volumio[13432]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 06:45:10 katarynka volumio[13432]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 06:45:10 katarynka volumio[13432]: info: No need to fix Spotify hosts Mar 25 06:45:10 katarynka volumio[13546]: Starting albumart workers Mar 25 06:45:10 katarynka go-librespot[13661]: time="2026-03-25T06:45: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 25 06:45:10 katarynka go-librespot[13661]: time="2026-03-25T06:45:10+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 25 06:45:10 katarynka go-librespot[13661]: time="2026-03-25T06:45:10+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 25 06:45:10 katarynka go-librespot[13661]: time="2026-03-25T06:45:10+01:00" level=info msg="zeroconf server listening on port 41197" Mar 25 06:45:10 katarynka go-librespot[13661]: time="2026-03-25T06:45:10+01:00" level=debug msg="obtained new client token: AAD7xwYFXjWnUn2W8Cn25epqsoFHTBgr5N2rWNUZ/Z9NfMiZavUCymdfiPFto2f1rRsazDpLm+9F9Sm/5S0gqOudjr98h3LMdqDrJRGVeQuDtphsnSrhPl1KCtDm3BJyKl49xyEP9eVzHNoPPo6fH90bo2XHZ4HFqJtHtEinCN6ijaUn7+Fd8Q6d8IGDdg5hgQPJN68SMHta8M1nsD2ApSFhXvBXf6XQlYSVIEq5OQvHO2rcMMKwB+Xy1lc=" Mar 25 06:45:10 katarynka go-librespot[13661]: time="2026-03-25T06:45:10+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 25 06:45:10 katarynka go-librespot[13661]: time="2026-03-25T06:45:10+01:00" level=debug msg="connected to ap-gew4.spotify.com:443" Mar 25 06:45:10 katarynka go-librespot[13661]: time="2026-03-25T06:45:10+01:00" level=debug msg="completed keyexchange" Mar 25 06:45:10 katarynka go-librespot[13661]: time="2026-03-25T06:45:10+01:00" level=debug msg="completed challenge" Mar 25 06:45:11 katarynka go-librespot[13661]: time="2026-03-25T06:45:11+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 25 06:45:11 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 06:45:11 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 06:45:11 katarynka volumio[13432]: info: Starting Shairport Sync Mar 25 06:45:11 katarynka volumio[13432]: info: Starting Shairport Sync Mar 25 06:45:11 katarynka volumio[13432]: info: Starting Shairport Sync Mar 25 06:45:11 katarynka sudo[13678]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 25 06:45:11 katarynka sudo[13678]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 06:45:11 katarynka sudo[13680]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 25 06:45:11 katarynka sudo[13680]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 06:45:11 katarynka systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Mar 25 06:45:11 katarynka systemd[1]: shairport-sync.service: Deactivated successfully. Mar 25 06:45:11 katarynka systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 25 06:45:11 katarynka systemd[1]: shairport-sync.service: Consumed 2.379s CPU time. Mar 25 06:45:11 katarynka sudo[13682]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 25 06:45:11 katarynka sudo[13682]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 06:45:11 katarynka systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 25 06:45:11 katarynka sudo[13678]: pam_unix(sudo:session): session closed for user root Mar 25 06:45:11 katarynka sudo[13685]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Mar 25 06:45:11 katarynka sudo[13685]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 06:45:11 katarynka systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Mar 25 06:45:11 katarynka systemd[1]: shairport-sync.service: Deactivated successfully. Mar 25 06:45:11 katarynka systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 25 06:45:11 katarynka systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 25 06:45:11 katarynka sudo[13682]: pam_unix(sudo:session): session closed for user root Mar 25 06:45:11 katarynka sudo[13680]: pam_unix(sudo:session): session closed for user root Mar 25 06:45:11 katarynka sudo[13685]: pam_unix(sudo:session): session closed for user root Mar 25 06:45:11 katarynka volumio[13432]: info: Shairport-Sync Started Mar 25 06:45:12 katarynka volumio[13432]: Error adding Membership: Error: addMembership EINVAL Mar 25 06:45:12 katarynka volumio[13432]: info: An error occurred while refreshing Spotify Token Error: Bad Request Mar 25 06:45:12 katarynka volumio[13432]: info: Upmpdcli Daemon Started Mar 25 06:45:12 katarynka volumio[13432]: info: Shairport-Sync Started Mar 25 06:45:12 katarynka volumio[13432]: info: Shairport-Sync Started Mar 25 06:45:12 katarynka volumio[13432]: info: CoreCommandRouter::volumioGetState Mar 25 06:45:12 katarynka volumio[13432]: info: CorePlayQueue::getTrack 0 Mar 25 06:45:14 katarynka volumio[13432]: info: go-librespot daemon successfully initialized Mar 25 06:45:14 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Mar 25 06:45:14 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 06:45:14 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 06:45:14 katarynka go-librespot[13724]: go-librespot daemon starting... Mar 25 06:45:14 katarynka go-librespot[13725]: time="2026-03-25T06:45:14+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 06:45:14 katarynka go-librespot[13725]: time="2026-03-25T06:45:14+01:00" level=debug msg="app state loaded" Mar 25 06:45:14 katarynka go-librespot[13725]: time="2026-03-25T06:45:14+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 06:45:14 katarynka go-librespot[13725]: time="2026-03-25T06:45: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-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 25 06:45:14 katarynka go-librespot[13725]: time="2026-03-25T06:45:14+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 25 06:45:14 katarynka go-librespot[13725]: time="2026-03-25T06:45:14+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 25 06:45:14 katarynka go-librespot[13725]: time="2026-03-25T06:45:14+01:00" level=info msg="zeroconf server listening on port 45609" Mar 25 06:45:14 katarynka go-librespot[13725]: time="2026-03-25T06:45:14+01:00" level=debug msg="obtained new client token: AADK0si7Pmsoi0Pydt/1Zqf/DFLRtjBfPH+dpJFAqHiwYNwHdN7RYp1JHAyZI1t42wggtN8KWuC06AlRpa80ZBoQIvNQwCmszmcnBjyX6VUTAyVt3jVyMEnJQwqUMHrd+ZyC2dXPtOWJy0KutAu/wNlJA2OVwK4X282UwSV17uoKy8jlgjxqMS41/Fo1sIWINshg0Mw6pKaywRY9yaC4cJd1TDHNUi0OJBRAyif0SAaj/3wiqWfGKT0l4p0=" Mar 25 06:45:14 katarynka mpd[13623]: 2026-03-25T06:45:14 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Mar 25 06:45:14 katarynka systemd[1]: Started mpd.service - Music Player Daemon. Mar 25 06:45:14 katarynka sudo[13583]: pam_unix(sudo:session): session closed for user root Mar 25 06:45:14 katarynka go-librespot[13725]: time="2026-03-25T06:45:14+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 06:45:14 katarynka sudo[13593]: pam_unix(sudo:session): session closed for user root Mar 25 06:45:14 katarynka volumio[13432]: info: Completed starting Core Plugins Mar 25 06:45:14 katarynka volumio[13432]: info: ------------------------------------------- Mar 25 06:45:14 katarynka volumio[13432]: info: ----- MyVolumio plugins startup ---- Mar 25 06:45:14 katarynka volumio[13432]: info: ------------------------------------------- Mar 25 06:45:14 katarynka volumio[13432]: info: [MyVolumio PluginManager] Fetching plans data.... Mar 25 06:45:15 katarynka go-librespot[13725]: time="2026-03-25T06:45:15+01:00" level=debug msg="completed keyexchange" Mar 25 06:45:15 katarynka go-librespot[13725]: time="2026-03-25T06:45:15+01:00" level=debug msg="completed challenge" Mar 25 06:45:15 katarynka go-librespot[13725]: time="2026-03-25T06:45: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 25 06:45:15 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 06:45:15 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 06:45:15 katarynka volumio[13432]: error: MPD error: The expression evaluated to a falsy value: Mar 25 06:45:15 katarynka volumio[13432]: assert.ok(self.idling) Mar 25 06:45:15 katarynka volumio[13432]: error: The expression evaluated to a falsy value: Mar 25 06:45:15 katarynka volumio[13432]: assert.ok(self.idling) Mar 25 06:45:15 katarynka volumio[13432]: error: updateQueue error: null Mar 25 06:45:15 katarynka volumio[13432]: info: MPD running with PID13623 Mar 25 06:45:15 katarynka volumio[13432]: ,establishing connection Mar 25 06:45:15 katarynka volumio[13432]: error: updateQueue error: null Mar 25 06:45:17 katarynka volumio[13432]: info: Initializing connection to go-librespot Websocket Mar 25 06:45:17 katarynka volumio[13432]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 25 06:45:17 katarynka sudo[13755]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Mar 25 06:45:18 katarynka sudo[13755]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 06:45:18 katarynka sudo[13757]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Mar 25 06:45:18 katarynka sudo[13757]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 06:45:18 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Mar 25 06:45:18 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 06:45:18 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 06:45:18 katarynka go-librespot[13760]: go-librespot daemon starting... Mar 25 06:45:18 katarynka systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Mar 25 06:45:18 katarynka systemd[1]: mpd_monitor.service: Deactivated successfully. Mar 25 06:45:18 katarynka systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Mar 25 06:45:18 katarynka go-librespot[13761]: time="2026-03-25T06:45:18+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 06:45:18 katarynka go-librespot[13761]: time="2026-03-25T06:45:18+01:00" level=debug msg="app state loaded" Mar 25 06:45:18 katarynka systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Mar 25 06:45:18 katarynka go-librespot[13761]: time="2026-03-25T06:45:18+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 06:45:18 katarynka sudo[13757]: pam_unix(sudo:session): session closed for user root Mar 25 06:45:18 katarynka sudo[13755]: pam_unix(sudo:session): session closed for user root Mar 25 06:45:18 katarynka volumio[13432]: info: Successfully started MPD Monitor Mar 25 06:45:18 katarynka volumio[13432]: info: Successfully started MPD Monitor Mar 25 06:45:18 katarynka mpd_monitor.sh[13767]: MPD Monitor Service: Starting MPD Monitor Service Mar 25 06:45:18 katarynka go-librespot[13761]: time="2026-03-25T06:45:18+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 25 06:45:18 katarynka go-librespot[13761]: time="2026-03-25T06:45:18+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 25 06:45:18 katarynka go-librespot[13761]: time="2026-03-25T06:45:18+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 25 06:45:18 katarynka go-librespot[13761]: time="2026-03-25T06:45:18+01:00" level=info msg="zeroconf server listening on port 44195" Mar 25 06:45:18 katarynka go-librespot[13761]: time="2026-03-25T06:45:18+01:00" level=debug msg="obtained new client token: AADPXQifCihWZSolsLs/fsowHm+HVc08ZiYEKyFKic6v8Fa3y9k8MkdQLutsY+xQdVJfMERysjC5YzciehZUH0J3CjSnDI0H2576O2/mSurV8dJzp3QL0t5Svo0vwiRhX1mPXf94odKRWttPBXVp+/8e5SYd2c9hyMWDndykc7SqGpk/ztmyvfPUybbmXNd1fyC+cRiT9bKnRrquzeKjIG2CNpyvltgDRA8YWcbdMpSP3sbVK0x+nbXaXXU=" Mar 25 06:45:19 katarynka go-librespot[13761]: time="2026-03-25T06:45:19+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 06:45:19 katarynka go-librespot[13761]: time="2026-03-25T06:45:19+01:00" level=debug msg="completed keyexchange" Mar 25 06:45:19 katarynka go-librespot[13761]: time="2026-03-25T06:45:19+01:00" level=debug msg="completed challenge" Mar 25 06:45:19 katarynka go-librespot[13761]: time="2026-03-25T06:45:19+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 25 06:45:19 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 06:45:19 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 06:45:20 katarynka volumio[13432]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Mar 25 06:45:20 katarynka volumio[13432]: info: Initializing connection to go-librespot Websocket Mar 25 06:45:20 katarynka volumio[13432]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 25 06:45:22 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Mar 25 06:45:22 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 06:45:22 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 06:45:22 katarynka go-librespot[13772]: go-librespot daemon starting... Mar 25 06:45:23 katarynka go-librespot[13773]: time="2026-03-25T06:45:23+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 06:45:23 katarynka go-librespot[13773]: time="2026-03-25T06:45:23+01:00" level=debug msg="app state loaded" Mar 25 06:45:23 katarynka go-librespot[13773]: time="2026-03-25T06:45:23+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 06:45:23 katarynka volumio[13432]: info: Initializing connection to go-librespot Websocket Mar 25 06:45:23 katarynka go-librespot[13773]: time="2026-03-25T06:45:23+01:00" level=debug msg="new websocket client" Mar 25 06:45:23 katarynka volumio[13432]: info: Connection to go-librespot Websocket established Mar 25 06:45:23 katarynka volumio[13432]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Mar 25 06:45:23 katarynka volumio[13432]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Mar 25 06:45:23 katarynka volumio[13432]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Mar 25 06:45:23 katarynka volumio[13432]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Mar 25 06:45:23 katarynka volumio[13432]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Mar 25 06:45:23 katarynka volumio[13432]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Mar 25 06:45:23 katarynka volumio[13432]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Mar 25 06:45:23 katarynka volumio[13432]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Mar 25 06:45:23 katarynka volumio[13432]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Mar 25 06:45:23 katarynka volumio[13432]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Mar 25 06:45:23 katarynka volumio[13432]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Mar 25 06:45:23 katarynka volumio[13432]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Mar 25 06:45:23 katarynka volumio[13432]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Mar 25 06:45:23 katarynka volumio[13432]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Mar 25 06:45:23 katarynka volumio[13432]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Mar 25 06:45:23 katarynka volumio[13432]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Mar 25 06:45:23 katarynka volumio[13432]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Mar 25 06:45:23 katarynka volumio[13432]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Mar 25 06:45:23 katarynka volumio[13432]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Mar 25 06:45:23 katarynka volumio[13432]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Mar 25 06:45:23 katarynka volumio[13432]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Mar 25 06:45:23 katarynka volumio[13432]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Mar 25 06:45:23 katarynka volumio[13432]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Mar 25 06:45:23 katarynka volumio[13432]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Mar 25 06:45:23 katarynka volumio[13432]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Mar 25 06:45:23 katarynka volumio[13432]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Mar 25 06:45:23 katarynka volumio[13432]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Mar 25 06:45:23 katarynka volumio[13432]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Mar 25 06:45:23 katarynka volumio[13432]: info: Adding plugin bluetooth to MyMusic Plugins Mar 25 06:45:23 katarynka volumio[13432]: info: Adding plugin multiroom to MyMusic Plugins Mar 25 06:45:23 katarynka volumio[13432]: info: Adding plugin metavolumio to MyMusic Plugins Mar 25 06:45:23 katarynka go-librespot[13773]: time="2026-03-25T06:45:23+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 25 06:45:23 katarynka go-librespot[13773]: time="2026-03-25T06:45:23+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 25 06:45:23 katarynka go-librespot[13773]: time="2026-03-25T06:45:23+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 25 06:45:23 katarynka volumio[13432]: info: Adding plugin cd_controller to MyMusic Plugins Mar 25 06:45:23 katarynka volumio[13432]: info: Adding plugin qobuzconnect to MyMusic Plugins Mar 25 06:45:23 katarynka volumio[13432]: info: Adding plugin smart_inputs to MyMusic Plugins Mar 25 06:45:23 katarynka volumio[13432]: info: Adding plugin tidalconnect to MyMusic Plugins Mar 25 06:45:23 katarynka volumio[13432]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Mar 25 06:45:23 katarynka go-librespot[13773]: time="2026-03-25T06:45:23+01:00" level=info msg="zeroconf server listening on port 37099" Mar 25 06:45:23 katarynka go-librespot[13773]: time="2026-03-25T06:45:23+01:00" level=debug msg="obtained new client token: AADC9rOsa+pmUjX2z/0vcqZ1X25dEMTL5UTTL6Stt3jyZT139LN+xHbp2Y9p1ZDT0MyUbKAOtZXx7B2vXfGbZ91ijHrfZ3sJv1soVPHTwHV9vn+vhE3UPu/IM+I8h9+l6c8e38LFWoPJ0aZUeXxUngZho07jPmBBu8iVoB2k7Qz6238pyr9xap7C73W3cUQwHkXJYPTIHrkjjh8hFbUtmOcVYr3XVpAXEaLehc3FypCPqVzzXTUyW1cgZ7E=" Mar 25 06:45:23 katarynka go-librespot[13773]: time="2026-03-25T06:45:23+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 06:45:23 katarynka go-librespot[13773]: time="2026-03-25T06:45:23+01:00" level=debug msg="completed keyexchange" Mar 25 06:45:23 katarynka go-librespot[13773]: time="2026-03-25T06:45:23+01:00" level=debug msg="completed challenge" Mar 25 06:45:23 katarynka go-librespot[13773]: time="2026-03-25T06:45:23+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 25 06:45:23 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 06:45:23 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 06:45:25 katarynka volumio[13432]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Mar 25 06:45:25 katarynka volumio[13432]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Mar 25 06:45:25 katarynka volumio[13432]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 06:45:25 katarynka volumio[13432]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 06:45:25 katarynka volumio[13432]: info: Starting MyVolumio Remote Streaming Endpoints Mar 25 06:45:25 katarynka volumio[13432]: info: MyVolumio login type: Token Mar 25 06:45:25 katarynka volumio[13432]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Mar 25 06:45:25 katarynka volumio[13432]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Mar 25 06:45:26 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Mar 25 06:45:26 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 06:45:26 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 06:45:26 katarynka go-librespot[13780]: go-librespot daemon starting... Mar 25 06:45:27 katarynka go-librespot[13781]: time="2026-03-25T06:45:27+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 06:45:27 katarynka go-librespot[13781]: time="2026-03-25T06:45:27+01:00" level=debug msg="app state loaded" Mar 25 06:45:27 katarynka go-librespot[13781]: time="2026-03-25T06:45:27+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 06:45:27 katarynka volumio[13432]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Mar 25 06:45:27 katarynka volumio[13432]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Mar 25 06:45:27 katarynka volumio[13432]: info: Streaming services startup Mar 25 06:45:27 katarynka volumio[13432]: info: Starting Streaming Daemon Mar 25 06:45:27 katarynka go-librespot[13781]: time="2026-03-25T06:45:27+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 25 06:45:27 katarynka go-librespot[13781]: time="2026-03-25T06:45:27+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 25 06:45:27 katarynka go-librespot[13781]: time="2026-03-25T06:45:27+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 25 06:45:27 katarynka sudo[13789]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Mar 25 06:45:27 katarynka sudo[13789]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 06:45:27 katarynka volumio[13432]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Mar 25 06:45:27 katarynka go-librespot[13781]: time="2026-03-25T06:45:27+01:00" level=info msg="zeroconf server listening on port 42495" Mar 25 06:45:27 katarynka sudo[13789]: pam_unix(sudo:session): session closed for user root Mar 25 06:45:27 katarynka go-librespot[13781]: time="2026-03-25T06:45:27+01:00" level=debug msg="obtained new client token: AABitxDiuvHrr/hmokNSNmhT3Vtn1IfShJdjBinzvGSA2ravLKPdTOUco1RLXatKqOGzBCaVFubVNSe2pfHSaQKdFyRan7EhW1kt+HJe1bN41uTnb1VS49Z8X36O/dNJ0ayzM4p63xt9j/UFIrzQViw60W96ryEoREElIQcxchv6ZKk/+knYB3O7HAU3bjNnK+XQjKuOqOxC24TxyoPONjISHnzMn8lAcH9hq9O1Kf1D8l90MdIsC+rD2HE=" Mar 25 06:45:27 katarynka volumio[13432]: info: Getting Spotify volume Mar 25 06:45:27 katarynka volumio[13432]: info: Connection to go-librespot Websocket closed Mar 25 06:45:27 katarynka volumio[13432]: error: Cannot start Volumio Streaming Daemon Mar 25 06:45:27 katarynka volumio[13432]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Mar 25 06:45:27 katarynka volumio[13432]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Mar 25 06:45:27 katarynka go-librespot[13781]: time="2026-03-25T06:45:27+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 06:45:27 katarynka volumio[13432]: 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 25 06:45:27 katarynka go-librespot[13781]: time="2026-03-25T06:45:27+01:00" level=debug msg="completed keyexchange" Mar 25 06:45:27 katarynka go-librespot[13781]: time="2026-03-25T06:45:27+01:00" level=debug msg="completed challenge" Mar 25 06:45:27 katarynka go-librespot[13781]: time="2026-03-25T06:45:27+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 25 06:45:27 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 06:45:27 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 06:45:27 katarynka volumio[13432]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 25 06:45:27 katarynka volumio[13432]: Error: socket hang up Mar 25 06:45:27 katarynka volumio[13432]: at connResetException (node:internal/errors:720:14) Mar 25 06:45:27 katarynka volumio[13432]: at Socket.socketOnEnd (node:_http_client:519:23) Mar 25 06:45:27 katarynka volumio[13432]: at Socket.emit (node:events:526:35) Mar 25 06:45:27 katarynka volumio[13432]: at endReadableNT (node:internal/streams/readable:1376:12) Mar 25 06:45:27 katarynka volumio[13432]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Mar 25 06:45:27 katarynka volumio[13432]: code: 'ECONNRESET', Mar 25 06:45:27 katarynka volumio[13432]: response: undefined Mar 25 06:45:27 katarynka volumio[13432]: } Mar 25 06:45:27 katarynka volumio[13432]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 25 06:45:29 katarynka sudo[13824]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-03-25 06:44' Mar 25 06:45:29 katarynka sudo[13824]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 06:45:29 katarynka sudo[13824]: pam_unix(sudo:session): session closed for user root Mar 25 06:45:30 katarynka volumio-remote-updater[622]: [2026-03-25 06:45:30] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Mar 25 06:45:30 katarynka volumio-remote-updater[622]: [2026-03-25 06:45:30] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Mar 25 06:45:30 katarynka systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Mar 25 06:45:30 katarynka systemd[1]: volumio.service: Failed with result 'exit-code'. Mar 25 06:45:30 katarynka systemd[1]: volumio.service: Consumed 48.984s CPU time. Mar 25 06:45:30 katarynka systemd[1]: Started dynamicswap.service - dynamicswap service. Mar 25 06:45:30 katarynka systemd[1]: dynamicswap.service: Deactivated successfully. Mar 25 06:45:30 katarynka systemd[1]: volumio.service: Scheduled restart job, restart counter is at 26033. Mar 25 06:45:30 katarynka systemd[1]: Started dynamicswap.service - dynamicswap service. Mar 25 06:45:30 katarynka systemd[1]: Stopped volumio.service - Volumio Backend Module. Mar 25 06:45:30 katarynka systemd[1]: volumio.service: Consumed 48.984s CPU time. Mar 25 06:45:30 katarynka systemd[1]: Started volumio.service - Volumio Backend Module. Mar 25 06:45:30 katarynka systemd[1]: dynamicswap.service: Deactivated successfully. Mar 25 06:45:30 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Mar 25 06:45:30 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 06:45:30 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 06:45:30 katarynka go-librespot[13854]: go-librespot daemon starting... Mar 25 06:45:31 katarynka go-librespot[13855]: time="2026-03-25T06:45:31+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 06:45:31 katarynka go-librespot[13855]: time="2026-03-25T06:45:31+01:00" level=debug msg="app state loaded" Mar 25 06:45:31 katarynka go-librespot[13855]: time="2026-03-25T06:45:31+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 06:45:31 katarynka go-librespot[13855]: time="2026-03-25T06:45:31+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 25 06:45:31 katarynka go-librespot[13855]: time="2026-03-25T06:45:31+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 25 06:45:31 katarynka go-librespot[13855]: time="2026-03-25T06:45:31+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 25 06:45:31 katarynka go-librespot[13855]: time="2026-03-25T06:45:31+01:00" level=info msg="zeroconf server listening on port 34611" Mar 25 06:45:31 katarynka go-librespot[13855]: time="2026-03-25T06:45:31+01:00" level=debug msg="obtained new client token: AADcPMh3n5W4GByqC1pn/Xa6WAUFI7Ru5JlAg9ko0hCiRYY3AzMFWyohWhx/8kequtUUWQY826ANXT1aaHTzbSRoQoMfwtV42imHnGm1K1zsBbAOXnZ19AuiDIMMasqjcCB+K4wYgKZxwg02+wuaIEMFphRLerwv5NCn97/I73pCvjh00dHb7Gzwrw+pI7FYQUQsWcGlLGAYzQ6lvzN/ks/+u8JxIq9iUOjiYVkFjJstipuGLNzl6EweqbU=" Mar 25 06:45:31 katarynka go-librespot[13855]: time="2026-03-25T06:45:31+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 06:45:31 katarynka go-librespot[13855]: time="2026-03-25T06:45:31+01:00" level=debug msg="completed keyexchange" Mar 25 06:45:31 katarynka go-librespot[13855]: time="2026-03-25T06:45:31+01:00" level=debug msg="completed challenge" Mar 25 06:45:31 katarynka go-librespot[13855]: time="2026-03-25T06:45:31+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 25 06:45:31 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 06:45:31 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 06:45:34 katarynka volumio[13839]: info: ------------------------------------------- Mar 25 06:45:34 katarynka volumio[13839]: info: ----- Volumio3 ---- Mar 25 06:45:34 katarynka volumio[13839]: info: ------------------------------------------- Mar 25 06:45:34 katarynka volumio[13839]: info: ----- System startup ---- Mar 25 06:45:34 katarynka volumio[13839]: info: ------------------------------------------- Mar 25 06:45:34 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Mar 25 06:45:34 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 06:45:34 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 06:45:34 katarynka go-librespot[13868]: go-librespot daemon starting... Mar 25 06:45:35 katarynka go-librespot[13869]: time="2026-03-25T06:45:35+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 06:45:35 katarynka go-librespot[13869]: time="2026-03-25T06:45:35+01:00" level=debug msg="app state loaded" Mar 25 06:45:35 katarynka go-librespot[13869]: time="2026-03-25T06:45:35+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 06:45:35 katarynka volumio-remote-updater[622]: [2026-03-25 06:45:35] [connect] Successful connection Mar 25 06:45:35 katarynka go-librespot[13869]: time="2026-03-25T06:45:35+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 25 06:45:35 katarynka go-librespot[13869]: time="2026-03-25T06:45:35+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 25 06:45:35 katarynka go-librespot[13869]: time="2026-03-25T06:45:35+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 25 06:45:35 katarynka go-librespot[13869]: time="2026-03-25T06:45:35+01:00" level=info msg="zeroconf server listening on port 38259" Mar 25 06:45:35 katarynka go-librespot[13869]: time="2026-03-25T06:45:35+01:00" level=debug msg="obtained new client token: AABTfuKMCXgGfsZ6XhtBxcgZVxttu4S62ujz6IfXVe2CddgvfMc0BYqdKkejPVKP030yMiwOxRtxIn0h3G9KzUtsm4PtDygo5v31oPc8AEEpbCOo5L/yajEKurSLHrlT30oIOWObRS7XfMor8KN25+N7dlPZbBgMckbW/dyPtnCZJlyzxdQE2UfTwMcrOD8g0E3TwWMyzDPI0/S0ncRZXB7OL5ebDWA67y/mj09c/Du3Lg3PvDhpTaxbUe8=" Mar 25 06:45:35 katarynka go-librespot[13869]: time="2026-03-25T06:45:35+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 25 06:45:35 katarynka go-librespot[13869]: time="2026-03-25T06:45:35+01:00" level=debug msg="connected to ap-gew4.spotify.com:443" Mar 25 06:45:35 katarynka volumio[13839]: info: MYVOLUMIO Environment detected Mar 25 06:45:35 katarynka go-librespot[13869]: time="2026-03-25T06:45:35+01:00" level=debug msg="completed keyexchange" Mar 25 06:45:35 katarynka go-librespot[13869]: time="2026-03-25T06:45:35+01:00" level=debug msg="completed challenge" Mar 25 06:45:35 katarynka go-librespot[13869]: time="2026-03-25T06:45:35+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 25 06:45:35 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 06:45:35 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 06:45:35 katarynka volumio[13839]: info: Plugin folders cleanup Mar 25 06:45:35 katarynka volumio[13839]: info: Scanning into folder /volumio/app/plugins/ Mar 25 06:45:35 katarynka volumio[13839]: info: Scanning category audio_interface Mar 25 06:45:35 katarynka volumio[13839]: info: Scanning category miscellanea Mar 25 06:45:36 katarynka volumio[13839]: info: Scanning category music_service Mar 25 06:45:36 katarynka volumio[13839]: info: Scanning category plugins.json Mar 25 06:45:36 katarynka volumio[13839]: info: Scanning category system_controller Mar 25 06:45:36 katarynka volumio[13839]: info: Scanning category user_interface Mar 25 06:45:36 katarynka volumio[13839]: info: Scanning into folder /data/plugins/ Mar 25 06:45:36 katarynka volumio[13839]: info: Scanning category music_service Mar 25 06:45:36 katarynka volumio[13839]: info: Plugin folders cleanup completed Mar 25 06:45:36 katarynka volumio[13839]: info: ------------------------------------------- Mar 25 06:45:36 katarynka volumio[13839]: info: ----- Core plugins startup ---- Mar 25 06:45:36 katarynka volumio[13839]: info: ------------------------------------------- Mar 25 06:45:36 katarynka volumio[13839]: info: Loading plugins from folder /volumio/app/plugins/ Mar 25 06:45:36 katarynka volumio[13839]: info: Adding plugin upnp to MyMusic Plugins Mar 25 06:45:36 katarynka volumio[13839]: info: Adding plugin airplay_emulation to MyMusic Plugins Mar 25 06:45:36 katarynka volumio[13839]: info: Adding plugin upnp_browser to MyMusic Plugins Mar 25 06:45:36 katarynka volumio[13839]: info: Loading plugins from folder /data/plugins/ Mar 25 06:45:36 katarynka volumio[13839]: info: Loading plugin "system"... Mar 25 06:45:36 katarynka volumio[13839]: info: Loading plugin "appearance"... Mar 25 06:45:38 katarynka volumio[13839]: info: Loading plugin "network"... Mar 25 06:45:38 katarynka volumio[13839]: info: Refreshing Cached IP Addresses Mar 25 06:45:38 katarynka sudo[13883]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 25 06:45:38 katarynka sudo[13883]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 06:45:38 katarynka sudo[13885]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 25 06:45:38 katarynka sudo[13885]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 06:45:38 katarynka sudo[13883]: pam_unix(sudo:session): session closed for user root Mar 25 06:45:38 katarynka sudo[13885]: pam_unix(sudo:session): session closed for user root Mar 25 06:45:38 katarynka volumio[13839]: info: Loading plugin "services"... Mar 25 06:45:38 katarynka volumio[13839]: info: Loading plugin "alsa_controller"... Mar 25 06:45:38 katarynka sudo[13892]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Mar 25 06:45:38 katarynka sudo[13892]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 06:45:38 katarynka volumio[13839]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 25 06:45:38 katarynka volumio[13839]: info: Loading plugin "wizard"... Mar 25 06:45:38 katarynka volumio[13839]: info: Loading plugin "networkfs"... Mar 25 06:45:38 katarynka volumio[13839]: info: Starting Udev Watcher for removable devices Mar 25 06:45:38 katarynka volumio[13839]: info: Ignoring mount for partition: boot Mar 25 06:45:38 katarynka volumio[13839]: info: Ignoring mount for partition: volumio Mar 25 06:45:38 katarynka volumio[13839]: info: Ignoring mount for partition: volumio_data Mar 25 06:45:38 katarynka volumio[13839]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 25 06:45:38 katarynka volumio[13839]: info: Loading plugin "volumio_command_line_client"... Mar 25 06:45:38 katarynka volumio[13839]: info: Loading plugin "upnp"... Mar 25 06:45:38 katarynka volumio[13839]: info: [1774417538580] Starting Upmpd Daemon Mar 25 06:45:38 katarynka volumio[13839]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 25 06:45:38 katarynka volumio[13839]: info: Loading plugin "my_music"... Mar 25 06:45:38 katarynka volumio[13839]: info: Loading plugin "mpd"... Mar 25 06:45:39 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Mar 25 06:45:39 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 06:45:39 katarynka sudo[13892]: pam_unix(sudo:session): session closed for user root Mar 25 06:45:39 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 06:45:39 katarynka go-librespot[13919]: go-librespot daemon starting... Mar 25 06:45:39 katarynka volumio[13839]: info: Loading plugin "upnp_browser"... Mar 25 06:45:39 katarynka go-librespot[13920]: time="2026-03-25T06:45:39+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 06:45:39 katarynka go-librespot[13920]: time="2026-03-25T06:45:39+01:00" level=debug msg="app state loaded" Mar 25 06:45:39 katarynka go-librespot[13920]: time="2026-03-25T06:45:39+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 06:45:39 katarynka go-librespot[13920]: time="2026-03-25T06:45:39+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 25 06:45:39 katarynka go-librespot[13920]: time="2026-03-25T06:45:39+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 25 06:45:39 katarynka go-librespot[13920]: time="2026-03-25T06:45:39+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 25 06:45:39 katarynka go-librespot[13920]: time="2026-03-25T06:45:39+01:00" level=info msg="zeroconf server listening on port 43717" Mar 25 06:45:39 katarynka go-librespot[13920]: time="2026-03-25T06:45:39+01:00" level=debug msg="obtained new client token: AACjKv8CGIZkIo0ORTlNdM6pnNyeR8dLbKT3aTG2baasoo2PpiDbU77fP7OmV5bYOR/hhNA92yu4QyuQiYL8GA4ZqM7lDWUMFTpc6tAnf3fKREvBEVTm8nWzL+18ROpdH91+zM1cxFJcOtw9sosa5yINiXSKDD2XgJwbLQgP6+IOpKOG2aRYXY3SL/e3PxoL88OMu1Kc2j3nLTg2sIjvEEGpk9jfGpumcSU42N24irSdKXYSBavI8PK3PJ4=" Mar 25 06:45:39 katarynka go-librespot[13920]: time="2026-03-25T06:45:39+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 25 06:45:40 katarynka go-librespot[13920]: time="2026-03-25T06:45:40+01:00" level=debug msg="connected to ap-gew4.spotify.com:443" Mar 25 06:45:40 katarynka go-librespot[13920]: time="2026-03-25T06:45:40+01:00" level=debug msg="completed keyexchange" Mar 25 06:45:40 katarynka go-librespot[13920]: time="2026-03-25T06:45:40+01:00" level=debug msg="completed challenge" Mar 25 06:45:40 katarynka go-librespot[13920]: time="2026-03-25T06:45: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 25 06:45:40 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 06:45:40 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 06:45:42 katarynka volumio[13839]: info: Starting UPNP Browser Mar 25 06:45:42 katarynka volumio[13839]: info: Loading plugin "alarm-clock"... Mar 25 06:45:42 katarynka volumio[13839]: info: Loading plugin "airplay_emulation"... Mar 25 06:45:42 katarynka volumio[13839]: info: Starting Shairport Sync Mar 25 06:45:42 katarynka volumio[13839]: info: Loading plugin "last_100"... Mar 25 06:45:42 katarynka volumio[13839]: info: Loading plugin "webradio"... Mar 25 06:45:42 katarynka volumio[13839]: info: Loading plugin "i2s_dacs"... Mar 25 06:45:42 katarynka volumio[13839]: info: Loading plugin "volumiodiscovery"... Mar 25 06:45:42 katarynka volumio[13839]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Mar 25 06:45:42 katarynka volumio[13839]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 25 06:45:42 katarynka volumio[13839]: *** WARNING *** For more information see Mar 25 06:45:42 katarynka volumio[13839]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Mar 25 06:45:42 katarynka volumio[13839]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 25 06:45:42 katarynka volumio[13839]: *** WARNING *** For more information see Mar 25 06:45:42 katarynka node[13839]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Mar 25 06:45:42 katarynka node[13839]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 25 06:45:42 katarynka node[13839]: *** WARNING *** For more information see Mar 25 06:45:42 katarynka node[13839]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Mar 25 06:45:42 katarynka node[13839]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 25 06:45:42 katarynka node[13839]: *** WARNING *** For more information see Mar 25 06:45:42 katarynka volumio[13839]: info: Applying required configuration parameters for plugin volumiodiscovery Mar 25 06:45:42 katarynka volumio[13839]: info: Discovery: Started advertising with name: katarynka Mar 25 06:45:43 katarynka volumio[13839]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 25 06:45:43 katarynka volumio[13839]: info: Loading plugin "spop"... Mar 25 06:45:43 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Mar 25 06:45:43 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 06:45:43 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 06:45:43 katarynka go-librespot[13930]: go-librespot daemon starting... Mar 25 06:45:43 katarynka go-librespot[13931]: time="2026-03-25T06:45:43+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 06:45:43 katarynka go-librespot[13931]: time="2026-03-25T06:45:43+01:00" level=debug msg="app state loaded" Mar 25 06:45:43 katarynka go-librespot[13931]: time="2026-03-25T06:45:43+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 06:45:43 katarynka go-librespot[13931]: time="2026-03-25T06:45:43+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 25 06:45:43 katarynka go-librespot[13931]: time="2026-03-25T06:45:43+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 25 06:45:43 katarynka go-librespot[13931]: time="2026-03-25T06:45:43+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 25 06:45:44 katarynka go-librespot[13931]: time="2026-03-25T06:45:44+01:00" level=info msg="zeroconf server listening on port 40765" Mar 25 06:45:44 katarynka go-librespot[13931]: time="2026-03-25T06:45:44+01:00" level=debug msg="obtained new client token: AAALwgKOyJGKQvkUY69CMSPrBpj9FOlI/LJby9m9SIuCTVxuZM9g14To4kXjXCJyO8t4wQoTPVPcY3CO6c6fGqD3Woud4c5ELcTJCrRUOmxjVJs+v0pFdzCp8hcL1kxyYQegeNGJR3qouGporH2bolaF1XXaT3aYeiCEXGBP+Gpw7xu96mherxgV52ZHAHJKnoDltSrYj8Q5TNIRDqW8K9qqj0hlB4yv+i1CDTSG7qMuzPX0gOVdaQnI" Mar 25 06:45:44 katarynka go-librespot[13931]: time="2026-03-25T06:45:44+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 06:45:44 katarynka go-librespot[13931]: time="2026-03-25T06:45:44+01:00" level=debug msg="completed keyexchange" Mar 25 06:45:44 katarynka go-librespot[13931]: time="2026-03-25T06:45:44+01:00" level=debug msg="completed challenge" Mar 25 06:45:44 katarynka go-librespot[13931]: time="2026-03-25T06:45:44+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 25 06:45:44 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 06:45:44 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 06:45:45 katarynka volumio[13839]: info: Loading plugin "outputs"... Mar 25 06:45:45 katarynka volumio[13839]: info: Loading plugin "albumart"... Mar 25 06:45:45 katarynka volumio[13839]: info: Plugin example_plugin is not enabled Mar 25 06:45:45 katarynka volumio[13839]: info: Loading plugin "inputs"... Mar 25 06:45:45 katarynka volumio[13839]: info: Loading plugin "updater_comm"... Mar 25 06:45:45 katarynka volumio[13839]: info: Plugin mpdemulation is not enabled Mar 25 06:45:45 katarynka volumio[13839]: info: Loading plugin "rest_api"... Mar 25 06:45:45 katarynka volumio[13839]: info: Loading plugin "websocket"... Mar 25 06:45:45 katarynka volumio[13839]: info: Starting Socket.io Server version 1.7.4 Mar 25 06:45:45 katarynka volumio[13839]: info: Loading i18n strings for locale pl Mar 25 06:45:45 katarynka volumio[13839]: Updating browse sources language Mar 25 06:45:45 katarynka volumio[13839]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 25 06:45:45 katarynka volumio[13839]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 25 06:45:45 katarynka volumio[13839]: info: CoreCommandRouter::initPlayerControls Mar 25 06:45:45 katarynka volumio[13839]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 06:45:45 katarynka volumio[13839]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 06:45:45 katarynka volumio[13839]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 06:45:45 katarynka volumio[13839]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 06:45:45 katarynka volumio[13839]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 06:45:45 katarynka volumio[13839]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 06:45:45 katarynka volumio[13839]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 06:45:45 katarynka volumio[13839]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 06:45:45 katarynka volumio[13839]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 25 06:45:45 katarynka volumio[13839]: Express server listening on port 3000 Mar 25 06:45:45 katarynka volumio[13839]: [Metrics] WebUI: 12s 492.43ms Mar 25 06:45:45 katarynka volumio[13839]: info: CoreStateMachine::resetVolumioState Mar 25 06:45:45 katarynka volumio[13839]: info: CoreStateMachine::getcurrentVolume Mar 25 06:45:45 katarynka volumio[13839]: info: CoreCommandRouter::volumioRetrievevolume Mar 25 06:45:45 katarynka volumio[13839]: info: Cannot read play queue from file Mar 25 06:45:45 katarynka volumio[13839]: info: Volumio Network Manager: Network status updated: 2 Mar 25 06:45:46 katarynka volumio[13839]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 06:45:46 katarynka volumio[13839]: info: CoreStateMachine::setRepeat null single undefined Mar 25 06:45:46 katarynka volumio[13839]: info: CoreStateMachine::pushState Mar 25 06:45:46 katarynka volumio[13839]: info: CorePlayQueue::getTrack 0 Mar 25 06:45:46 katarynka volumio[13839]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 25 06:45:46 katarynka volumio[13938]: Forking 3 albumart workers Mar 25 06:45:46 katarynka volumio[13839]: info: CoreCommandRouter::volumioPushState Mar 25 06:45:46 katarynka volumio[13839]: info: CoreStateMachine::setRandom null Mar 25 06:45:46 katarynka volumio[13839]: info: CoreStateMachine::pushState Mar 25 06:45:46 katarynka volumio[13839]: info: CorePlayQueue::getTrack 0 Mar 25 06:45:46 katarynka volumio[13839]: info: CoreCommandRouter::volumioPushState Mar 25 06:45:46 katarynka volumio[13839]: info: Setting Device type: Raspberry PI Mar 25 06:45:46 katarynka volumio[13839]: info: Completed loading Core Plugins Mar 25 06:45:46 katarynka volumio[13839]: info: Preparing to generate the ALSA configuration file Mar 25 06:45:46 katarynka volumio[13839]: info: VolumeController:: Volume=96 Mute =false Mar 25 06:45:46 katarynka volumio[13839]: info: CoreStateMachine::pushState Mar 25 06:45:46 katarynka volumio[13839]: info: CorePlayQueue::getTrack 0 Mar 25 06:45:46 katarynka volumio[13839]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 25 06:45:46 katarynka volumio[13839]: info: CoreCommandRouter::volumioPushState Mar 25 06:45:46 katarynka volumio[13839]: info: CoreStateMachine::updateTrackBlock Mar 25 06:45:46 katarynka volumio[13839]: info: CorePlayQueue::getTrackBlock Mar 25 06:45:46 katarynka volumio[13839]: info: CoreCommandRouter::volumioRetrievevolume Mar 25 06:45:46 katarynka volumio[13839]: info: Asound.conf file unchanged, so no further update is needed Mar 25 06:45:46 katarynka volumio[13839]: info: Output device has changed, restarting MPD Mar 25 06:45:46 katarynka volumio[13839]: info: Output device has changed, restarting Shairport Sync Mar 25 06:45:46 katarynka sudo[13992]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 25 06:45:46 katarynka sudo[13992]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 06:45:46 katarynka volumio[13839]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 06:45:46 katarynka volumio[13839]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 06:45:46 katarynka sudo[13992]: pam_unix(sudo:session): session closed for user root Mar 25 06:45:46 katarynka sudo[13995]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 25 06:45:46 katarynka sudo[13995]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 06:45:46 katarynka volumio[13839]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 25 06:45:46 katarynka volumio[13839]: info: ___________ START PLUGINS ___________ Mar 25 06:45:46 katarynka volumio[13839]: info: ControllerMpd::onStart: Initializing MPD Mar 25 06:45:46 katarynka volumio[13839]: info: Creating MPD Configuration file Mar 25 06:45:46 katarynka systemd[1]: Stopping mpd.service - Music Player Daemon... Mar 25 06:45:46 katarynka sudo[14003]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 25 06:45:46 katarynka sudo[14003]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 06:45:46 katarynka sudo[14003]: pam_unix(sudo:session): session closed for user root Mar 25 06:45:46 katarynka volumio[13839]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 25 06:45:46 katarynka volumio[13839]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 25 06:45:46 katarynka volumio[13839]: info: [1774417546998] CoreMusicLibrary::Adding element Serwery Mediów Mar 25 06:45:47 katarynka systemd[1]: mpd.service: Deactivated successfully. Mar 25 06:45:47 katarynka systemd[1]: Stopped mpd.service - Music Player Daemon. Mar 25 06:45:47 katarynka systemd[1]: mpd.service: Consumed 7.747s CPU time. Mar 25 06:45:47 katarynka volumio[13839]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 25 06:45:47 katarynka systemd[1]: mpd.socket: Deactivated successfully. Mar 25 06:45:47 katarynka systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Mar 25 06:45:47 katarynka systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Mar 25 06:45:47 katarynka volumio[13839]: info: UPNP Browser: Client initialized successfully Mar 25 06:45:47 katarynka volumio[13839]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 06:45:47 katarynka volumio[13839]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 06:45:47 katarynka systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Mar 25 06:45:47 katarynka systemd[1]: Starting mpd.service - Music Player Daemon... Mar 25 06:45:47 katarynka volumio[13839]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 25 06:45:47 katarynka volumio[13839]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 06:45:47 katarynka sudo[14006]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 25 06:45:47 katarynka sudo[14006]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 06:45:47 katarynka volumio[13839]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 06:45:47 katarynka volumio[13839]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 25 06:45:47 katarynka volumio[13839]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 25 06:45:47 katarynka systemd[1]: mpd.service: Deactivated successfully. Mar 25 06:45:47 katarynka volumio[13839]: info: [1774417547324] CoreMusicLibrary::Adding element Last_100 Mar 25 06:45:47 katarynka volumio[13839]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 25 06:45:47 katarynka systemd[1]: Stopped mpd.service - Music Player Daemon. Mar 25 06:45:47 katarynka systemd[1]: mpd.socket: Deactivated successfully. Mar 25 06:45:47 katarynka systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Mar 25 06:45:47 katarynka systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Mar 25 06:45:47 katarynka volumio[13839]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 25 06:45:47 katarynka volumio[13839]: info: [1774417547353] CoreMusicLibrary::Adding element Webradio Mar 25 06:45:47 katarynka volumio[13839]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 25 06:45:47 katarynka volumio[13839]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 25 06:45:47 katarynka volumio[13839]: info: Initializing BBC Radios Mar 25 06:45:47 katarynka systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Mar 25 06:45:47 katarynka systemd[1]: Starting mpd.service - Music Player Daemon... Mar 25 06:45:47 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Mar 25 06:45:47 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 06:45:47 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 06:45:47 katarynka go-librespot[14028]: go-librespot daemon starting... Mar 25 06:45:47 katarynka volumio[13839]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 25 06:45:47 katarynka volumio[13839]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 06:45:47 katarynka go-librespot[14031]: time="2026-03-25T06:45:47+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 06:45:47 katarynka go-librespot[14031]: time="2026-03-25T06:45:47+01:00" level=debug msg="app state loaded" Mar 25 06:45:47 katarynka go-librespot[14031]: time="2026-03-25T06:45:47+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 06:45:47 katarynka volumio[13839]: info: Creating Spotify config file Mar 25 06:45:47 katarynka volumio[13839]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 06:45:47 katarynka volumio-remote-updater[622]: [2026-03-25 06:45:47] [connect] Successful connection Mar 25 06:45:48 katarynka sudo[14027]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Mar 25 06:45:48 katarynka sudo[14027]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Mar 25 06:45:48 katarynka sudo[14027]: pam_unix(sudo:session): session closed for user root Mar 25 06:45:48 katarynka go-librespot[14031]: time="2026-03-25T06:45:48+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 25 06:45:48 katarynka go-librespot[14031]: time="2026-03-25T06:45:48+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 25 06:45:48 katarynka go-librespot[14031]: time="2026-03-25T06:45:48+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 25 06:45:48 katarynka go-librespot[14031]: time="2026-03-25T06:45:48+01:00" level=info msg="zeroconf server listening on port 42555" Mar 25 06:45:48 katarynka go-librespot[14031]: time="2026-03-25T06:45:48+01:00" level=debug msg="obtained new client token: AABTq8de+pqi+jEq7SPe5Be5BjN3O4/XvN6OqRdJSKFVwsur+d4UjRidwCUnK13PL4oCpg5SqiL0arBUzHB9snz8sOtngK41uIbeOxswVTPAhpJK/kBiDKDXIOebYXaciBHYIjh7hTEkJ3oNGqRj+lJIJldpd0bXDFkFkm/ysBE6RbCG07HnJ6ec6kF6HmloH6PnzUT4YQLaafXciw5Hd8soQyIBHDblQe+KiYxXjRq5kGYPkX/OkrBScCk=" Mar 25 06:45:48 katarynka go-librespot[14031]: time="2026-03-25T06:45:48+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 06:45:48 katarynka go-librespot[14031]: time="2026-03-25T06:45:48+01:00" level=debug msg="completed keyexchange" Mar 25 06:45:48 katarynka go-librespot[14031]: time="2026-03-25T06:45:48+01:00" level=debug msg="completed challenge" Mar 25 06:45:48 katarynka go-librespot[14031]: time="2026-03-25T06:45:48+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 25 06:45:48 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 06:45:48 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 06:45:48 katarynka volumio[13839]: info: Volumio Calling Home Mar 25 06:45:49 katarynka volumio[13959]: Starting albumart workers Mar 25 06:45:50 katarynka volumio[13839]: info: Discovery: adding 4d616d77-6a8c-4da2-85a4-840d70f98e51 Mar 25 06:45:50 katarynka volumio[13839]: info: Discovery: Found device katarynka Mar 25 06:45:50 katarynka volumio[13839]: info: CoreCommandRouter::volumioGetState Mar 25 06:45:50 katarynka volumio[13839]: info: CorePlayQueue::getTrack 0 Mar 25 06:45:50 katarynka sudo[14062]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 25 06:45:50 katarynka sudo[14062]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 06:45:50 katarynka sudo[14062]: pam_unix(sudo:session): session closed for user root Mar 25 06:45:50 katarynka volumio[13839]: info: Discovery: this is already registered, 4d616d77-6a8c-4da2-85a4-840d70f98e51 Mar 25 06:45:50 katarynka volumio[13839]: info: Discovery: Found device katarynka Mar 25 06:45:50 katarynka volumio[13839]: info: CoreCommandRouter::volumioGetState Mar 25 06:45:50 katarynka volumio[13839]: info: CorePlayQueue::getTrack 0 Mar 25 06:45:50 katarynka volumio[13839]: info: MPD Permissions set Mar 25 06:45:50 katarynka volumio[13839]: info: MPD Permissions set Mar 25 06:45:50 katarynka volumio[13839]: info: VolumeController:: Volume=96 Mute =false Mar 25 06:45:50 katarynka sudo[14064]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 25 06:45:50 katarynka volumio[13839]: info: CoreStateMachine::pushState Mar 25 06:45:50 katarynka volumio[13839]: info: CorePlayQueue::getTrack 0 Mar 25 06:45:50 katarynka sudo[14064]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 06:45:50 katarynka volumio[13839]: info: CoreCommandRouter::volumioPushState Mar 25 06:45:50 katarynka sudo[14064]: pam_unix(sudo:session): session closed for user root Mar 25 06:45:50 katarynka volumio-remote-updater[622]: [2026-03-25 06:45:50] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1774417547 101 Mar 25 06:45:50 katarynka volumio[13839]: 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 25 06:45:50 katarynka volumio[13839]: info: Volumio called home Mar 25 06:45:50 katarynka volumio[13839]: info: Spotify config file written Mar 25 06:45:50 katarynka sudo[14068]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Mar 25 06:45:50 katarynka sudo[14068]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 06:45:50 katarynka volumio[13839]: 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 25 06:45:50 katarynka volumio[13839]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 06:45:50 katarynka volumio[13839]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 06:45:50 katarynka volumio[13839]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 06:45:50 katarynka volumio[13839]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 06:45:50 katarynka volumio[13839]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 06:45:50 katarynka volumio[13839]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 06:45:50 katarynka volumio[13839]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 06:45:50 katarynka volumio[13839]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 06:45:50 katarynka volumio[13839]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 06:45:50 katarynka volumio[13839]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 06:45:50 katarynka volumio[13839]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 06:45:50 katarynka volumio[13839]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 06:45:50 katarynka volumio[13839]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 06:45:50 katarynka volumio[13839]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 06:45:50 katarynka volumio[13839]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 06:45:50 katarynka volumio[13839]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 06:45:50 katarynka volumio[13839]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 06:45:50 katarynka volumio[13839]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 06:45:50 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 06:45:50 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 06:45:50 katarynka go-librespot[14077]: go-librespot daemon starting... Mar 25 06:45:50 katarynka volumio[13839]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 06:45:50 katarynka volumio[13839]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 06:45:50 katarynka sudo[14068]: pam_unix(sudo:session): session closed for user root Mar 25 06:45:50 katarynka volumio[13839]: info: No need to fix Spotify hosts Mar 25 06:45:50 katarynka go-librespot[14081]: time="2026-03-25T06:45:50+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 06:45:50 katarynka go-librespot[14081]: time="2026-03-25T06:45:50+01:00" level=debug msg="app state loaded" Mar 25 06:45:50 katarynka go-librespot[14081]: time="2026-03-25T06:45:50+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 06:45:51 katarynka go-librespot[14081]: time="2026-03-25T06:45:51+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 25 06:45:51 katarynka go-librespot[14081]: time="2026-03-25T06:45:51+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 25 06:45:51 katarynka go-librespot[14081]: time="2026-03-25T06:45:51+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 25 06:45:51 katarynka go-librespot[14081]: time="2026-03-25T06:45:51+01:00" level=info msg="zeroconf server listening on port 40157" Mar 25 06:45:51 katarynka volumio[13958]: Starting albumart workers Mar 25 06:45:51 katarynka volumio[13960]: Starting albumart workers Mar 25 06:45:51 katarynka go-librespot[14081]: time="2026-03-25T06:45:51+01:00" level=debug msg="obtained new client token: AAAScwPkjXWKcPXGUmcRIWnyWw8JwwCxEvFSHkSz+4b1ic0xnZ25LMXqQ3hPeLpZhwyg9f5XcMoUQoxloFFs7eP20vWKWPq5045/GDeX7dYHxzSYTmyO+wuXR4MqMCf1RrQd9Qel9Flf9OldQmKFR0pb4E/i4N2EOUM/lW56HBb5uf0RZcleYh8NFArVcsaiK9Ut34D29fCwF3YrB8CHYtKGRqgo244XpRWzDHrPcOVdYOmN7BzpnKK0QSk=" Mar 25 06:45:51 katarynka go-librespot[14081]: time="2026-03-25T06:45:51+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 06:45:51 katarynka go-librespot[14081]: time="2026-03-25T06:45:51+01:00" level=debug msg="completed keyexchange" Mar 25 06:45:51 katarynka go-librespot[14081]: time="2026-03-25T06:45:51+01:00" level=debug msg="completed challenge" Mar 25 06:45:51 katarynka volumio[13839]: info: Starting Shairport Sync Mar 25 06:45:51 katarynka go-librespot[14081]: time="2026-03-25T06:45:51+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 25 06:45:51 katarynka volumio[13839]: info: Starting Shairport Sync Mar 25 06:45:51 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 06:45:51 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 06:45:51 katarynka volumio[13839]: info: Starting Shairport Sync Mar 25 06:45:51 katarynka sudo[14091]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 25 06:45:51 katarynka sudo[14091]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 06:45:51 katarynka sudo[14089]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 25 06:45:51 katarynka sudo[14093]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 25 06:45:51 katarynka sudo[14093]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 06:45:51 katarynka sudo[14089]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 06:45:52 katarynka sudo[14095]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Mar 25 06:45:52 katarynka sudo[14095]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 06:45:52 katarynka systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Mar 25 06:45:52 katarynka systemd[1]: shairport-sync.service: Deactivated successfully. Mar 25 06:45:52 katarynka systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 25 06:45:52 katarynka systemd[1]: shairport-sync.service: Consumed 2.199s CPU time. Mar 25 06:45:52 katarynka systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 25 06:45:52 katarynka sudo[14093]: pam_unix(sudo:session): session closed for user root Mar 25 06:45:52 katarynka systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Mar 25 06:45:52 katarynka sudo[14095]: pam_unix(sudo:session): session closed for user root Mar 25 06:45:52 katarynka systemd[1]: shairport-sync.service: Deactivated successfully. Mar 25 06:45:52 katarynka systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 25 06:45:52 katarynka systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 25 06:45:52 katarynka sudo[14089]: pam_unix(sudo:session): session closed for user root Mar 25 06:45:52 katarynka sudo[14091]: pam_unix(sudo:session): session closed for user root Mar 25 06:45:52 katarynka volumio[13839]: info: Shairport-Sync Started Mar 25 06:45:52 katarynka volumio[13839]: Error adding Membership: Error: addMembership EINVAL Mar 25 06:45:52 katarynka volumio[13839]: info: Shairport-Sync Started Mar 25 06:45:52 katarynka volumio[13839]: info: Shairport-Sync Started Mar 25 06:45:52 katarynka volumio[13839]: info: Upmpdcli Daemon Started Mar 25 06:45:52 katarynka volumio[13839]: info: An error occurred while refreshing Spotify Token Error: Bad Request Mar 25 06:45:52 katarynka volumio[13839]: info: CoreCommandRouter::volumioGetState Mar 25 06:45:52 katarynka volumio[13839]: info: CorePlayQueue::getTrack 0 Mar 25 06:45:54 katarynka volumio[13839]: info: go-librespot daemon successfully initialized Mar 25 06:45:54 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Mar 25 06:45:54 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 06:45:54 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 06:45:54 katarynka go-librespot[14147]: go-librespot daemon starting... Mar 25 06:45:55 katarynka go-librespot[14148]: time="2026-03-25T06:45:55+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 06:45:55 katarynka go-librespot[14148]: time="2026-03-25T06:45:55+01:00" level=debug msg="app state loaded" Mar 25 06:45:55 katarynka go-librespot[14148]: time="2026-03-25T06:45:55+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 06:45:55 katarynka go-librespot[14148]: time="2026-03-25T06:45:55+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 25 06:45:55 katarynka go-librespot[14148]: time="2026-03-25T06:45:55+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 25 06:45:55 katarynka go-librespot[14148]: time="2026-03-25T06:45:55+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 25 06:45:55 katarynka go-librespot[14148]: time="2026-03-25T06:45:55+01:00" level=info msg="zeroconf server listening on port 43569" Mar 25 06:45:55 katarynka go-librespot[14148]: time="2026-03-25T06:45:55+01:00" level=debug msg="obtained new client token: AAAFfLkT6oT5Cw8GZ0V/cIgVomrh1dY6Zv1PcPmIjDB6NXXFL0VjGCVo9hsRj/2vIjl3qSRzqB18KHjortt+fQ5Z8WgGUmG4SyOMNno9gMYRF7DUO21Z359p8jY4apL7JGe94hsqN+55bugIBetsxc/qtA3GI8Gmqy2UZXzEcjoDaaN80v1n2apQJJP82TDo19MswYOws11UAkRSR7nQX/H8LoXoQLK5msHyxxlajID15tjPt8gVGsFEyqo=" Mar 25 06:45:55 katarynka mpd[14042]: 2026-03-25T06:45:55 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Mar 25 06:45:55 katarynka systemd[1]: Started mpd.service - Music Player Daemon. Mar 25 06:45:55 katarynka sudo[13995]: pam_unix(sudo:session): session closed for user root Mar 25 06:45:55 katarynka sudo[14006]: pam_unix(sudo:session): session closed for user root Mar 25 06:45:55 katarynka go-librespot[14148]: time="2026-03-25T06:45:55+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 25 06:45:55 katarynka volumio[13839]: info: Completed starting Core Plugins Mar 25 06:45:55 katarynka go-librespot[14148]: time="2026-03-25T06:45:55+01:00" level=debug msg="connected to ap-gew4.spotify.com:443" Mar 25 06:45:55 katarynka volumio[13839]: info: ------------------------------------------- Mar 25 06:45:55 katarynka volumio[13839]: info: ----- MyVolumio plugins startup ---- Mar 25 06:45:55 katarynka volumio[13839]: info: ------------------------------------------- Mar 25 06:45:55 katarynka volumio[13839]: info: [MyVolumio PluginManager] Fetching plans data.... Mar 25 06:45:55 katarynka go-librespot[14148]: time="2026-03-25T06:45:55+01:00" level=debug msg="completed keyexchange" Mar 25 06:45:55 katarynka go-librespot[14148]: time="2026-03-25T06:45:55+01:00" level=debug msg="completed challenge" Mar 25 06:45:55 katarynka go-librespot[14148]: time="2026-03-25T06:45:55+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 25 06:45:55 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 06:45:55 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 06:45:55 katarynka volumio[13839]: error: MPD error: The expression evaluated to a falsy value: Mar 25 06:45:55 katarynka volumio[13839]: assert.ok(self.idling) Mar 25 06:45:55 katarynka volumio[13839]: error: The expression evaluated to a falsy value: Mar 25 06:45:55 katarynka volumio[13839]: assert.ok(self.idling) Mar 25 06:45:55 katarynka volumio[13839]: info: MPD running with PID14042 Mar 25 06:45:55 katarynka volumio[13839]: ,establishing connection Mar 25 06:45:55 katarynka volumio[13839]: error: updateQueue error: null Mar 25 06:45:55 katarynka volumio[13839]: error: updateQueue error: null Mar 25 06:45:57 katarynka volumio[13839]: info: Initializing connection to go-librespot Websocket Mar 25 06:45:57 katarynka volumio[13839]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 25 06:45:58 katarynka sudo[14177]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Mar 25 06:45:58 katarynka sudo[14177]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 06:45:58 katarynka sudo[14179]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Mar 25 06:45:58 katarynka sudo[14179]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 06:45:58 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 11. Mar 25 06:45:58 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 06:45:58 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 06:45:58 katarynka go-librespot[14182]: go-librespot daemon starting... Mar 25 06:45:59 katarynka systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Mar 25 06:45:59 katarynka systemd[1]: mpd_monitor.service: Deactivated successfully. Mar 25 06:45:59 katarynka systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Mar 25 06:45:59 katarynka systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Mar 25 06:45:59 katarynka go-librespot[14183]: time="2026-03-25T06:45:59+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 06:45:59 katarynka go-librespot[14183]: time="2026-03-25T06:45:59+01:00" level=debug msg="app state loaded" Mar 25 06:45:59 katarynka sudo[14177]: pam_unix(sudo:session): session closed for user root Mar 25 06:45:59 katarynka go-librespot[14183]: time="2026-03-25T06:45:59+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 06:45:59 katarynka sudo[14179]: pam_unix(sudo:session): session closed for user root Mar 25 06:45:59 katarynka mpd_monitor.sh[14189]: MPD Monitor Service: Starting MPD Monitor Service Mar 25 06:45:59 katarynka volumio[13839]: info: Successfully started MPD Monitor Mar 25 06:45:59 katarynka volumio[13839]: info: Successfully started MPD Monitor Mar 25 06:45:59 katarynka go-librespot[14183]: time="2026-03-25T06:45:59+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 25 06:45:59 katarynka go-librespot[14183]: time="2026-03-25T06:45:59+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 25 06:45:59 katarynka go-librespot[14183]: time="2026-03-25T06:45:59+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 25 06:45:59 katarynka go-librespot[14183]: time="2026-03-25T06:45:59+01:00" level=info msg="zeroconf server listening on port 40029" Mar 25 06:45:59 katarynka go-librespot[14183]: time="2026-03-25T06:45:59+01:00" level=debug msg="obtained new client token: AABkAYiI+Ldqg/lPtLpFeK7yL9g5kVxWlzJa75bUzl99Q+C5EU66hyUcW/ikEX5IPk19JiL2e37tybbjd3FSHgIMa0c/JVfiY2A/SIiJt55484rcx2m7MroQGoyMgap0wNCgNBc6mTWGLeRURNxTQyNSyZaRx5uQu2M74Fp8My9pSFnctYtXhPrrYlkcFieksqubIccnEnxvYqezPDjSOF6oby4auM9PTriI+VQgnahKuR03VCCaB0G1zDc=" Mar 25 06:45:59 katarynka go-librespot[14183]: time="2026-03-25T06:45:59+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 06:45:59 katarynka go-librespot[14183]: time="2026-03-25T06:45:59+01:00" level=debug msg="completed keyexchange" Mar 25 06:45:59 katarynka go-librespot[14183]: time="2026-03-25T06:45:59+01:00" level=debug msg="completed challenge" Mar 25 06:45:59 katarynka go-librespot[14183]: time="2026-03-25T06:45:59+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 25 06:45:59 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 06:45:59 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 06:46:00 katarynka volumio[13839]: info: Initializing connection to go-librespot Websocket Mar 25 06:46:00 katarynka volumio[13839]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 25 06:46:00 katarynka volumio[13839]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Mar 25 06:46:02 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 12. Mar 25 06:46:02 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 06:46:02 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 06:46:02 katarynka go-librespot[14195]: go-librespot daemon starting... Mar 25 06:46:03 katarynka go-librespot[14196]: time="2026-03-25T06:46:03+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 06:46:03 katarynka go-librespot[14196]: time="2026-03-25T06:46:03+01:00" level=debug msg="app state loaded" Mar 25 06:46:03 katarynka go-librespot[14196]: time="2026-03-25T06:46:03+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 06:46:03 katarynka go-librespot[14196]: time="2026-03-25T06:46:03+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 25 06:46:03 katarynka go-librespot[14196]: time="2026-03-25T06:46:03+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 25 06:46:03 katarynka go-librespot[14196]: time="2026-03-25T06:46:03+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 25 06:46:03 katarynka go-librespot[14196]: time="2026-03-25T06:46:03+01:00" level=info msg="zeroconf server listening on port 32955" Mar 25 06:46:03 katarynka go-librespot[14196]: time="2026-03-25T06:46:03+01:00" level=debug msg="obtained new client token: AAD44tkQ89DRDEfzafcH2cxuIlwAIUpd1tey3c0GMGOpchPhHsTkZu5e+m7LpenfptIIYBMCyLhOK4W3fIhqnddLu5imTq6ZjbTAblQ6jqt59W+JyG7kWHr2XZUndSqKstDVgJOncc0JIxyDsPdxI1nIhKQEYbSEUSecqUU8zy10CI88cCbPpABEv9bazlg3WDjIwVOaCJnizZgx2cE4QNKkKOhYwu9UInafdzFUUtmF7Kk2+VDLOZi1FSA=" Mar 25 06:46:03 katarynka go-librespot[14196]: time="2026-03-25T06:46:03+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 25 06:46:03 katarynka go-librespot[14196]: time="2026-03-25T06:46:03+01:00" level=debug msg="connected to ap-gew4.spotify.com:443" Mar 25 06:46:03 katarynka go-librespot[14196]: time="2026-03-25T06:46:03+01:00" level=debug msg="completed keyexchange" Mar 25 06:46:03 katarynka go-librespot[14196]: time="2026-03-25T06:46:03+01:00" level=debug msg="completed challenge" Mar 25 06:46:03 katarynka volumio[13839]: info: Initializing connection to go-librespot Websocket Mar 25 06:46:03 katarynka go-librespot[14196]: time="2026-03-25T06:46:03+01:00" level=debug msg="new websocket client" Mar 25 06:46:03 katarynka volumio[13839]: info: Connection to go-librespot Websocket established Mar 25 06:46:03 katarynka go-librespot[14196]: time="2026-03-25T06:46:03+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 25 06:46:03 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 06:46:03 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 06:46:03 katarynka volumio[13839]: info: Connection to go-librespot Websocket closed Mar 25 06:46:04 katarynka volumio[13839]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Mar 25 06:46:04 katarynka volumio[13839]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Mar 25 06:46:04 katarynka volumio[13839]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Mar 25 06:46:04 katarynka volumio[13839]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Mar 25 06:46:04 katarynka volumio[13839]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Mar 25 06:46:04 katarynka volumio[13839]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Mar 25 06:46:04 katarynka volumio[13839]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Mar 25 06:46:04 katarynka volumio[13839]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Mar 25 06:46:04 katarynka volumio[13839]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Mar 25 06:46:04 katarynka volumio[13839]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Mar 25 06:46:04 katarynka volumio[13839]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Mar 25 06:46:04 katarynka volumio[13839]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Mar 25 06:46:04 katarynka volumio[13839]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Mar 25 06:46:04 katarynka volumio[13839]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Mar 25 06:46:04 katarynka volumio[13839]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Mar 25 06:46:04 katarynka volumio[13839]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Mar 25 06:46:04 katarynka volumio[13839]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Mar 25 06:46:04 katarynka volumio[13839]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Mar 25 06:46:04 katarynka volumio[13839]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Mar 25 06:46:04 katarynka volumio[13839]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Mar 25 06:46:04 katarynka volumio[13839]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Mar 25 06:46:04 katarynka volumio[13839]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Mar 25 06:46:04 katarynka volumio[13839]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Mar 25 06:46:04 katarynka volumio[13839]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Mar 25 06:46:04 katarynka volumio[13839]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Mar 25 06:46:04 katarynka volumio[13839]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Mar 25 06:46:04 katarynka volumio[13839]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Mar 25 06:46:04 katarynka volumio[13839]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Mar 25 06:46:04 katarynka volumio[13839]: info: Adding plugin bluetooth to MyMusic Plugins Mar 25 06:46:04 katarynka volumio[13839]: info: Adding plugin multiroom to MyMusic Plugins Mar 25 06:46:04 katarynka volumio[13839]: info: Adding plugin metavolumio to MyMusic Plugins Mar 25 06:46:04 katarynka volumio[13839]: info: Adding plugin cd_controller to MyMusic Plugins Mar 25 06:46:04 katarynka volumio[13839]: info: Adding plugin qobuzconnect to MyMusic Plugins Mar 25 06:46:04 katarynka volumio[13839]: info: Adding plugin smart_inputs to MyMusic Plugins Mar 25 06:46:04 katarynka volumio[13839]: info: Adding plugin tidalconnect to MyMusic Plugins Mar 25 06:46:04 katarynka volumio[13839]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Mar 25 06:46:06 katarynka volumio[13839]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Mar 25 06:46:06 katarynka volumio[13839]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Mar 25 06:46:06 katarynka volumio[13839]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 06:46:06 katarynka volumio[13839]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 06:46:06 katarynka volumio[13839]: info: Starting MyVolumio Remote Streaming Endpoints Mar 25 06:46:06 katarynka volumio[13839]: info: MyVolumio login type: Token Mar 25 06:46:06 katarynka volumio[13839]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Mar 25 06:46:06 katarynka volumio[13839]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Mar 25 06:46:06 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 13. Mar 25 06:46:06 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 06:46:07 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 06:46:07 katarynka go-librespot[14203]: go-librespot daemon starting... Mar 25 06:46:07 katarynka go-librespot[14204]: time="2026-03-25T06:46:07+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 06:46:07 katarynka go-librespot[14204]: time="2026-03-25T06:46:07+01:00" level=debug msg="app state loaded" Mar 25 06:46:07 katarynka go-librespot[14204]: time="2026-03-25T06:46:07+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 06:46:07 katarynka go-librespot[14204]: time="2026-03-25T06:46:07+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 25 06:46:07 katarynka go-librespot[14204]: time="2026-03-25T06:46:07+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 25 06:46:07 katarynka go-librespot[14204]: time="2026-03-25T06:46:07+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 25 06:46:07 katarynka go-librespot[14204]: time="2026-03-25T06:46:07+01:00" level=info msg="zeroconf server listening on port 39721" Mar 25 06:46:07 katarynka go-librespot[14204]: time="2026-03-25T06:46:07+01:00" level=debug msg="obtained new client token: AAA/5mMQkRUsuEX8fM6v2c/hO4j9ZDtBa5rZc61fTb4e1Ki++bMuJu9g2GXGi3Zcga+nOh1FyXRhDrHADo6l9GbqF/0ll+ob/A5UgulIguis9srlmVkvNEpRBu4e1QgLZrmdtS2pLYDzIH8OfiS7QIeWMeBylqFEWh8RwtVUJfdTzNjRvkFSoiSloscVWZZ2ziEKKAjZMLBouslsaVDnZK+pLkMN5ABI0fbjdCpMjFULAX98ebyNUXI8BKc=" Mar 25 06:46:07 katarynka go-librespot[14204]: time="2026-03-25T06:46:07+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 06:46:08 katarynka volumio[13839]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Mar 25 06:46:08 katarynka volumio[13839]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Mar 25 06:46:08 katarynka volumio[13839]: info: Streaming services startup Mar 25 06:46:08 katarynka volumio[13839]: info: Starting Streaming Daemon Mar 25 06:46:08 katarynka sudo[14212]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Mar 25 06:46:08 katarynka sudo[14212]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 06:46:08 katarynka volumio[13839]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Mar 25 06:46:08 katarynka sudo[14212]: pam_unix(sudo:session): session closed for user root Mar 25 06:46:08 katarynka go-librespot[14204]: time="2026-03-25T06:46:08+01:00" level=debug msg="completed keyexchange" Mar 25 06:46:08 katarynka go-librespot[14204]: time="2026-03-25T06:46:08+01:00" level=debug msg="completed challenge" Mar 25 06:46:08 katarynka volumio[13839]: info: Getting Spotify volume Mar 25 06:46:08 katarynka volumio[13839]: info: Initializing connection to go-librespot Websocket Mar 25 06:46:08 katarynka volumio[13839]: error: Cannot start Volumio Streaming Daemon Mar 25 06:46:08 katarynka volumio[13839]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Mar 25 06:46:08 katarynka volumio[13839]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Mar 25 06:46:08 katarynka go-librespot[14204]: time="2026-03-25T06:46:08+01:00" level=debug msg="new websocket client" Mar 25 06:46:08 katarynka volumio[13839]: 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 25 06:46:08 katarynka volumio[13839]: info: Connection to go-librespot Websocket established Mar 25 06:46:08 katarynka go-librespot[14204]: time="2026-03-25T06:46: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 25 06:46:08 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 06:46:08 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 06:46:08 katarynka volumio[13839]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 25 06:46:08 katarynka volumio[13839]: Error: socket hang up Mar 25 06:46:08 katarynka volumio[13839]: at connResetException (node:internal/errors:720:14) Mar 25 06:46:08 katarynka volumio[13839]: at Socket.socketOnEnd (node:_http_client:519:23) Mar 25 06:46:08 katarynka volumio[13839]: at Socket.emit (node:events:526:35) Mar 25 06:46:08 katarynka volumio[13839]: at endReadableNT (node:internal/streams/readable:1376:12) Mar 25 06:46:08 katarynka volumio[13839]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Mar 25 06:46:08 katarynka volumio[13839]: code: 'ECONNRESET', Mar 25 06:46:08 katarynka volumio[13839]: response: undefined Mar 25 06:46:08 katarynka volumio[13839]: } Mar 25 06:46:08 katarynka volumio[13839]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 25 06:46:10 katarynka sudo[14246]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-03-25 06:45' Mar 25 06:46:10 katarynka sudo[14246]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 06:46:10 katarynka sudo[14246]: pam_unix(sudo:session): session closed for user root Mar 25 06:46:10 katarynka volumio-remote-updater[622]: [2026-03-25 06:46:10] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Mar 25 06:46:10 katarynka volumio-remote-updater[622]: [2026-03-25 06:46:10] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Mar 25 06:46:10 katarynka systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Mar 25 06:46:10 katarynka systemd[1]: volumio.service: Failed with result 'exit-code'. Mar 25 06:46:10 katarynka systemd[1]: volumio.service: Consumed 48.913s CPU time. Mar 25 06:46:10 katarynka systemd[1]: Started dynamicswap.service - dynamicswap service. Mar 25 06:46:10 katarynka systemd[1]: dynamicswap.service: Deactivated successfully. Mar 25 06:46:10 katarynka systemd[1]: volumio.service: Scheduled restart job, restart counter is at 26034. Mar 25 06:46:10 katarynka systemd[1]: Started dynamicswap.service - dynamicswap service. Mar 25 06:46:10 katarynka systemd[1]: Stopped volumio.service - Volumio Backend Module. Mar 25 06:46:10 katarynka systemd[1]: volumio.service: Consumed 48.913s CPU time. Mar 25 06:46:10 katarynka systemd[1]: Started volumio.service - Volumio Backend Module. Mar 25 06:46:10 katarynka systemd[1]: dynamicswap.service: Deactivated successfully. Mar 25 06:46:11 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 14. Mar 25 06:46:11 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 06:46:11 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 06:46:11 katarynka go-librespot[14274]: go-librespot daemon starting... Mar 25 06:46:11 katarynka go-librespot[14275]: time="2026-03-25T06:46:11+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 06:46:11 katarynka go-librespot[14275]: time="2026-03-25T06:46:11+01:00" level=debug msg="app state loaded" Mar 25 06:46:11 katarynka go-librespot[14275]: time="2026-03-25T06:46:11+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 06:46:12 katarynka go-librespot[14275]: time="2026-03-25T06:46: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-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 25 06:46:12 katarynka go-librespot[14275]: time="2026-03-25T06:46:12+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 25 06:46:12 katarynka go-librespot[14275]: time="2026-03-25T06:46:12+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 25 06:46:12 katarynka go-librespot[14275]: time="2026-03-25T06:46:12+01:00" level=info msg="zeroconf server listening on port 35499" Mar 25 06:46:12 katarynka go-librespot[14275]: time="2026-03-25T06:46:12+01:00" level=debug msg="obtained new client token: AABDw1bARfCpbKb4lEWtDYUSdx1y+xNygf3qxE4OCXWpbeB0F2wnSwV6xLwXqw9+TR+KmKGIVzbH96IvSxPP3w8b5pBEId0UWbVS24zAsk7Up33ag4oMo11JjI2/a6o9VW9A7lPhfr28SD6oqsWf5h/E3P9I+5zpa5cP3jkPjjFQGn8Ov5/sgQt8lXmwo75jpWy+4D7uKsd5IJLqAdCrMPJMB0FXEMLtDgF+N925ukKT2BDqtL/crGbE9wI=" Mar 25 06:46:12 katarynka go-librespot[14275]: time="2026-03-25T06:46:12+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 06:46:12 katarynka go-librespot[14275]: time="2026-03-25T06:46:12+01:00" level=debug msg="completed keyexchange" Mar 25 06:46:12 katarynka go-librespot[14275]: time="2026-03-25T06:46:12+01:00" level=debug msg="completed challenge" Mar 25 06:46:12 katarynka go-librespot[14275]: time="2026-03-25T06:46: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 25 06:46:12 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 06:46:12 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 06:46:14 katarynka volumio[14259]: info: ------------------------------------------- Mar 25 06:46:14 katarynka volumio[14259]: info: ----- Volumio3 ---- Mar 25 06:46:14 katarynka volumio[14259]: info: ------------------------------------------- Mar 25 06:46:14 katarynka volumio[14259]: info: ----- System startup ---- Mar 25 06:46:14 katarynka volumio[14259]: info: ------------------------------------------- Mar 25 06:46:15 katarynka volumio-remote-updater[622]: [2026-03-25 06:46:15] [connect] Successful connection Mar 25 06:46:15 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 15. Mar 25 06:46:15 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 06:46:15 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 06:46:15 katarynka go-librespot[14288]: go-librespot daemon starting... Mar 25 06:46:15 katarynka go-librespot[14289]: time="2026-03-25T06:46:15+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 06:46:15 katarynka go-librespot[14289]: time="2026-03-25T06:46:15+01:00" level=debug msg="app state loaded" Mar 25 06:46:15 katarynka go-librespot[14289]: time="2026-03-25T06:46:15+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 06:46:15 katarynka volumio[14259]: info: MYVOLUMIO Environment detected Mar 25 06:46:16 katarynka volumio[14259]: info: Plugin folders cleanup Mar 25 06:46:16 katarynka volumio[14259]: info: Scanning into folder /volumio/app/plugins/ Mar 25 06:46:16 katarynka volumio[14259]: info: Scanning category audio_interface Mar 25 06:46:16 katarynka volumio[14259]: info: Scanning category miscellanea Mar 25 06:46:16 katarynka volumio[14259]: info: Scanning category music_service Mar 25 06:46:16 katarynka volumio[14259]: info: Scanning category plugins.json Mar 25 06:46:16 katarynka volumio[14259]: info: Scanning category system_controller Mar 25 06:46:16 katarynka volumio[14259]: info: Scanning category user_interface Mar 25 06:46:16 katarynka volumio[14259]: info: Scanning into folder /data/plugins/ Mar 25 06:46:16 katarynka volumio[14259]: info: Scanning category music_service Mar 25 06:46:16 katarynka volumio[14259]: info: Plugin folders cleanup completed Mar 25 06:46:16 katarynka volumio[14259]: info: ------------------------------------------- Mar 25 06:46:16 katarynka volumio[14259]: info: ----- Core plugins startup ---- Mar 25 06:46:16 katarynka volumio[14259]: info: ------------------------------------------- Mar 25 06:46:16 katarynka volumio[14259]: info: Loading plugins from folder /volumio/app/plugins/ Mar 25 06:46:16 katarynka volumio[14259]: info: Adding plugin upnp to MyMusic Plugins Mar 25 06:46:16 katarynka volumio[14259]: info: Adding plugin airplay_emulation to MyMusic Plugins Mar 25 06:46:16 katarynka volumio[14259]: info: Adding plugin upnp_browser to MyMusic Plugins Mar 25 06:46:16 katarynka volumio[14259]: info: Loading plugins from folder /data/plugins/ Mar 25 06:46:16 katarynka volumio[14259]: info: Loading plugin "system"... Mar 25 06:46:16 katarynka go-librespot[14289]: time="2026-03-25T06:46: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 25 06:46:16 katarynka go-librespot[14289]: time="2026-03-25T06:46: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 25 06:46:16 katarynka go-librespot[14289]: time="2026-03-25T06:46: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 25 06:46:16 katarynka go-librespot[14289]: time="2026-03-25T06:46:16+01:00" level=info msg="zeroconf server listening on port 36493" Mar 25 06:46:16 katarynka volumio[14259]: info: Loading plugin "appearance"... Mar 25 06:46:16 katarynka go-librespot[14289]: time="2026-03-25T06:46:16+01:00" level=debug msg="obtained new client token: AADSkjNWoamZ0dknN6eH3zONUg+67LLz59IM6bWr7cOL17ofLjguBDoWkHqoZh0g5/Pmbkv0O02t+bY7/PW2RUTX7f55TVpxe2lT1eaSc1CJtviLCnZWUWFtlJmPsh3ptf4nLypuAqzYJhoH4vdrP+qpR+w5jI3/caPcuxanxwPCbyUERGpqhTa27G+Raiph7i6BLD3+TxZNBMfl7PeOGrm9+YfIC9vaKg0qznDR5FCEcJSq4VkiFdMhcLU=" Mar 25 06:46:16 katarynka go-librespot[14289]: time="2026-03-25T06:46:16+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 06:46:16 katarynka go-librespot[14289]: time="2026-03-25T06:46:16+01:00" level=debug msg="completed keyexchange" Mar 25 06:46:16 katarynka go-librespot[14289]: time="2026-03-25T06:46:16+01:00" level=debug msg="completed challenge" Mar 25 06:46:16 katarynka go-librespot[14289]: time="2026-03-25T06:46: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 25 06:46:16 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 06:46:16 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 06:46:18 katarynka volumio[14259]: info: Loading plugin "network"... Mar 25 06:46:18 katarynka volumio[14259]: info: Refreshing Cached IP Addresses Mar 25 06:46:18 katarynka sudo[14303]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 25 06:46:18 katarynka sudo[14303]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 06:46:18 katarynka sudo[14305]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 25 06:46:18 katarynka sudo[14305]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 06:46:18 katarynka sudo[14303]: pam_unix(sudo:session): session closed for user root Mar 25 06:46:18 katarynka volumio[14259]: info: Loading plugin "services"... Mar 25 06:46:18 katarynka sudo[14305]: pam_unix(sudo:session): session closed for user root Mar 25 06:46:18 katarynka volumio[14259]: info: Loading plugin "alsa_controller"... Mar 25 06:46:18 katarynka sudo[14313]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Mar 25 06:46:18 katarynka sudo[14313]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 06:46:18 katarynka volumio[14259]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 25 06:46:18 katarynka volumio[14259]: info: Loading plugin "wizard"... Mar 25 06:46:18 katarynka volumio[14259]: info: Loading plugin "networkfs"... Mar 25 06:46:18 katarynka volumio[14259]: info: Starting Udev Watcher for removable devices Mar 25 06:46:18 katarynka volumio[14259]: info: Ignoring mount for partition: boot Mar 25 06:46:18 katarynka volumio[14259]: info: Ignoring mount for partition: volumio Mar 25 06:46:18 katarynka volumio[14259]: info: Ignoring mount for partition: volumio_data Mar 25 06:46:18 katarynka volumio[14259]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 25 06:46:18 katarynka volumio[14259]: info: Loading plugin "volumio_command_line_client"... Mar 25 06:46:18 katarynka volumio[14259]: info: Loading plugin "upnp"... Mar 25 06:46:18 katarynka volumio[14259]: info: [1774417578715] Starting Upmpd Daemon Mar 25 06:46:18 katarynka volumio[14259]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 25 06:46:18 katarynka volumio[14259]: info: Loading plugin "my_music"... Mar 25 06:46:18 katarynka volumio[14259]: info: Loading plugin "mpd"... Mar 25 06:46:19 katarynka sudo[14313]: pam_unix(sudo:session): session closed for user root Mar 25 06:46:19 katarynka volumio[14259]: info: Loading plugin "upnp_browser"... Mar 25 06:46:19 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 16. Mar 25 06:46:19 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 06:46:19 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 06:46:19 katarynka go-librespot[14340]: go-librespot daemon starting... Mar 25 06:46:19 katarynka go-librespot[14341]: time="2026-03-25T06:46:19+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 06:46:19 katarynka go-librespot[14341]: time="2026-03-25T06:46:19+01:00" level=debug msg="app state loaded" Mar 25 06:46:19 katarynka go-librespot[14341]: time="2026-03-25T06:46:19+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 06:46:20 katarynka go-librespot[14341]: time="2026-03-25T06:46: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 25 06:46:20 katarynka go-librespot[14341]: time="2026-03-25T06:46:20+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 25 06:46:20 katarynka go-librespot[14341]: time="2026-03-25T06:46:20+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 25 06:46:20 katarynka go-librespot[14341]: time="2026-03-25T06:46:20+01:00" level=info msg="zeroconf server listening on port 46531" Mar 25 06:46:20 katarynka go-librespot[14341]: time="2026-03-25T06:46:20+01:00" level=debug msg="obtained new client token: AADsCTZWTxvIQTUTJZN7RCzUivQr6hjjBgOIBkDOk+vAmENR23dKZ+T2vxk2I9+UtRGPogfN8b7zLSzzxJ5TlkqZIE9bSt7reZscyGsXcZPfBsoGCjz45rH+SmA5bX6dvTLZdAb7mPHzCx2/tfHfwXnIa0Cj3qoRfeFFLZhOzRR7kcUi5q9OPKXKBwBK4UuF5ZQ3eLz8khOvB/vMrvtMnefUHXmroDCD/2/uXcWwbtq3MP1qTDeDCcSQ58U=" Mar 25 06:46:20 katarynka go-librespot[14341]: time="2026-03-25T06:46:20+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 06:46:20 katarynka go-librespot[14341]: time="2026-03-25T06:46:20+01:00" level=debug msg="completed keyexchange" Mar 25 06:46:20 katarynka go-librespot[14341]: time="2026-03-25T06:46:20+01:00" level=debug msg="completed challenge" Mar 25 06:46:20 katarynka go-librespot[14341]: time="2026-03-25T06:46: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 25 06:46:20 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 06:46:20 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 06:46:22 katarynka volumio[14259]: info: Starting UPNP Browser Mar 25 06:46:22 katarynka volumio[14259]: info: Loading plugin "alarm-clock"... Mar 25 06:46:22 katarynka volumio[14259]: info: Loading plugin "airplay_emulation"... Mar 25 06:46:22 katarynka volumio[14259]: info: Starting Shairport Sync Mar 25 06:46:22 katarynka volumio[14259]: info: Loading plugin "last_100"... Mar 25 06:46:22 katarynka volumio[14259]: info: Loading plugin "webradio"... Mar 25 06:46:23 katarynka volumio[14259]: info: Loading plugin "i2s_dacs"... Mar 25 06:46:23 katarynka volumio[14259]: info: Loading plugin "volumiodiscovery"... Mar 25 06:46:23 katarynka volumio[14259]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Mar 25 06:46:23 katarynka volumio[14259]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 25 06:46:23 katarynka volumio[14259]: *** WARNING *** For more information see Mar 25 06:46:23 katarynka volumio[14259]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Mar 25 06:46:23 katarynka volumio[14259]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 25 06:46:23 katarynka volumio[14259]: *** WARNING *** For more information see Mar 25 06:46:23 katarynka node[14259]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Mar 25 06:46:23 katarynka node[14259]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 25 06:46:23 katarynka node[14259]: *** WARNING *** For more information see Mar 25 06:46:23 katarynka node[14259]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Mar 25 06:46:23 katarynka node[14259]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 25 06:46:23 katarynka node[14259]: *** WARNING *** For more information see Mar 25 06:46:23 katarynka volumio[14259]: info: Applying required configuration parameters for plugin volumiodiscovery Mar 25 06:46:23 katarynka volumio[14259]: info: Discovery: Started advertising with name: katarynka Mar 25 06:46:23 katarynka volumio[14259]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 25 06:46:23 katarynka volumio[14259]: info: Loading plugin "spop"... Mar 25 06:46:23 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 17. Mar 25 06:46:23 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 06:46:23 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 06:46:23 katarynka go-librespot[14350]: go-librespot daemon starting... Mar 25 06:46:23 katarynka go-librespot[14351]: time="2026-03-25T06:46:23+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 06:46:23 katarynka go-librespot[14351]: time="2026-03-25T06:46:23+01:00" level=debug msg="app state loaded" Mar 25 06:46:23 katarynka go-librespot[14351]: time="2026-03-25T06:46:23+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 06:46:24 katarynka go-librespot[14351]: time="2026-03-25T06:46: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-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 25 06:46:24 katarynka go-librespot[14351]: time="2026-03-25T06:46:24+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 25 06:46:24 katarynka go-librespot[14351]: time="2026-03-25T06:46:24+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 25 06:46:24 katarynka go-librespot[14351]: time="2026-03-25T06:46:24+01:00" level=info msg="zeroconf server listening on port 40907" Mar 25 06:46:24 katarynka go-librespot[14351]: time="2026-03-25T06:46:24+01:00" level=debug msg="obtained new client token: AACeBjIpdoBlR2BQfbNPz14oH3WaFkDbNVDOliR6WjuWZBR2xgGycB2PeBRDk3h8ldj810Y97u0tX8ivbpkNZ+ePzoTjYvy0Rof6W/cXmq3uB/wVnjzcd7gQiAp1nhTh7T8X5e5RT71SJVR+tuyYSEOKMFaSbIF/hIb1Eoq+Wck7ptkF7apq9ETP5DNwQA/MxunMBjqt1dnznk8Eyu00NQ2Rda8DkQMVMAficsMwMQgvcNu4vCDxk/zp97s=" Mar 25 06:46:24 katarynka go-librespot[14351]: time="2026-03-25T06:46:24+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 06:46:24 katarynka go-librespot[14351]: time="2026-03-25T06:46:24+01:00" level=debug msg="completed keyexchange" Mar 25 06:46:24 katarynka go-librespot[14351]: time="2026-03-25T06:46:24+01:00" level=debug msg="completed challenge" Mar 25 06:46:24 katarynka go-librespot[14351]: time="2026-03-25T06:46: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 25 06:46:24 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 06:46:24 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 06:46:25 katarynka volumio[14259]: info: Loading plugin "outputs"... Mar 25 06:46:25 katarynka volumio[14259]: info: Loading plugin "albumart"... Mar 25 06:46:25 katarynka volumio[14259]: info: Plugin example_plugin is not enabled Mar 25 06:46:25 katarynka volumio[14259]: info: Loading plugin "inputs"... Mar 25 06:46:25 katarynka volumio[14259]: info: Loading plugin "updater_comm"... Mar 25 06:46:25 katarynka volumio[14259]: info: Plugin mpdemulation is not enabled Mar 25 06:46:25 katarynka volumio[14259]: info: Loading plugin "rest_api"... Mar 25 06:46:25 katarynka volumio[14259]: info: Loading plugin "websocket"... Mar 25 06:46:25 katarynka volumio[14259]: info: Starting Socket.io Server version 1.7.4 Mar 25 06:46:25 katarynka volumio[14259]: info: Loading i18n strings for locale pl Mar 25 06:46:25 katarynka volumio[14259]: Updating browse sources language Mar 25 06:46:25 katarynka volumio[14259]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 25 06:46:26 katarynka volumio[14259]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 25 06:46:26 katarynka volumio[14259]: info: CoreCommandRouter::initPlayerControls Mar 25 06:46:26 katarynka volumio[14259]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 06:46:26 katarynka volumio[14259]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 06:46:26 katarynka volumio[14259]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 06:46:26 katarynka volumio[14259]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 06:46:26 katarynka volumio[14259]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 06:46:26 katarynka volumio[14259]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 06:46:26 katarynka volumio[14259]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 06:46:26 katarynka volumio[14259]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 06:46:26 katarynka volumio[14259]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 25 06:46:26 katarynka volumio[14259]: Express server listening on port 3000 Mar 25 06:46:26 katarynka volumio[14259]: [Metrics] WebUI: 12s 524.55ms Mar 25 06:46:26 katarynka volumio[14259]: info: CoreStateMachine::resetVolumioState Mar 25 06:46:26 katarynka volumio[14259]: info: CoreStateMachine::getcurrentVolume Mar 25 06:46:26 katarynka volumio[14259]: info: CoreCommandRouter::volumioRetrievevolume Mar 25 06:46:26 katarynka volumio[14259]: info: Cannot read play queue from file Mar 25 06:46:26 katarynka volumio[14259]: info: Volumio Network Manager: Network status updated: 2 Mar 25 06:46:26 katarynka volumio[14259]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 06:46:26 katarynka volumio[14259]: info: CoreStateMachine::setRepeat null single undefined Mar 25 06:46:26 katarynka volumio[14259]: info: CoreStateMachine::pushState Mar 25 06:46:26 katarynka volumio[14259]: info: CorePlayQueue::getTrack 0 Mar 25 06:46:26 katarynka volumio[14259]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 25 06:46:26 katarynka volumio[14259]: info: CoreCommandRouter::volumioPushState Mar 25 06:46:26 katarynka volumio[14358]: Forking 3 albumart workers Mar 25 06:46:26 katarynka volumio[14259]: info: CoreStateMachine::setRandom null Mar 25 06:46:26 katarynka volumio[14259]: info: CoreStateMachine::pushState Mar 25 06:46:26 katarynka volumio[14259]: info: CorePlayQueue::getTrack 0 Mar 25 06:46:26 katarynka volumio[14259]: info: CoreCommandRouter::volumioPushState Mar 25 06:46:26 katarynka volumio[14259]: info: Setting Device type: Raspberry PI Mar 25 06:46:26 katarynka volumio[14259]: info: Completed loading Core Plugins Mar 25 06:46:26 katarynka volumio[14259]: info: Preparing to generate the ALSA configuration file Mar 25 06:46:26 katarynka volumio[14259]: info: VolumeController:: Volume=96 Mute =false Mar 25 06:46:26 katarynka volumio[14259]: info: CoreStateMachine::pushState Mar 25 06:46:26 katarynka volumio[14259]: info: CorePlayQueue::getTrack 0 Mar 25 06:46:26 katarynka volumio[14259]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 25 06:46:26 katarynka volumio[14259]: info: CoreCommandRouter::volumioPushState Mar 25 06:46:26 katarynka volumio[14259]: info: CoreStateMachine::updateTrackBlock Mar 25 06:46:26 katarynka volumio[14259]: info: CorePlayQueue::getTrackBlock Mar 25 06:46:26 katarynka volumio[14259]: info: CoreCommandRouter::volumioRetrievevolume Mar 25 06:46:26 katarynka volumio[14259]: info: Asound.conf file unchanged, so no further update is needed Mar 25 06:46:26 katarynka volumio[14259]: info: Output device has changed, restarting MPD Mar 25 06:46:26 katarynka volumio[14259]: info: Output device has changed, restarting Shairport Sync Mar 25 06:46:26 katarynka volumio[14259]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 06:46:26 katarynka volumio[14259]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 06:46:26 katarynka sudo[14413]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 25 06:46:26 katarynka sudo[14410]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 25 06:46:26 katarynka sudo[14413]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 06:46:26 katarynka sudo[14410]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 06:46:26 katarynka sudo[14410]: pam_unix(sudo:session): session closed for user root Mar 25 06:46:26 katarynka volumio[14259]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 25 06:46:27 katarynka volumio[14259]: info: ___________ START PLUGINS ___________ Mar 25 06:46:27 katarynka volumio[14259]: info: ControllerMpd::onStart: Initializing MPD Mar 25 06:46:27 katarynka volumio[14259]: info: Creating MPD Configuration file Mar 25 06:46:27 katarynka volumio[14259]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 25 06:46:27 katarynka volumio[14259]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 25 06:46:27 katarynka volumio[14259]: info: [1774417587076] CoreMusicLibrary::Adding element Serwery Mediów Mar 25 06:46:27 katarynka volumio[14259]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 25 06:46:27 katarynka systemd[1]: Stopping mpd.service - Music Player Daemon... Mar 25 06:46:27 katarynka volumio[14259]: info: UPNP Browser: Client initialized successfully Mar 25 06:46:27 katarynka sudo[14424]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 25 06:46:27 katarynka sudo[14424]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 06:46:27 katarynka sudo[14422]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 25 06:46:27 katarynka sudo[14422]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 06:46:27 katarynka systemd[1]: mpd.service: Deactivated successfully. Mar 25 06:46:27 katarynka systemd[1]: Stopped mpd.service - Music Player Daemon. Mar 25 06:46:27 katarynka systemd[1]: mpd.service: Consumed 7.800s CPU time. Mar 25 06:46:27 katarynka sudo[14422]: pam_unix(sudo:session): session closed for user root Mar 25 06:46:27 katarynka volumio[14259]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 06:46:27 katarynka volumio[14259]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 06:46:27 katarynka systemd[1]: mpd.socket: Deactivated successfully. Mar 25 06:46:27 katarynka systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Mar 25 06:46:27 katarynka systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Mar 25 06:46:27 katarynka volumio[14259]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 25 06:46:27 katarynka volumio[14259]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 06:46:27 katarynka volumio[14259]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 06:46:27 katarynka systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Mar 25 06:46:27 katarynka volumio[14259]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 25 06:46:27 katarynka volumio[14259]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 25 06:46:27 katarynka volumio[14259]: info: [1774417587424] CoreMusicLibrary::Adding element Last_100 Mar 25 06:46:27 katarynka volumio[14259]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 25 06:46:27 katarynka systemd[1]: Starting mpd.service - Music Player Daemon... Mar 25 06:46:27 katarynka volumio[14259]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 25 06:46:27 katarynka systemd[1]: mpd.service: Deactivated successfully. Mar 25 06:46:27 katarynka systemd[1]: Stopped mpd.service - Music Player Daemon. Mar 25 06:46:27 katarynka systemd[1]: mpd.socket: Deactivated successfully. Mar 25 06:46:27 katarynka volumio[14259]: info: [1774417587488] CoreMusicLibrary::Adding element Webradio Mar 25 06:46:27 katarynka volumio[14259]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 25 06:46:27 katarynka systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Mar 25 06:46:27 katarynka systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Mar 25 06:46:27 katarynka systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Mar 25 06:46:27 katarynka systemd[1]: Starting mpd.service - Music Player Daemon... Mar 25 06:46:27 katarynka volumio[14259]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 25 06:46:27 katarynka volumio[14259]: info: Initializing BBC Radios Mar 25 06:46:27 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 18. Mar 25 06:46:27 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 06:46:27 katarynka volumio[14259]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 25 06:46:27 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 06:46:27 katarynka go-librespot[14449]: go-librespot daemon starting... Mar 25 06:46:27 katarynka volumio[14259]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 06:46:27 katarynka volumio[14259]: info: Creating Spotify config file Mar 25 06:46:27 katarynka volumio[14259]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 06:46:27 katarynka go-librespot[14453]: time="2026-03-25T06:46:27+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 06:46:27 katarynka go-librespot[14453]: time="2026-03-25T06:46:27+01:00" level=debug msg="app state loaded" Mar 25 06:46:27 katarynka go-librespot[14453]: time="2026-03-25T06:46:27+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 06:46:28 katarynka volumio-remote-updater[622]: [2026-03-25 06:46:28] [connect] Successful connection Mar 25 06:46:28 katarynka sudo[14438]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Mar 25 06:46:28 katarynka sudo[14438]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Mar 25 06:46:28 katarynka sudo[14438]: pam_unix(sudo:session): session closed for user root Mar 25 06:46:28 katarynka go-librespot[14453]: time="2026-03-25T06:46: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 25 06:46:28 katarynka go-librespot[14453]: time="2026-03-25T06:46: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 25 06:46:28 katarynka go-librespot[14453]: time="2026-03-25T06:46: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 25 06:46:28 katarynka go-librespot[14453]: time="2026-03-25T06:46:28+01:00" level=info msg="zeroconf server listening on port 44639" Mar 25 06:46:28 katarynka go-librespot[14453]: time="2026-03-25T06:46:28+01:00" level=debug msg="obtained new client token: AADKiysO4Jw8u5mcABgI2jjV1hq0MbIqKX/DetLyQoYBjIVkkaWnfT85NMnlJHs1XvFs/wMIqerbnVon75WTsIe0iddtAz158ywuODDeWBdvdpuEjaaQWIb2uon1cWY2lQRASlHkA8AeeLL5Rwxa7DbG8Wjcki/NiQNETIOdDI3iCtUQhauqe27zkbi030V6WhA3o4h1HX0GyJtNIoZLPyuZHjgUNqXjzpR23AfBgtyLjBJEEF4Pmci8uJA=" Mar 25 06:46:28 katarynka go-librespot[14453]: time="2026-03-25T06:46:28+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 06:46:28 katarynka go-librespot[14453]: time="2026-03-25T06:46:28+01:00" level=debug msg="completed keyexchange" Mar 25 06:46:29 katarynka go-librespot[14453]: time="2026-03-25T06:46:28+01:00" level=debug msg="completed challenge" Mar 25 06:46:29 katarynka go-librespot[14453]: time="2026-03-25T06:46: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 25 06:46:29 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 06:46:29 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 06:46:29 katarynka volumio[14259]: info: Volumio Calling Home Mar 25 06:46:30 katarynka volumio[14259]: info: Discovery: adding 4d616d77-6a8c-4da2-85a4-840d70f98e51 Mar 25 06:46:30 katarynka volumio[14259]: info: Discovery: Found device katarynka Mar 25 06:46:30 katarynka volumio[14259]: info: CoreCommandRouter::volumioGetState Mar 25 06:46:30 katarynka volumio[14259]: info: CorePlayQueue::getTrack 0 Mar 25 06:46:30 katarynka sudo[14481]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 25 06:46:30 katarynka sudo[14481]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 06:46:30 katarynka volumio[14259]: info: Discovery: this is already registered, 4d616d77-6a8c-4da2-85a4-840d70f98e51 Mar 25 06:46:30 katarynka volumio[14259]: info: Discovery: Found device katarynka Mar 25 06:46:30 katarynka volumio[14259]: info: CoreCommandRouter::volumioGetState Mar 25 06:46:30 katarynka volumio[14259]: info: CorePlayQueue::getTrack 0 Mar 25 06:46:30 katarynka sudo[14481]: pam_unix(sudo:session): session closed for user root Mar 25 06:46:30 katarynka sudo[14483]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 25 06:46:30 katarynka sudo[14483]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 06:46:30 katarynka volumio[14259]: info: MPD Permissions set Mar 25 06:46:30 katarynka volumio[14259]: info: MPD Permissions set Mar 25 06:46:30 katarynka volumio[14259]: info: VolumeController:: Volume=96 Mute =false Mar 25 06:46:30 katarynka volumio[14259]: info: CoreStateMachine::pushState Mar 25 06:46:30 katarynka volumio[14259]: info: CorePlayQueue::getTrack 0 Mar 25 06:46:30 katarynka volumio[14259]: info: CoreCommandRouter::volumioPushState Mar 25 06:46:30 katarynka sudo[14483]: pam_unix(sudo:session): session closed for user root Mar 25 06:46:30 katarynka volumio-remote-updater[622]: [2026-03-25 06:46:30] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1774417588 101 Mar 25 06:46:30 katarynka volumio[14259]: 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 25 06:46:30 katarynka volumio[14259]: info: Spotify config file written Mar 25 06:46:30 katarynka volumio[14380]: Starting albumart workers Mar 25 06:46:30 katarynka sudo[14487]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Mar 25 06:46:30 katarynka sudo[14487]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 06:46:30 katarynka volumio[14259]: 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 25 06:46:30 katarynka volumio[14259]: info: Volumio called home Mar 25 06:46:30 katarynka volumio[14259]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 06:46:30 katarynka volumio[14259]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 06:46:30 katarynka volumio[14259]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 06:46:30 katarynka volumio[14259]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 06:46:30 katarynka volumio[14259]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 06:46:30 katarynka volumio[14259]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 06:46:30 katarynka volumio[14259]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 06:46:30 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 06:46:30 katarynka volumio[14259]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 06:46:30 katarynka volumio[14259]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 06:46:30 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 06:46:30 katarynka volumio[14259]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 06:46:30 katarynka go-librespot[14490]: go-librespot daemon starting... Mar 25 06:46:30 katarynka volumio[14259]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 06:46:30 katarynka volumio[14259]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 06:46:30 katarynka volumio[14259]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 06:46:30 katarynka volumio[14259]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 06:46:30 katarynka volumio[14259]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 06:46:30 katarynka volumio[14259]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 06:46:30 katarynka volumio[14259]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 06:46:30 katarynka volumio[14259]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 06:46:30 katarynka sudo[14487]: pam_unix(sudo:session): session closed for user root Mar 25 06:46:31 katarynka go-librespot[14495]: time="2026-03-25T06:46:31+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 06:46:31 katarynka go-librespot[14495]: time="2026-03-25T06:46:31+01:00" level=debug msg="app state loaded" Mar 25 06:46:31 katarynka go-librespot[14495]: time="2026-03-25T06:46:31+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 06:46:31 katarynka volumio[14379]: Starting albumart workers Mar 25 06:46:31 katarynka volumio[14259]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 06:46:31 katarynka volumio[14259]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 06:46:31 katarynka volumio[14378]: Starting albumart workers Mar 25 06:46:31 katarynka volumio[14259]: info: No need to fix Spotify hosts Mar 25 06:46:31 katarynka go-librespot[14495]: time="2026-03-25T06:46:31+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 25 06:46:31 katarynka go-librespot[14495]: time="2026-03-25T06:46:31+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 25 06:46:31 katarynka go-librespot[14495]: time="2026-03-25T06:46:31+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 25 06:46:31 katarynka go-librespot[14495]: time="2026-03-25T06:46:31+01:00" level=info msg="zeroconf server listening on port 44357" Mar 25 06:46:31 katarynka go-librespot[14495]: time="2026-03-25T06:46:31+01:00" level=debug msg="obtained new client token: AAB9lE5n2BCbK1JNPQ7abvEhMD5KviTG35xxaALXUdt1F24kynBCVH5m4uUpCoHAluggGMiKsfTc1NZ28gktMxTdCCXr+/tgYxG99LQQwjRtAyTUng6cBzmSYDGGL8KYbl+PFvW3NRSy88IRKoocVPYDUKiNaQRimEp4uF2LY9mDtvTDsVyCvVBz2z8dCZDCoFq80gJI2BUMfRSKhx4unp1MfoqTKATrUeSMERU0bzSfVPP/xjKM5z0Qw/o=" Mar 25 06:46:32 katarynka go-librespot[14495]: time="2026-03-25T06:46:32+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 06:46:32 katarynka volumio[14259]: info: Starting Shairport Sync Mar 25 06:46:32 katarynka go-librespot[14495]: time="2026-03-25T06:46:32+01:00" level=debug msg="completed keyexchange" Mar 25 06:46:32 katarynka go-librespot[14495]: time="2026-03-25T06:46:32+01:00" level=debug msg="completed challenge" Mar 25 06:46:32 katarynka volumio[14259]: info: Starting Shairport Sync Mar 25 06:46:32 katarynka volumio[14259]: info: Starting Shairport Sync Mar 25 06:46:32 katarynka go-librespot[14495]: time="2026-03-25T06:46: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 25 06:46:32 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 06:46:32 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 06:46:32 katarynka sudo[14508]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 25 06:46:32 katarynka sudo[14508]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 06:46:32 katarynka sudo[14510]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 25 06:46:32 katarynka sudo[14510]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 06:46:32 katarynka sudo[14515]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 25 06:46:32 katarynka systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Mar 25 06:46:32 katarynka systemd[1]: shairport-sync.service: Deactivated successfully. Mar 25 06:46:32 katarynka systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 25 06:46:32 katarynka systemd[1]: shairport-sync.service: Consumed 2.295s CPU time. Mar 25 06:46:32 katarynka sudo[14514]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Mar 25 06:46:32 katarynka sudo[14515]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 06:46:32 katarynka sudo[14514]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 06:46:32 katarynka systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 25 06:46:32 katarynka sudo[14508]: pam_unix(sudo:session): session closed for user root Mar 25 06:46:32 katarynka systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Mar 25 06:46:32 katarynka sudo[14514]: pam_unix(sudo:session): session closed for user root Mar 25 06:46:32 katarynka systemd[1]: shairport-sync.service: Deactivated successfully. Mar 25 06:46:32 katarynka systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 25 06:46:32 katarynka volumio[14259]: info: CoreCommandRouter::volumioGetState Mar 25 06:46:32 katarynka volumio[14259]: info: CorePlayQueue::getTrack 0 Mar 25 06:46:32 katarynka volumio[14259]: info: Shairport-Sync Started Mar 25 06:46:32 katarynka volumio[14259]: Error adding Membership: Error: addMembership EINVAL Mar 25 06:46:32 katarynka systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 25 06:46:32 katarynka volumio[14259]: info: An error occurred while refreshing Spotify Token Error: Bad Request Mar 25 06:46:33 katarynka sudo[14515]: pam_unix(sudo:session): session closed for user root Mar 25 06:46:33 katarynka sudo[14510]: pam_unix(sudo:session): session closed for user root Mar 25 06:46:33 katarynka volumio[14259]: info: Upmpdcli Daemon Started Mar 25 06:46:33 katarynka volumio[14259]: info: Shairport-Sync Started Mar 25 06:46:33 katarynka volumio[14259]: info: Shairport-Sync Started Mar 25 06:46:35 katarynka volumio[14259]: info: go-librespot daemon successfully initialized Mar 25 06:46:35 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 19. Mar 25 06:46:35 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 06:46:35 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 06:46:35 katarynka go-librespot[14567]: go-librespot daemon starting... Mar 25 06:46:35 katarynka go-librespot[14568]: time="2026-03-25T06:46:35+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 06:46:35 katarynka go-librespot[14568]: time="2026-03-25T06:46:35+01:00" level=debug msg="app state loaded" Mar 25 06:46:35 katarynka go-librespot[14568]: time="2026-03-25T06:46:35+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 06:46:35 katarynka mpd[14460]: 2026-03-25T06:46:35 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Mar 25 06:46:35 katarynka systemd[1]: Started mpd.service - Music Player Daemon. Mar 25 06:46:35 katarynka sudo[14413]: pam_unix(sudo:session): session closed for user root Mar 25 06:46:35 katarynka sudo[14424]: pam_unix(sudo:session): session closed for user root Mar 25 06:46:35 katarynka go-librespot[14568]: time="2026-03-25T06:46:35+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 25 06:46:35 katarynka go-librespot[14568]: time="2026-03-25T06:46:35+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 25 06:46:35 katarynka go-librespot[14568]: time="2026-03-25T06:46:35+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 25 06:46:35 katarynka go-librespot[14568]: time="2026-03-25T06:46:35+01:00" level=info msg="zeroconf server listening on port 33765" Mar 25 06:46:35 katarynka volumio[14259]: info: Completed starting Core Plugins Mar 25 06:46:35 katarynka volumio[14259]: info: ------------------------------------------- Mar 25 06:46:35 katarynka volumio[14259]: info: ----- MyVolumio plugins startup ---- Mar 25 06:46:35 katarynka volumio[14259]: info: ------------------------------------------- Mar 25 06:46:35 katarynka volumio[14259]: info: [MyVolumio PluginManager] Fetching plans data.... Mar 25 06:46:36 katarynka go-librespot[14568]: time="2026-03-25T06:46:36+01:00" level=debug msg="obtained new client token: AABOYRVTmFzrBxJselc3XFUnLnkvMQJdxr35WxZNRPeVA2FkQnkq5S+1eqwOD4iQWqMQ4H85xQ6Ph0GUkunSxhzNbg7GrNmayv9yV6wKv7zfHNc7k1edZIubr9m+6Fr42yfqv8/eZ1rd+NXLdHGywgfDw+UBGUflQvzltuwp2MvCZzt9v7lajj5ITvO7Gh7V7CcauZO2x0+8Ce0QllxEG8Vd2KOrCIjigt5hIHotxao4Ygm6CaQnTmeY" Mar 25 06:46:36 katarynka volumio[14259]: error: MPD error: The expression evaluated to a falsy value: Mar 25 06:46:36 katarynka volumio[14259]: assert.ok(self.idling) Mar 25 06:46:36 katarynka volumio[14259]: error: The expression evaluated to a falsy value: Mar 25 06:46:36 katarynka volumio[14259]: assert.ok(self.idling) Mar 25 06:46:36 katarynka volumio[14259]: error: updateQueue error: null Mar 25 06:46:36 katarynka go-librespot[14568]: time="2026-03-25T06:46:36+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 06:46:36 katarynka volumio[14259]: info: MPD running with PID14460 Mar 25 06:46:36 katarynka volumio[14259]: ,establishing connection Mar 25 06:46:36 katarynka volumio[14259]: error: updateQueue error: null Mar 25 06:46:36 katarynka go-librespot[14568]: time="2026-03-25T06:46:36+01:00" level=debug msg="completed keyexchange" Mar 25 06:46:36 katarynka go-librespot[14568]: time="2026-03-25T06:46:36+01:00" level=debug msg="completed challenge" Mar 25 06:46:36 katarynka go-librespot[14568]: time="2026-03-25T06:46: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 25 06:46:36 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 06:46:36 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 06:46:38 katarynka volumio[14259]: info: Initializing connection to go-librespot Websocket Mar 25 06:46:38 katarynka volumio[14259]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 25 06:46:38 katarynka sudo[14594]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Mar 25 06:46:39 katarynka sudo[14594]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 06:46:39 katarynka sudo[14596]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Mar 25 06:46:39 katarynka sudo[14596]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 06:46:39 katarynka systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Mar 25 06:46:39 katarynka systemd[1]: mpd_monitor.service: Deactivated successfully. Mar 25 06:46:39 katarynka systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Mar 25 06:46:39 katarynka systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Mar 25 06:46:39 katarynka sudo[14596]: pam_unix(sudo:session): session closed for user root Mar 25 06:46:39 katarynka sudo[14594]: pam_unix(sudo:session): session closed for user root Mar 25 06:46:39 katarynka volumio[14259]: info: Successfully started MPD Monitor Mar 25 06:46:39 katarynka volumio[14259]: info: Successfully started MPD Monitor Mar 25 06:46:39 katarynka mpd_monitor.sh[14599]: MPD Monitor Service: Starting MPD Monitor Service Mar 25 06:46:39 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 20. Mar 25 06:46:39 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 06:46:39 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 06:46:39 katarynka go-librespot[14603]: go-librespot daemon starting... Mar 25 06:46:39 katarynka go-librespot[14604]: time="2026-03-25T06:46:39+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 06:46:39 katarynka go-librespot[14604]: time="2026-03-25T06:46:39+01:00" level=debug msg="app state loaded" Mar 25 06:46:39 katarynka go-librespot[14604]: time="2026-03-25T06:46:39+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 06:46:39 katarynka go-librespot[14604]: time="2026-03-25T06:46:39+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 25 06:46:39 katarynka go-librespot[14604]: time="2026-03-25T06:46:39+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 25 06:46:39 katarynka go-librespot[14604]: time="2026-03-25T06:46:39+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 25 06:46:39 katarynka go-librespot[14604]: time="2026-03-25T06:46:39+01:00" level=info msg="zeroconf server listening on port 41453" Mar 25 06:46:40 katarynka go-librespot[14604]: time="2026-03-25T06:46:40+01:00" level=debug msg="obtained new client token: AACFqm5vFhoF88DfFJdhINjoQ6YNsDA+d/fulDksJfO0PEjN7rI2WD3X/YvY1akehtCUQWsFlpPCDvETi7JMMCg7wiWRvqz6RttplpndcKcixDnc2ExfdvXFiY4OjNfAe2w7AoLAMrYCNH/t/ZWsy48/t+GEL1mP+TLYUBgHsuE/0uYhNTUH9IjwGWjioYPyhqD+P5oyGMTj3iD4z0KK9JD48eDvDdm1e9a6GOOlj0cvTp6qEULu6iHd" Mar 25 06:46:40 katarynka go-librespot[14604]: time="2026-03-25T06:46:40+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 06:46:40 katarynka go-librespot[14604]: time="2026-03-25T06:46:40+01:00" level=debug msg="completed keyexchange" Mar 25 06:46:40 katarynka go-librespot[14604]: time="2026-03-25T06:46:40+01:00" level=debug msg="completed challenge" Mar 25 06:46:40 katarynka go-librespot[14604]: time="2026-03-25T06:46: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 25 06:46:40 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 06:46:40 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 06:46:41 katarynka volumio[14259]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Mar 25 06:46:41 katarynka volumio[14259]: info: Initializing connection to go-librespot Websocket Mar 25 06:46:41 katarynka volumio[14259]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 25 06:46:43 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 21. Mar 25 06:46:43 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 06:46:43 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 06:46:43 katarynka go-librespot[14612]: go-librespot daemon starting... Mar 25 06:46:43 katarynka go-librespot[14613]: time="2026-03-25T06:46:43+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 06:46:43 katarynka go-librespot[14613]: time="2026-03-25T06:46:43+01:00" level=debug msg="app state loaded" Mar 25 06:46:43 katarynka go-librespot[14613]: time="2026-03-25T06:46:43+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 06:46:43 katarynka go-librespot[14613]: time="2026-03-25T06:46:43+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 25 06:46:43 katarynka go-librespot[14613]: time="2026-03-25T06:46:43+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 25 06:46:43 katarynka go-librespot[14613]: time="2026-03-25T06:46:43+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 25 06:46:43 katarynka go-librespot[14613]: time="2026-03-25T06:46:43+01:00" level=info msg="zeroconf server listening on port 45705" Mar 25 06:46:44 katarynka volumio[14259]: info: Initializing connection to go-librespot Websocket Mar 25 06:46:44 katarynka go-librespot[14613]: time="2026-03-25T06:46:44+01:00" level=debug msg="new websocket client" Mar 25 06:46:44 katarynka go-librespot[14613]: time="2026-03-25T06:46:44+01:00" level=debug msg="obtained new client token: AAAonfUFafV8uWhKNE4cua53yJaPk90+H9gMjjbld5ZaTNwCynO+UZvjJfA5MGB2lkQvRUX6XqWVu3BKVJQGbGLIffNUUBGC28AMAGW+rycHY1bSMx8MCZID4M/+yHs/6TFztU0q4FVVlQBcFlK+ZID1zFajIvcutiQYD0OfhXp1fJzLeWypxae+vfafXcjTkfsxzhmlEpb7F8wuAl0At4VrgtSGGxG+KWtZGEWNuWAPlRb9L4HNHDpP" Mar 25 06:46:44 katarynka volumio[14259]: info: Connection to go-librespot Websocket established Mar 25 06:46:44 katarynka go-librespot[14613]: time="2026-03-25T06:46:44+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 06:46:44 katarynka go-librespot[14613]: time="2026-03-25T06:46:44+01:00" level=debug msg="completed keyexchange" Mar 25 06:46:44 katarynka go-librespot[14613]: time="2026-03-25T06:46:44+01:00" level=debug msg="completed challenge" Mar 25 06:46:44 katarynka go-librespot[14613]: time="2026-03-25T06:46:44+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 25 06:46:44 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 06:46:44 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 06:46:44 katarynka volumio[14259]: info: Connection to go-librespot Websocket closed Mar 25 06:46:44 katarynka volumio[14259]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Mar 25 06:46:44 katarynka volumio[14259]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Mar 25 06:46:44 katarynka volumio[14259]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Mar 25 06:46:44 katarynka volumio[14259]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Mar 25 06:46:44 katarynka volumio[14259]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Mar 25 06:46:44 katarynka volumio[14259]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Mar 25 06:46:44 katarynka volumio[14259]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Mar 25 06:46:44 katarynka volumio[14259]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Mar 25 06:46:44 katarynka volumio[14259]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Mar 25 06:46:44 katarynka volumio[14259]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Mar 25 06:46:44 katarynka volumio[14259]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Mar 25 06:46:44 katarynka volumio[14259]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Mar 25 06:46:44 katarynka volumio[14259]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Mar 25 06:46:44 katarynka volumio[14259]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Mar 25 06:46:44 katarynka volumio[14259]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Mar 25 06:46:44 katarynka volumio[14259]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Mar 25 06:46:44 katarynka volumio[14259]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Mar 25 06:46:44 katarynka volumio[14259]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Mar 25 06:46:44 katarynka volumio[14259]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Mar 25 06:46:44 katarynka volumio[14259]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Mar 25 06:46:44 katarynka volumio[14259]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Mar 25 06:46:44 katarynka volumio[14259]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Mar 25 06:46:44 katarynka volumio[14259]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Mar 25 06:46:44 katarynka volumio[14259]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Mar 25 06:46:44 katarynka volumio[14259]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Mar 25 06:46:44 katarynka volumio[14259]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Mar 25 06:46:44 katarynka volumio[14259]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Mar 25 06:46:44 katarynka volumio[14259]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Mar 25 06:46:44 katarynka volumio[14259]: info: Adding plugin bluetooth to MyMusic Plugins Mar 25 06:46:44 katarynka volumio[14259]: info: Adding plugin multiroom to MyMusic Plugins Mar 25 06:46:44 katarynka volumio[14259]: info: Adding plugin metavolumio to MyMusic Plugins Mar 25 06:46:44 katarynka volumio[14259]: info: Adding plugin cd_controller to MyMusic Plugins Mar 25 06:46:44 katarynka volumio[14259]: info: Adding plugin qobuzconnect to MyMusic Plugins Mar 25 06:46:44 katarynka volumio[14259]: info: Adding plugin smart_inputs to MyMusic Plugins Mar 25 06:46:44 katarynka volumio[14259]: info: Adding plugin tidalconnect to MyMusic Plugins Mar 25 06:46:44 katarynka volumio[14259]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Mar 25 06:46:46 katarynka volumio[14259]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Mar 25 06:46:46 katarynka volumio[14259]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Mar 25 06:46:46 katarynka volumio[14259]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 06:46:46 katarynka volumio[14259]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 06:46:46 katarynka volumio[14259]: info: Starting MyVolumio Remote Streaming Endpoints Mar 25 06:46:46 katarynka volumio[14259]: info: MyVolumio login type: Token Mar 25 06:46:46 katarynka volumio[14259]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Mar 25 06:46:46 katarynka volumio[14259]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Mar 25 06:46:47 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 22. Mar 25 06:46:47 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 06:46:47 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 06:46:47 katarynka go-librespot[14620]: go-librespot daemon starting... Mar 25 06:46:47 katarynka go-librespot[14621]: time="2026-03-25T06:46:47+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 06:46:47 katarynka go-librespot[14621]: time="2026-03-25T06:46:47+01:00" level=debug msg="app state loaded" Mar 25 06:46:47 katarynka go-librespot[14621]: time="2026-03-25T06:46:47+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 06:46:47 katarynka go-librespot[14621]: time="2026-03-25T06:46:47+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 25 06:46:47 katarynka go-librespot[14621]: time="2026-03-25T06:46:47+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 25 06:46:47 katarynka go-librespot[14621]: time="2026-03-25T06:46:47+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 25 06:46:47 katarynka go-librespot[14621]: time="2026-03-25T06:46:47+01:00" level=info msg="zeroconf server listening on port 45581" Mar 25 06:46:48 katarynka go-librespot[14621]: time="2026-03-25T06:46:48+01:00" level=debug msg="obtained new client token: AAAuooCBCt/Dej1W4hkD1LTaIcsyZ+IK3ChqYqHXkY44wooJqli2i6D2SWR4BepWCXRR8NkLuyFgQ6UM6CHVhqwixR/QfpW+ViHH8E3baPhLPKPU+SlPH02Y5eJNwZz4ZV6NUs297WkdR0mdwF1OLXQF9r7hq4ZSxHP3RIVejmqCd8j7JEJXeOzOSwY8I6o12vbLhcj36wM7SNfOJw0NmznB9ptFqbEWTiRYPUsvpkN36+gC4Y2MpAdU" Mar 25 06:46:48 katarynka go-librespot[14621]: time="2026-03-25T06:46:48+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 06:46:48 katarynka go-librespot[14621]: time="2026-03-25T06:46:48+01:00" level=debug msg="completed keyexchange" Mar 25 06:46:48 katarynka go-librespot[14621]: time="2026-03-25T06:46:48+01:00" level=debug msg="completed challenge" Mar 25 06:46:48 katarynka go-librespot[14621]: time="2026-03-25T06:46:48+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 25 06:46:48 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 06:46:48 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 06:46:48 katarynka volumio[14259]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Mar 25 06:46:48 katarynka volumio[14259]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Mar 25 06:46:48 katarynka volumio[14259]: info: Streaming services startup Mar 25 06:46:48 katarynka volumio[14259]: info: Starting Streaming Daemon Mar 25 06:46:48 katarynka sudo[14629]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Mar 25 06:46:48 katarynka sudo[14629]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 06:46:48 katarynka volumio[14259]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Mar 25 06:46:48 katarynka sudo[14629]: pam_unix(sudo:session): session closed for user root Mar 25 06:46:48 katarynka volumio[14259]: info: Getting Spotify volume Mar 25 06:46:48 katarynka volumio[14259]: info: Initializing connection to go-librespot Websocket Mar 25 06:46:48 katarynka volumio[14259]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 25 06:46:48 katarynka volumio[14259]: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 25 06:46:48 katarynka volumio[14259]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Mar 25 06:46:48 katarynka volumio[14259]: errno: -111, Mar 25 06:46:48 katarynka volumio[14259]: code: 'ECONNREFUSED', Mar 25 06:46:48 katarynka volumio[14259]: syscall: 'connect', Mar 25 06:46:48 katarynka volumio[14259]: address: '127.0.0.1', Mar 25 06:46:48 katarynka volumio[14259]: port: 9879, Mar 25 06:46:48 katarynka volumio[14259]: response: undefined Mar 25 06:46:48 katarynka volumio[14259]: } Mar 25 06:46:48 katarynka volumio[14259]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 25 06:46:50 katarynka sudo[14663]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-03-25 06:45' Mar 25 06:46:50 katarynka sudo[14663]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) PRETTY_NAME="Raspbian GNU/Linux 12 (bookworm)" NAME="Raspbian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="cfdc872d40b979cca36352a7333c940c38dc64b5" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="6cbc2303e10f00c3a01cb7f02c6d12448bd32c62" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri Dec 5 20:42:14 UTC 2025" VOLUMIO_VERSION="4.073" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="67fdc5f60f00b7a328ccd8c4ad441086"