Mar 25 10:37:00 katarynka volumio[32244]: info: Loading plugin "network"... Mar 25 10:37:00 katarynka volumio[32244]: info: Refreshing Cached IP Addresses Mar 25 10:37:00 katarynka sudo[32288]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 25 10:37:00 katarynka sudo[32288]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 10:37:00 katarynka sudo[32290]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 25 10:37:00 katarynka sudo[32290]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 10:37:00 katarynka volumio[32244]: info: Loading plugin "services"... Mar 25 10:37:00 katarynka sudo[32288]: pam_unix(sudo:session): session closed for user root Mar 25 10:37:00 katarynka volumio[32244]: info: Loading plugin "alsa_controller"... Mar 25 10:37:00 katarynka sudo[32290]: pam_unix(sudo:session): session closed for user root Mar 25 10:37:00 katarynka sudo[32298]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Mar 25 10:37:00 katarynka sudo[32298]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 10:37:00 katarynka volumio[32244]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 25 10:37:00 katarynka volumio[32244]: info: Loading plugin "wizard"... Mar 25 10:37:00 katarynka volumio[32244]: info: Loading plugin "networkfs"... Mar 25 10:37:00 katarynka volumio[32244]: info: Starting Udev Watcher for removable devices Mar 25 10:37:00 katarynka volumio[32244]: info: Ignoring mount for partition: boot Mar 25 10:37:00 katarynka volumio[32244]: info: Ignoring mount for partition: volumio Mar 25 10:37:00 katarynka volumio[32244]: info: Ignoring mount for partition: volumio_data Mar 25 10:37:00 katarynka volumio[32244]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 25 10:37:00 katarynka volumio[32244]: info: Loading plugin "volumio_command_line_client"... Mar 25 10:37:00 katarynka volumio[32244]: info: Loading plugin "upnp"... Mar 25 10:37:00 katarynka volumio[32244]: info: [1774431420844] Starting Upmpd Daemon Mar 25 10:37:00 katarynka volumio[32244]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 25 10:37:00 katarynka volumio[32244]: info: Loading plugin "my_music"... Mar 25 10:37:00 katarynka volumio[32244]: info: Loading plugin "mpd"... Mar 25 10:37:00 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Mar 25 10:37:00 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 10:37:00 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 10:37:00 katarynka go-librespot[32321]: go-librespot daemon starting... Mar 25 10:37:01 katarynka go-librespot[32322]: time="2026-03-25T10:37:01+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 10:37:01 katarynka go-librespot[32322]: time="2026-03-25T10:37:01+01:00" level=debug msg="app state loaded" Mar 25 10:37:01 katarynka go-librespot[32322]: time="2026-03-25T10:37:01+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 10:37:01 katarynka sudo[32298]: pam_unix(sudo:session): session closed for user root Mar 25 10:37:01 katarynka volumio[32244]: info: Loading plugin "upnp_browser"... Mar 25 10:37:01 katarynka go-librespot[32322]: time="2026-03-25T10:37:01+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 10:37:01 katarynka go-librespot[32322]: time="2026-03-25T10:37:01+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 10:37:01 katarynka go-librespot[32322]: time="2026-03-25T10:37:01+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 10:37:01 katarynka go-librespot[32322]: time="2026-03-25T10:37:01+01:00" level=info msg="zeroconf server listening on port 46375" Mar 25 10:37:01 katarynka go-librespot[32322]: time="2026-03-25T10:37:01+01:00" level=debug msg="obtained new client token: AAA16ljSPnzoS6oLOi6dbbNwP6C6qppsdmVp+qB7IOmMfQ5WzSIEve6Tx5F9oZ27hjX+rA0fE6XUgXVnSD6EUCF5aBptHFzCOAnNREQqrnFNkduW2f4xSu8jIVB77Ez1ecwM4HStX+kgXg37ZMUf+2CzV2Cj4msNRLU5Spmaj2tgE9II/rRE20/+n4PW14GNrwhFsqia521loVr3rMJGPhDDCIhD10/HmPEtGDuSyCkCOzuYxYbm+Uk5tek=" Mar 25 10:37:01 katarynka go-librespot[32322]: time="2026-03-25T10:37:01+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 10:37:01 katarynka go-librespot[32322]: time="2026-03-25T10:37:01+01:00" level=debug msg="completed keyexchange" Mar 25 10:37:01 katarynka go-librespot[32322]: time="2026-03-25T10:37:01+01:00" level=debug msg="completed challenge" Mar 25 10:37:01 katarynka go-librespot[32322]: time="2026-03-25T10:37: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 10:37:01 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 10:37:01 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 10:37:04 katarynka volumio[32244]: info: Starting UPNP Browser Mar 25 10:37:04 katarynka volumio[32244]: info: Loading plugin "alarm-clock"... Mar 25 10:37:04 katarynka volumio[32244]: info: Loading plugin "airplay_emulation"... Mar 25 10:37:04 katarynka volumio[32244]: info: Starting Shairport Sync Mar 25 10:37:04 katarynka volumio[32244]: info: Loading plugin "last_100"... Mar 25 10:37:05 katarynka volumio[32244]: info: Loading plugin "webradio"... Mar 25 10:37:05 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Mar 25 10:37:05 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 10:37:05 katarynka volumio[32244]: info: Loading plugin "i2s_dacs"... Mar 25 10:37:05 katarynka volumio[32244]: info: Loading plugin "volumiodiscovery"... Mar 25 10:37:05 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 10:37:05 katarynka go-librespot[32334]: go-librespot daemon starting... Mar 25 10:37:05 katarynka go-librespot[32335]: time="2026-03-25T10:37:05+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 10:37:05 katarynka go-librespot[32335]: time="2026-03-25T10:37:05+01:00" level=debug msg="app state loaded" Mar 25 10:37:05 katarynka go-librespot[32335]: time="2026-03-25T10:37:05+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 10:37:05 katarynka volumio[32244]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Mar 25 10:37:05 katarynka volumio[32244]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 25 10:37:05 katarynka volumio[32244]: *** WARNING *** For more information see Mar 25 10:37:05 katarynka volumio[32244]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Mar 25 10:37:05 katarynka volumio[32244]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 25 10:37:05 katarynka volumio[32244]: *** WARNING *** For more information see Mar 25 10:37:05 katarynka node[32244]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Mar 25 10:37:05 katarynka node[32244]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 25 10:37:05 katarynka node[32244]: *** WARNING *** For more information see Mar 25 10:37:05 katarynka node[32244]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Mar 25 10:37:05 katarynka node[32244]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 25 10:37:05 katarynka node[32244]: *** WARNING *** For more information see Mar 25 10:37:05 katarynka volumio[32244]: info: Applying required configuration parameters for plugin volumiodiscovery Mar 25 10:37:05 katarynka volumio[32244]: info: Discovery: Started advertising with name: katarynka Mar 25 10:37:05 katarynka volumio[32244]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 25 10:37:05 katarynka volumio[32244]: info: Loading plugin "spop"... Mar 25 10:37:05 katarynka go-librespot[32335]: time="2026-03-25T10:37: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-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 25 10:37:05 katarynka go-librespot[32335]: time="2026-03-25T10:37:05+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 10:37:05 katarynka go-librespot[32335]: time="2026-03-25T10:37:05+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 10:37:05 katarynka go-librespot[32335]: time="2026-03-25T10:37:05+01:00" level=info msg="zeroconf server listening on port 35177" Mar 25 10:37:05 katarynka go-librespot[32335]: time="2026-03-25T10:37:05+01:00" level=debug msg="obtained new client token: AADfktXkkA4xvV+LQZLphMtlGtS4Z5J2xa+AUlOIWwTPK1/DOulc/LJGvavZwKpcaOB8hVJUu7DtW13DNAIGVwNW1D3Ap3m48WBS/a/rnpUgyYhOSLkxQ7sEepp8HFiT/Pgqmx6met3CoKpX85B1Jd4bg+SOf6H7PxgGGjq1xESDur/rKu8MiE5CEJOmuMGAs46D0qt8a9nbaUAbQzfUVVhGUPkvZAJe00Ve9B0598TF/ftl2j2PtQx6ar4=" Mar 25 10:37:05 katarynka go-librespot[32335]: time="2026-03-25T10:37:05+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 10:37:06 katarynka go-librespot[32335]: time="2026-03-25T10:37:06+01:00" level=debug msg="completed keyexchange" Mar 25 10:37:06 katarynka go-librespot[32335]: time="2026-03-25T10:37:06+01:00" level=debug msg="completed challenge" Mar 25 10:37:06 katarynka go-librespot[32335]: time="2026-03-25T10:37:06+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 25 10:37:06 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 10:37:06 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 10:37:07 katarynka volumio[32244]: info: Loading plugin "outputs"... Mar 25 10:37:07 katarynka volumio[32244]: info: Loading plugin "albumart"... Mar 25 10:37:07 katarynka volumio[32244]: info: Plugin example_plugin is not enabled Mar 25 10:37:07 katarynka volumio[32244]: info: Loading plugin "inputs"... Mar 25 10:37:07 katarynka volumio[32244]: info: Loading plugin "updater_comm"... Mar 25 10:37:07 katarynka volumio[32244]: info: Plugin mpdemulation is not enabled Mar 25 10:37:07 katarynka volumio[32244]: info: Loading plugin "rest_api"... Mar 25 10:37:07 katarynka volumio[32244]: info: Loading plugin "websocket"... Mar 25 10:37:07 katarynka volumio[32244]: info: Starting Socket.io Server version 1.7.4 Mar 25 10:37:07 katarynka volumio[32244]: info: Loading i18n strings for locale pl Mar 25 10:37:07 katarynka volumio[32244]: Updating browse sources language Mar 25 10:37:07 katarynka volumio[32244]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 25 10:37:08 katarynka volumio[32244]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 25 10:37:08 katarynka volumio[32244]: info: CoreCommandRouter::initPlayerControls Mar 25 10:37:08 katarynka volumio[32244]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 10:37:08 katarynka volumio[32244]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 10:37:08 katarynka volumio[32244]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 10:37:08 katarynka volumio[32244]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 10:37:08 katarynka volumio[32244]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 10:37:08 katarynka volumio[32244]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 10:37:08 katarynka volumio[32244]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 10:37:08 katarynka volumio[32244]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 10:37:08 katarynka volumio[32244]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 25 10:37:08 katarynka volumio[32244]: Express server listening on port 3000 Mar 25 10:37:08 katarynka volumio[32244]: [Metrics] WebUI: 12s 589.80ms Mar 25 10:37:08 katarynka volumio[32244]: info: CoreStateMachine::resetVolumioState Mar 25 10:37:08 katarynka volumio[32244]: info: CoreStateMachine::getcurrentVolume Mar 25 10:37:08 katarynka volumio[32244]: info: CoreCommandRouter::volumioRetrievevolume Mar 25 10:37:08 katarynka volumio[32244]: info: Cannot read play queue from file Mar 25 10:37:08 katarynka volumio[32244]: info: Volumio Network Manager: Network status updated: 2 Mar 25 10:37:08 katarynka volumio[32345]: Forking 3 albumart workers Mar 25 10:37:08 katarynka volumio[32244]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 10:37:08 katarynka volumio[32244]: info: VolumeController:: Volume=96 Mute =false Mar 25 10:37:08 katarynka volumio[32244]: info: CoreStateMachine::pushState Mar 25 10:37:08 katarynka volumio[32244]: info: CorePlayQueue::getTrack 0 Mar 25 10:37:08 katarynka volumio[32244]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 25 10:37:08 katarynka volumio[32244]: info: CoreCommandRouter::volumioPushState Mar 25 10:37:08 katarynka volumio[32244]: info: CoreStateMachine::updateTrackBlock Mar 25 10:37:08 katarynka volumio[32244]: info: CorePlayQueue::getTrackBlock Mar 25 10:37:08 katarynka volumio[32244]: info: CoreCommandRouter::volumioRetrievevolume Mar 25 10:37:08 katarynka volumio[32244]: info: CoreStateMachine::setRepeat null single undefined Mar 25 10:37:08 katarynka volumio[32244]: info: CoreStateMachine::pushState Mar 25 10:37:08 katarynka volumio[32244]: info: CorePlayQueue::getTrack 0 Mar 25 10:37:08 katarynka volumio[32244]: info: CoreCommandRouter::volumioPushState Mar 25 10:37:08 katarynka volumio[32244]: info: CoreStateMachine::setRandom null Mar 25 10:37:08 katarynka volumio[32244]: info: CoreStateMachine::pushState Mar 25 10:37:08 katarynka volumio[32244]: info: CorePlayQueue::getTrack 0 Mar 25 10:37:08 katarynka volumio[32244]: info: CoreCommandRouter::volumioPushState Mar 25 10:37:08 katarynka volumio[32244]: info: Setting Device type: Raspberry PI Mar 25 10:37:08 katarynka volumio[32244]: info: Completed loading Core Plugins Mar 25 10:37:08 katarynka volumio[32244]: info: Preparing to generate the ALSA configuration file Mar 25 10:37:09 katarynka volumio[32244]: info: Discovery: adding 4d616d77-6a8c-4da2-85a4-840d70f98e51 Mar 25 10:37:09 katarynka volumio[32244]: info: Discovery: Found device katarynka Mar 25 10:37:09 katarynka volumio[32244]: info: CoreCommandRouter::volumioGetState Mar 25 10:37:09 katarynka volumio[32244]: info: CorePlayQueue::getTrack 0 Mar 25 10:37:09 katarynka volumio[32244]: info: Discovery: this is already registered, 4d616d77-6a8c-4da2-85a4-840d70f98e51 Mar 25 10:37:09 katarynka volumio[32244]: info: Discovery: Found device katarynka Mar 25 10:37:09 katarynka volumio[32244]: info: CoreCommandRouter::volumioGetState Mar 25 10:37:09 katarynka volumio[32244]: info: CorePlayQueue::getTrack 0 Mar 25 10:37:09 katarynka volumio[32244]: info: Asound.conf file unchanged, so no further update is needed Mar 25 10:37:09 katarynka volumio[32244]: info: Output device has changed, restarting MPD Mar 25 10:37:09 katarynka volumio[32244]: info: Output device has changed, restarting Shairport Sync Mar 25 10:37:09 katarynka volumio[32244]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 10:37:09 katarynka volumio[32244]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 10:37:09 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Mar 25 10:37:09 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 10:37:09 katarynka sudo[32400]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 25 10:37:09 katarynka sudo[32400]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 10:37:09 katarynka volumio[32244]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 25 10:37:09 katarynka volumio[32244]: info: ___________ START PLUGINS ___________ Mar 25 10:37:09 katarynka sudo[32400]: pam_unix(sudo:session): session closed for user root Mar 25 10:37:09 katarynka volumio[32244]: info: ControllerMpd::onStart: Initializing MPD Mar 25 10:37:09 katarynka volumio[32244]: info: Creating MPD Configuration file Mar 25 10:37:09 katarynka sudo[32402]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 25 10:37:09 katarynka sudo[32402]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 10:37:09 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 10:37:09 katarynka go-librespot[32407]: go-librespot daemon starting... Mar 25 10:37:09 katarynka volumio[32244]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 25 10:37:09 katarynka volumio[32244]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 25 10:37:09 katarynka volumio[32244]: info: [1774431429291] CoreMusicLibrary::Adding element Serwery Mediów Mar 25 10:37:09 katarynka volumio[32244]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 25 10:37:09 katarynka sudo[32411]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 25 10:37:09 katarynka sudo[32411]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 10:37:09 katarynka systemd[1]: Stopping mpd.service - Music Player Daemon... Mar 25 10:37:09 katarynka go-librespot[32413]: time="2026-03-25T10:37:09+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 10:37:09 katarynka go-librespot[32413]: time="2026-03-25T10:37:09+01:00" level=debug msg="app state loaded" Mar 25 10:37:09 katarynka go-librespot[32413]: time="2026-03-25T10:37:09+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 10:37:09 katarynka sudo[32411]: pam_unix(sudo:session): session closed for user root Mar 25 10:37:09 katarynka volumio[32244]: info: UPNP Browser: Client initialized successfully Mar 25 10:37:09 katarynka sudo[32414]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 25 10:37:09 katarynka sudo[32414]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 10:37:09 katarynka systemd[1]: mpd.service: Deactivated successfully. Mar 25 10:37:09 katarynka systemd[1]: Stopped mpd.service - Music Player Daemon. Mar 25 10:37:09 katarynka systemd[1]: mpd.service: Consumed 7.721s CPU time. Mar 25 10:37:09 katarynka systemd[1]: mpd.socket: Deactivated successfully. Mar 25 10:37:09 katarynka systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Mar 25 10:37:09 katarynka systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Mar 25 10:37:09 katarynka volumio[32244]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 10:37:09 katarynka volumio[32244]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 10:37:09 katarynka systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Mar 25 10:37:09 katarynka systemd[1]: Starting mpd.service - Music Player Daemon... Mar 25 10:37:09 katarynka volumio[32244]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 25 10:37:09 katarynka volumio[32244]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 10:37:09 katarynka volumio[32244]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 10:37:09 katarynka systemd[1]: mpd.service: Deactivated successfully. Mar 25 10:37:09 katarynka systemd[1]: Stopped mpd.service - Music Player Daemon. Mar 25 10:37:09 katarynka systemd[1]: mpd.socket: Deactivated successfully. Mar 25 10:37:09 katarynka systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Mar 25 10:37:09 katarynka systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Mar 25 10:37:09 katarynka volumio[32244]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 25 10:37:09 katarynka volumio[32244]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 25 10:37:09 katarynka volumio[32244]: info: [1774431429779] CoreMusicLibrary::Adding element Last_100 Mar 25 10:37:09 katarynka volumio[32244]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 25 10:37:09 katarynka volumio[32244]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 25 10:37:09 katarynka volumio[32244]: info: [1774431429807] CoreMusicLibrary::Adding element Webradio Mar 25 10:37:09 katarynka volumio[32244]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 25 10:37:09 katarynka systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Mar 25 10:37:09 katarynka volumio[32244]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 25 10:37:09 katarynka systemd[1]: Starting mpd.service - Music Player Daemon... Mar 25 10:37:09 katarynka volumio[32244]: info: Initializing BBC Radios Mar 25 10:37:10 katarynka go-librespot[32413]: time="2026-03-25T10:37:10+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 25 10:37:10 katarynka go-librespot[32413]: time="2026-03-25T10:37:10+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 10:37:10 katarynka go-librespot[32413]: time="2026-03-25T10:37:10+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 10:37:10 katarynka volumio-remote-updater[622]: [2026-03-25 10:37:10] [connect] Successful connection Mar 25 10:37:10 katarynka go-librespot[32413]: time="2026-03-25T10:37:10+01:00" level=info msg="zeroconf server listening on port 39841" Mar 25 10:37:10 katarynka volumio[32244]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 25 10:37:10 katarynka volumio[32244]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 10:37:10 katarynka volumio[32244]: info: Creating Spotify config file Mar 25 10:37:10 katarynka volumio[32244]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 10:37:10 katarynka go-librespot[32413]: time="2026-03-25T10:37:10+01:00" level=debug msg="obtained new client token: AACoxztnybsj7JPBP5++WQpfldEWd/U2uEA06NXw6PmhZqBWr5Bra4m+c9QZc87MbH0FVr3qK8FlRGWKebKyA8REnw6g2B/LDe92ZLCn68UaXLnrSmZxEerWMDNRMFuANvy39TzCH1OOsPNiRMA1iKu23/BKiJT+lX3M6TNBZqgdz+zpZwaxMWiYG+3hj9WtcsQAr3V0ZseZVKxTowciNwDVY7fvq7Bwxeu93RPw3lEvE3muQk+IUXyK" Mar 25 10:37:10 katarynka go-librespot[32413]: time="2026-03-25T10:37:10+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 10:37:10 katarynka sudo[32435]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Mar 25 10:37:10 katarynka sudo[32435]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Mar 25 10:37:10 katarynka go-librespot[32413]: time="2026-03-25T10:37:10+01:00" level=debug msg="completed keyexchange" Mar 25 10:37:10 katarynka go-librespot[32413]: time="2026-03-25T10:37:10+01:00" level=debug msg="completed challenge" Mar 25 10:37:10 katarynka sudo[32435]: pam_unix(sudo:session): session closed for user root Mar 25 10:37:10 katarynka go-librespot[32413]: time="2026-03-25T10:37:10+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 25 10:37:10 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 10:37:10 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 10:37:11 katarynka volumio[32244]: info: Volumio Calling Home Mar 25 10:37:12 katarynka volumio[32366]: Starting albumart workers Mar 25 10:37:12 katarynka sudo[32469]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 25 10:37:12 katarynka sudo[32469]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 10:37:12 katarynka sudo[32469]: pam_unix(sudo:session): session closed for user root Mar 25 10:37:12 katarynka volumio[32244]: info: MPD Permissions set Mar 25 10:37:12 katarynka volumio[32244]: info: MPD Permissions set Mar 25 10:37:12 katarynka sudo[32471]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 25 10:37:12 katarynka sudo[32471]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 10:37:12 katarynka volumio[32244]: info: VolumeController:: Volume=96 Mute =false Mar 25 10:37:12 katarynka volumio[32244]: info: CoreStateMachine::pushState Mar 25 10:37:12 katarynka volumio[32244]: info: CorePlayQueue::getTrack 0 Mar 25 10:37:12 katarynka volumio[32244]: info: CoreCommandRouter::volumioPushState Mar 25 10:37:12 katarynka sudo[32471]: pam_unix(sudo:session): session closed for user root Mar 25 10:37:12 katarynka volumio[32362]: Starting albumart workers Mar 25 10:37:12 katarynka volumio-remote-updater[622]: [2026-03-25 10:37:12] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1774431430 101 Mar 25 10:37:12 katarynka volumio[32244]: 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 10:37:12 katarynka volumio[32244]: info: Volumio called home Mar 25 10:37:12 katarynka volumio[32244]: info: Spotify config file written Mar 25 10:37:12 katarynka volumio[32363]: Starting albumart workers Mar 25 10:37:13 katarynka sudo[32475]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Mar 25 10:37:13 katarynka sudo[32475]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 10:37:13 katarynka volumio[32244]: 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 10:37:13 katarynka volumio[32244]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 10:37:13 katarynka volumio[32244]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 10:37:13 katarynka volumio[32244]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 10:37:13 katarynka volumio[32244]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 10:37:13 katarynka volumio[32244]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 10:37:13 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 10:37:13 katarynka volumio[32244]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 10:37:13 katarynka volumio[32244]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 10:37:13 katarynka volumio[32244]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 10:37:13 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 10:37:13 katarynka go-librespot[32477]: go-librespot daemon starting... Mar 25 10:37:13 katarynka volumio[32244]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 10:37:13 katarynka volumio[32244]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 10:37:13 katarynka volumio[32244]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 10:37:13 katarynka sudo[32475]: pam_unix(sudo:session): session closed for user root Mar 25 10:37:13 katarynka volumio[32244]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 10:37:13 katarynka volumio[32244]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 10:37:13 katarynka volumio[32244]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 10:37:13 katarynka volumio[32244]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 10:37:13 katarynka volumio[32244]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 10:37:13 katarynka volumio[32244]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 10:37:13 katarynka volumio[32244]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 10:37:13 katarynka go-librespot[32483]: time="2026-03-25T10:37:13+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 10:37:13 katarynka go-librespot[32483]: time="2026-03-25T10:37:13+01:00" level=debug msg="app state loaded" Mar 25 10:37:13 katarynka go-librespot[32483]: time="2026-03-25T10:37:13+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 10:37:13 katarynka volumio[32244]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 10:37:13 katarynka volumio[32244]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 10:37:13 katarynka volumio[32244]: info: No need to fix Spotify hosts Mar 25 10:37:13 katarynka go-librespot[32483]: time="2026-03-25T10:37:13+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 10:37:13 katarynka go-librespot[32483]: time="2026-03-25T10:37:13+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 10:37:13 katarynka go-librespot[32483]: time="2026-03-25T10:37:13+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 10:37:14 katarynka go-librespot[32483]: time="2026-03-25T10:37:14+01:00" level=info msg="zeroconf server listening on port 43837" Mar 25 10:37:14 katarynka go-librespot[32483]: time="2026-03-25T10:37:14+01:00" level=debug msg="obtained new client token: AACirhMZaXznZgqC929UNf8/wi1UqH9RPeq6goP9VhYrqOIse6hMLBZUAAvVHC72nh61d4psQtTFS+Qr+wDD8PR0j1NcUWZzYOGd4d2d5MAf63YZUmRei1MkU23qGs86P9iG/5gFpCHeGYyGpoPv9WbOU1OpqTMXzRTe1ob5RSVb5IFrBaAMMETXZVUt/icaQt8gyyXtIE296wQl+XNJVow+hPxz0jWpn9awE6SPFmvtXDZ0baDaQ/Vw" Mar 25 10:37:14 katarynka go-librespot[32483]: time="2026-03-25T10:37:14+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 10:37:14 katarynka volumio[32244]: info: Starting Shairport Sync Mar 25 10:37:14 katarynka volumio[32244]: info: Starting Shairport Sync Mar 25 10:37:14 katarynka go-librespot[32483]: time="2026-03-25T10:37:14+01:00" level=debug msg="completed keyexchange" Mar 25 10:37:14 katarynka go-librespot[32483]: time="2026-03-25T10:37:14+01:00" level=debug msg="completed challenge" Mar 25 10:37:14 katarynka volumio[32244]: info: Starting Shairport Sync Mar 25 10:37:14 katarynka go-librespot[32483]: time="2026-03-25T10:37:14+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 10:37:14 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 10:37:14 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 10:37:14 katarynka sudo[32500]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 25 10:37:14 katarynka sudo[32500]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 10:37:14 katarynka sudo[32498]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 25 10:37:14 katarynka sudo[32498]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 10:37:14 katarynka sudo[32503]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 25 10:37:14 katarynka sudo[32503]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 10:37:14 katarynka systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Mar 25 10:37:14 katarynka systemd[1]: shairport-sync.service: Deactivated successfully. Mar 25 10:37:14 katarynka systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 25 10:37:14 katarynka systemd[1]: shairport-sync.service: Consumed 2.369s CPU time. Mar 25 10:37:14 katarynka sudo[32507]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Mar 25 10:37:14 katarynka sudo[32507]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 10:37:14 katarynka systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 25 10:37:14 katarynka sudo[32500]: pam_unix(sudo:session): session closed for user root Mar 25 10:37:14 katarynka sudo[32498]: pam_unix(sudo:session): session closed for user root Mar 25 10:37:14 katarynka systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Mar 25 10:37:14 katarynka systemd[1]: shairport-sync.service: Deactivated successfully. Mar 25 10:37:14 katarynka systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 25 10:37:15 katarynka systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 25 10:37:15 katarynka sudo[32507]: pam_unix(sudo:session): session closed for user root Mar 25 10:37:15 katarynka sudo[32503]: pam_unix(sudo:session): session closed for user root Mar 25 10:37:15 katarynka volumio[32244]: info: Shairport-Sync Started Mar 25 10:37:15 katarynka volumio[32244]: Error adding Membership: Error: addMembership EINVAL Mar 25 10:37:15 katarynka volumio[32244]: info: Shairport-Sync Started Mar 25 10:37:15 katarynka volumio[32244]: info: An error occurred while refreshing Spotify Token Error: Bad Request Mar 25 10:37:15 katarynka volumio[32244]: info: Shairport-Sync Started Mar 25 10:37:15 katarynka volumio[32244]: info: Upmpdcli Daemon Started Mar 25 10:37:15 katarynka volumio[32244]: info: CoreCommandRouter::volumioGetState Mar 25 10:37:15 katarynka volumio[32244]: info: CorePlayQueue::getTrack 0 Mar 25 10:37:17 katarynka volumio[32244]: info: go-librespot daemon successfully initialized Mar 25 10:37:17 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Mar 25 10:37:17 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 10:37:17 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 10:37:17 katarynka go-librespot[32544]: go-librespot daemon starting... Mar 25 10:37:17 katarynka go-librespot[32545]: time="2026-03-25T10:37:17+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 10:37:17 katarynka go-librespot[32545]: time="2026-03-25T10:37:17+01:00" level=debug msg="app state loaded" Mar 25 10:37:17 katarynka go-librespot[32545]: time="2026-03-25T10:37:17+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 10:37:17 katarynka mpd[32450]: 2026-03-25T10:37:17 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Mar 25 10:37:18 katarynka systemd[1]: Started mpd.service - Music Player Daemon. Mar 25 10:37:18 katarynka sudo[32414]: pam_unix(sudo:session): session closed for user root Mar 25 10:37:18 katarynka sudo[32402]: pam_unix(sudo:session): session closed for user root Mar 25 10:37:18 katarynka volumio[32244]: info: Completed starting Core Plugins Mar 25 10:37:18 katarynka volumio[32244]: info: ------------------------------------------- Mar 25 10:37:18 katarynka volumio[32244]: info: ----- MyVolumio plugins startup ---- Mar 25 10:37:18 katarynka volumio[32244]: info: ------------------------------------------- Mar 25 10:37:18 katarynka volumio[32244]: info: [MyVolumio PluginManager] Fetching plans data.... Mar 25 10:37:18 katarynka go-librespot[32545]: time="2026-03-25T10:37: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-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 25 10:37:18 katarynka go-librespot[32545]: time="2026-03-25T10:37:18+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 10:37:18 katarynka go-librespot[32545]: time="2026-03-25T10:37:18+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 10:37:18 katarynka go-librespot[32545]: time="2026-03-25T10:37:18+01:00" level=info msg="zeroconf server listening on port 42273" Mar 25 10:37:18 katarynka volumio[32244]: error: MPD error: The expression evaluated to a falsy value: Mar 25 10:37:18 katarynka volumio[32244]: assert.ok(self.idling) Mar 25 10:37:18 katarynka volumio[32244]: error: The expression evaluated to a falsy value: Mar 25 10:37:18 katarynka volumio[32244]: assert.ok(self.idling) Mar 25 10:37:18 katarynka volumio[32244]: info: MPD running with PID32450 Mar 25 10:37:18 katarynka volumio[32244]: ,establishing connection Mar 25 10:37:18 katarynka volumio[32244]: error: updateQueue error: null Mar 25 10:37:18 katarynka volumio[32244]: error: updateQueue error: null Mar 25 10:37:18 katarynka go-librespot[32545]: time="2026-03-25T10:37:18+01:00" level=debug msg="obtained new client token: AAA4qPm3Y1EFqWF3HtAVIWt1OOybSa+LaL7QkGVouQlOVyowKMBJ8HNRvvLKKbUJk5FWP6YL7gkxq3rNFYdYpYxTu46E/RK0V1ENZQlF3lB8tRTw8SRxlHbYstZfbMFjLktnWODDrOy2zPmOI0ogJen3qgsNQV+BmfWsrIb/CCJ+PEGqmevNUahDF+54yo7V1r6dMJM6DrWtKWACaGQskDGQ098LpHpfw6w5ZuETTbxt7eOFq86zMhPhaDs=" Mar 25 10:37:18 katarynka go-librespot[32545]: time="2026-03-25T10:37:18+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 10:37:19 katarynka go-librespot[32545]: time="2026-03-25T10:37:19+01:00" level=debug msg="completed keyexchange" Mar 25 10:37:19 katarynka go-librespot[32545]: time="2026-03-25T10:37:19+01:00" level=debug msg="completed challenge" Mar 25 10:37:19 katarynka go-librespot[32545]: time="2026-03-25T10:37: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 10:37:19 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 10:37:19 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 10:37:20 katarynka volumio[32244]: info: Initializing connection to go-librespot Websocket Mar 25 10:37:20 katarynka volumio[32244]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 25 10:37:21 katarynka sudo[32574]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Mar 25 10:37:21 katarynka sudo[32574]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 10:37:21 katarynka sudo[32577]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Mar 25 10:37:21 katarynka sudo[32577]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 10:37:21 katarynka systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Mar 25 10:37:21 katarynka systemd[1]: mpd_monitor.service: Deactivated successfully. Mar 25 10:37:21 katarynka systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Mar 25 10:37:21 katarynka systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Mar 25 10:37:21 katarynka sudo[32574]: pam_unix(sudo:session): session closed for user root Mar 25 10:37:21 katarynka sudo[32577]: pam_unix(sudo:session): session closed for user root Mar 25 10:37:21 katarynka volumio[32244]: info: Successfully started MPD Monitor Mar 25 10:37:21 katarynka mpd_monitor.sh[32580]: MPD Monitor Service: Starting MPD Monitor Service Mar 25 10:37:21 katarynka volumio[32244]: info: Successfully started MPD Monitor Mar 25 10:37:22 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 11. Mar 25 10:37:22 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 10:37:22 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 10:37:22 katarynka go-librespot[32584]: go-librespot daemon starting... Mar 25 10:37:22 katarynka go-librespot[32585]: time="2026-03-25T10:37:22+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 10:37:22 katarynka go-librespot[32585]: time="2026-03-25T10:37:22+01:00" level=debug msg="app state loaded" Mar 25 10:37:22 katarynka go-librespot[32585]: time="2026-03-25T10:37:22+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 10:37:22 katarynka go-librespot[32585]: time="2026-03-25T10:37:22+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 10:37:22 katarynka go-librespot[32585]: time="2026-03-25T10:37:22+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 10:37:22 katarynka go-librespot[32585]: time="2026-03-25T10:37:22+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 10:37:22 katarynka go-librespot[32585]: time="2026-03-25T10:37:22+01:00" level=info msg="zeroconf server listening on port 46141" Mar 25 10:37:22 katarynka go-librespot[32585]: time="2026-03-25T10:37:22+01:00" level=debug msg="obtained new client token: AACCKcvjE5P3GynrAh3un6w19s1uQLZggRk7N5GuYNKPI5Nu/vRk3BDZ8KcByx1uSLXoj6zAUu+BIvOQb34PlM6WkYBXLPd2Hjew07DWisQMjZS+4YT/XIiSwYtCs5u16oeNOucQpk9uthUlCIPObpYhWq6MqUjybmD4q/1UB0CETBHBejqri8yg6z1AYnwzVmDcjMyVTlfU8hUJoLlrIHURIAgQDywSnKmBXD4pjJ1wxHI08DX1E1rPDIc=" Mar 25 10:37:23 katarynka volumio[32244]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Mar 25 10:37:23 katarynka go-librespot[32585]: time="2026-03-25T10:37:23+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 10:37:23 katarynka volumio[32244]: info: Initializing connection to go-librespot Websocket Mar 25 10:37:23 katarynka go-librespot[32585]: time="2026-03-25T10:37:23+01:00" level=debug msg="new websocket client" Mar 25 10:37:23 katarynka volumio[32244]: info: Connection to go-librespot Websocket established Mar 25 10:37:23 katarynka go-librespot[32585]: time="2026-03-25T10:37:23+01:00" level=debug msg="completed keyexchange" Mar 25 10:37:23 katarynka go-librespot[32585]: time="2026-03-25T10:37:23+01:00" level=debug msg="completed challenge" Mar 25 10:37:23 katarynka go-librespot[32585]: time="2026-03-25T10:37: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 10:37:23 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 10:37:23 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 10:37:23 katarynka volumio[32244]: info: Connection to go-librespot Websocket closed Mar 25 10:37:26 katarynka volumio[32244]: info: Getting Spotify volume Mar 25 10:37:26 katarynka volumio[32244]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 25 10:37:26 katarynka volumio[32244]: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 25 10:37:26 katarynka volumio[32244]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Mar 25 10:37:26 katarynka volumio[32244]: errno: -111, Mar 25 10:37:26 katarynka volumio[32244]: code: 'ECONNREFUSED', Mar 25 10:37:26 katarynka volumio[32244]: syscall: 'connect', Mar 25 10:37:26 katarynka volumio[32244]: address: '127.0.0.1', Mar 25 10:37:26 katarynka volumio[32244]: port: 9879, Mar 25 10:37:26 katarynka volumio[32244]: response: undefined Mar 25 10:37:26 katarynka volumio[32244]: } Mar 25 10:37:26 katarynka volumio[32244]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 25 10:37:26 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 12. Mar 25 10:37:26 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 10:37:26 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 10:37:26 katarynka go-librespot[32605]: go-librespot daemon starting... Mar 25 10:37:27 katarynka go-librespot[32606]: time="2026-03-25T10:37:27+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 10:37:27 katarynka go-librespot[32606]: time="2026-03-25T10:37:27+01:00" level=debug msg="app state loaded" Mar 25 10:37:27 katarynka go-librespot[32606]: time="2026-03-25T10:37:27+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 10:37:27 katarynka go-librespot[32606]: time="2026-03-25T10:37: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 10:37:27 katarynka go-librespot[32606]: time="2026-03-25T10:37: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 10:37:27 katarynka go-librespot[32606]: time="2026-03-25T10:37: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 10:37:27 katarynka go-librespot[32606]: time="2026-03-25T10:37:27+01:00" level=info msg="zeroconf server listening on port 45185" Mar 25 10:37:27 katarynka go-librespot[32606]: time="2026-03-25T10:37:27+01:00" level=debug msg="obtained new client token: AACi07t6o90k9XxvzBB8PUjfVhjJcdIOTgFx0EMdD2/8TvGt3Xsg8wyw7bLAgTDTQ2wa/AYxWYV1E/nfNEGdMOJVZXOa3YXVAGX3vCt9P8Bw56iEeSfZDZ9XxmPIn+F1TT3DaxTJ2sRG6S0egA4uPjMTZ1OuEafuU9V7wcEzynOwNHGRZvyxaWwutuo6edn25ItzNybAneiJtYBgAQ5th7/1xUjpz1+kWK7kHnw8x2H6Y/j92Zc36R4bqhc=" Mar 25 10:37:27 katarynka go-librespot[32606]: time="2026-03-25T10:37:27+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 10:37:27 katarynka go-librespot[32606]: time="2026-03-25T10:37:27+01:00" level=debug msg="connected to ap-gew4.spotify.com:443" Mar 25 10:37:27 katarynka go-librespot[32606]: time="2026-03-25T10:37:27+01:00" level=debug msg="completed keyexchange" Mar 25 10:37:27 katarynka go-librespot[32606]: time="2026-03-25T10:37:27+01:00" level=debug msg="completed challenge" Mar 25 10:37:27 katarynka go-librespot[32606]: time="2026-03-25T10:37: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 10:37:27 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 10:37:27 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 10:37:27 katarynka sudo[32616]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-03-25 10:36' Mar 25 10:37:27 katarynka sudo[32616]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 10:37:28 katarynka sudo[32616]: pam_unix(sudo:session): session closed for user root Mar 25 10:37:28 katarynka volumio-remote-updater[622]: [2026-03-25 10:37:28] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Mar 25 10:37:28 katarynka volumio-remote-updater[622]: [2026-03-25 10:37:28] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Mar 25 10:37:28 katarynka systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Mar 25 10:37:28 katarynka systemd[1]: volumio.service: Failed with result 'exit-code'. Mar 25 10:37:28 katarynka systemd[1]: volumio.service: Consumed 42.934s CPU time. Mar 25 10:37:28 katarynka systemd[1]: Started dynamicswap.service - dynamicswap service. Mar 25 10:37:28 katarynka systemd[1]: dynamicswap.service: Deactivated successfully. Mar 25 10:37:28 katarynka systemd[1]: volumio.service: Scheduled restart job, restart counter is at 26288. Mar 25 10:37:28 katarynka systemd[1]: Started dynamicswap.service - dynamicswap service. Mar 25 10:37:28 katarynka systemd[1]: Stopped volumio.service - Volumio Backend Module. Mar 25 10:37:28 katarynka systemd[1]: volumio.service: Consumed 42.934s CPU time. Mar 25 10:37:28 katarynka systemd[1]: Started volumio.service - Volumio Backend Module. Mar 25 10:37:28 katarynka systemd[1]: dynamicswap.service: Deactivated successfully. Mar 25 10:37:30 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 13. Mar 25 10:37:30 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 10:37:30 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 10:37:30 katarynka go-librespot[32644]: go-librespot daemon starting... Mar 25 10:37:31 katarynka go-librespot[32645]: time="2026-03-25T10:37:31+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 10:37:31 katarynka go-librespot[32645]: time="2026-03-25T10:37:31+01:00" level=debug msg="app state loaded" Mar 25 10:37:31 katarynka go-librespot[32645]: time="2026-03-25T10:37:31+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 10:37:31 katarynka go-librespot[32645]: time="2026-03-25T10:37: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-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 25 10:37:31 katarynka go-librespot[32645]: time="2026-03-25T10:37:31+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 10:37:31 katarynka go-librespot[32645]: time="2026-03-25T10:37:31+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 10:37:31 katarynka go-librespot[32645]: time="2026-03-25T10:37:31+01:00" level=info msg="zeroconf server listening on port 33271" Mar 25 10:37:31 katarynka go-librespot[32645]: time="2026-03-25T10:37:31+01:00" level=debug msg="obtained new client token: AAAXNYm9fs1ZAir3pmP3PRa8cbQs8w/DCWYdLtIUudl+K9kxTl3fPAH6gO4BW5OwF50RTcF9tPJJfJ8DtUgg52YHRLsNDTEz3p52CYPdafhiHz5A64IBLkmevxuq4dcfS+qkMZTyIPSo7SCVXLWhA1Sa+c+hxk4b4RYK1njRgrbEjz4ktoXq45dfDUVj68sKElvC37pqLBk1rzNod3NPGVjekduCUdEFXVneUfdNqgaWTmfbNFRx+tLih0U=" Mar 25 10:37:31 katarynka go-librespot[32645]: time="2026-03-25T10:37:31+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 10:37:31 katarynka go-librespot[32645]: time="2026-03-25T10:37:31+01:00" level=debug msg="completed keyexchange" Mar 25 10:37:31 katarynka go-librespot[32645]: time="2026-03-25T10:37:31+01:00" level=debug msg="completed challenge" Mar 25 10:37:31 katarynka go-librespot[32645]: time="2026-03-25T10:37: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 10:37:31 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 10:37:31 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 10:37:32 katarynka volumio[32629]: info: ------------------------------------------- Mar 25 10:37:32 katarynka volumio[32629]: info: ----- Volumio3 ---- Mar 25 10:37:32 katarynka volumio[32629]: info: ------------------------------------------- Mar 25 10:37:32 katarynka volumio[32629]: info: ----- System startup ---- Mar 25 10:37:32 katarynka volumio[32629]: info: ------------------------------------------- Mar 25 10:37:33 katarynka volumio-remote-updater[622]: [2026-03-25 10:37:33] [connect] Successful connection Mar 25 10:37:33 katarynka volumio[32629]: info: MYVOLUMIO Environment detected Mar 25 10:37:34 katarynka volumio[32629]: info: Plugin folders cleanup Mar 25 10:37:34 katarynka volumio[32629]: info: Scanning into folder /volumio/app/plugins/ Mar 25 10:37:34 katarynka volumio[32629]: info: Scanning category audio_interface Mar 25 10:37:34 katarynka volumio[32629]: info: Scanning category miscellanea Mar 25 10:37:34 katarynka volumio[32629]: info: Scanning category music_service Mar 25 10:37:34 katarynka volumio[32629]: info: Scanning category plugins.json Mar 25 10:37:34 katarynka volumio[32629]: info: Scanning category system_controller Mar 25 10:37:34 katarynka volumio[32629]: info: Scanning category user_interface Mar 25 10:37:34 katarynka volumio[32629]: info: Scanning into folder /data/plugins/ Mar 25 10:37:34 katarynka volumio[32629]: info: Scanning category music_service Mar 25 10:37:34 katarynka volumio[32629]: info: Plugin folders cleanup completed Mar 25 10:37:34 katarynka volumio[32629]: info: ------------------------------------------- Mar 25 10:37:34 katarynka volumio[32629]: info: ----- Core plugins startup ---- Mar 25 10:37:34 katarynka volumio[32629]: info: ------------------------------------------- Mar 25 10:37:34 katarynka volumio[32629]: info: Loading plugins from folder /volumio/app/plugins/ Mar 25 10:37:34 katarynka volumio[32629]: info: Adding plugin upnp to MyMusic Plugins Mar 25 10:37:34 katarynka volumio[32629]: info: Adding plugin airplay_emulation to MyMusic Plugins Mar 25 10:37:34 katarynka volumio[32629]: info: Adding plugin upnp_browser to MyMusic Plugins Mar 25 10:37:34 katarynka volumio[32629]: info: Loading plugins from folder /data/plugins/ Mar 25 10:37:34 katarynka volumio[32629]: info: Loading plugin "system"... Mar 25 10:37:34 katarynka volumio[32629]: info: Loading plugin "appearance"... Mar 25 10:37:34 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 14. Mar 25 10:37:34 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 10:37:34 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 10:37:34 katarynka go-librespot[32664]: go-librespot daemon starting... Mar 25 10:37:35 katarynka go-librespot[32665]: time="2026-03-25T10:37:35+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 10:37:35 katarynka go-librespot[32665]: time="2026-03-25T10:37:35+01:00" level=debug msg="app state loaded" Mar 25 10:37:35 katarynka go-librespot[32665]: time="2026-03-25T10:37:35+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 10:37:35 katarynka go-librespot[32665]: time="2026-03-25T10:37: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 10:37:35 katarynka go-librespot[32665]: time="2026-03-25T10:37: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 10:37:35 katarynka go-librespot[32665]: time="2026-03-25T10:37: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 10:37:35 katarynka go-librespot[32665]: time="2026-03-25T10:37:35+01:00" level=info msg="zeroconf server listening on port 44763" Mar 25 10:37:35 katarynka go-librespot[32665]: time="2026-03-25T10:37:35+01:00" level=debug msg="obtained new client token: AAB6XJZUP5Fvma3mpv2m2jge2CD7o+pctIVd/8NroVjVDy9YUT4vxZYKDur8sl47uPVovtok9P/3CUVnP7nTHpGKfE3IfQYqorFW9jdI34FhZQeCbuuNIa6Rwjzs8CH/8XciK8Lrui7XPE5t5ZYri72faNtvFzLZez5a3yApPshCCJBEYMjfWJJTiOxDFIecSWvrHoWqqdW7rzpWuvTa4GScHt845MWZrooIGzzRH3IKf6pgGHzOz6wbsqU=" Mar 25 10:37:35 katarynka go-librespot[32665]: time="2026-03-25T10:37:35+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 10:37:36 katarynka go-librespot[32665]: time="2026-03-25T10:37:36+01:00" level=debug msg="completed keyexchange" Mar 25 10:37:36 katarynka go-librespot[32665]: time="2026-03-25T10:37:36+01:00" level=debug msg="completed challenge" Mar 25 10:37:36 katarynka volumio[32629]: info: Loading plugin "network"... Mar 25 10:37:36 katarynka volumio[32629]: info: Refreshing Cached IP Addresses Mar 25 10:37:36 katarynka sudo[32673]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 25 10:37:36 katarynka sudo[32673]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 10:37:36 katarynka sudo[32675]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 25 10:37:36 katarynka sudo[32675]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 10:37:36 katarynka sudo[32673]: pam_unix(sudo:session): session closed for user root Mar 25 10:37:36 katarynka volumio[32629]: info: Loading plugin "services"... Mar 25 10:37:36 katarynka sudo[32675]: pam_unix(sudo:session): session closed for user root Mar 25 10:37:36 katarynka volumio[32629]: info: Loading plugin "alsa_controller"... Mar 25 10:37:36 katarynka sudo[32682]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Mar 25 10:37:36 katarynka sudo[32682]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 10:37:36 katarynka volumio[32629]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 25 10:37:36 katarynka volumio[32629]: info: Loading plugin "wizard"... Mar 25 10:37:36 katarynka go-librespot[32665]: time="2026-03-25T10:37: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 10:37:36 katarynka volumio[32629]: info: Loading plugin "networkfs"... Mar 25 10:37:36 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 10:37:36 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 10:37:36 katarynka volumio[32629]: info: Starting Udev Watcher for removable devices Mar 25 10:37:36 katarynka volumio[32629]: info: Ignoring mount for partition: boot Mar 25 10:37:36 katarynka volumio[32629]: info: Ignoring mount for partition: volumio Mar 25 10:37:36 katarynka volumio[32629]: info: Ignoring mount for partition: volumio_data Mar 25 10:37:36 katarynka volumio[32629]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 25 10:37:36 katarynka volumio[32629]: info: Loading plugin "volumio_command_line_client"... Mar 25 10:37:36 katarynka volumio[32629]: info: Loading plugin "upnp"... Mar 25 10:37:36 katarynka volumio[32629]: info: [1774431456770] Starting Upmpd Daemon Mar 25 10:37:36 katarynka volumio[32629]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 25 10:37:36 katarynka volumio[32629]: info: Loading plugin "my_music"... Mar 25 10:37:36 katarynka volumio[32629]: info: Loading plugin "mpd"... Mar 25 10:37:37 katarynka sudo[32682]: pam_unix(sudo:session): session closed for user root Mar 25 10:37:37 katarynka volumio[32629]: info: Loading plugin "upnp_browser"... Mar 25 10:37:39 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 15. Mar 25 10:37:39 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 10:37:39 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 10:37:39 katarynka go-librespot[32706]: go-librespot daemon starting... Mar 25 10:37:39 katarynka go-librespot[32707]: time="2026-03-25T10:37:39+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 10:37:39 katarynka go-librespot[32707]: time="2026-03-25T10:37:39+01:00" level=debug msg="app state loaded" Mar 25 10:37:39 katarynka go-librespot[32707]: time="2026-03-25T10:37:39+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 10:37:40 katarynka go-librespot[32707]: time="2026-03-25T10:37:40+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 25 10:37:40 katarynka go-librespot[32707]: time="2026-03-25T10:37:40+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 25 10:37:40 katarynka go-librespot[32707]: time="2026-03-25T10:37:40+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 25 10:37:40 katarynka go-librespot[32707]: time="2026-03-25T10:37:40+01:00" level=info msg="zeroconf server listening on port 36481" Mar 25 10:37:40 katarynka go-librespot[32707]: time="2026-03-25T10:37:40+01:00" level=debug msg="obtained new client token: AAC4JKy0iIFoEkafPlqIZwhUu3GyDQlIhC6naSQVQKkuKV1t40XR1wxkfXyQ7SYWFSKZTZmaKJZoquWTAvfNOJQ6aLtt/jeuwlXPcPyztTDjmcxvQvnZ6DJwW5f6WdkIY+yomnMHeCF/Rqbn4w4oMOTEJ4QWQkInReJCHzsHquyqSNo47RhY4StpZDgH96D54s+PecMHJAWMlbiyrVQHeOG5MvLZynjqblqqNpKukNUx5I9eZEoXu0oTn1s=" Mar 25 10:37:40 katarynka go-librespot[32707]: time="2026-03-25T10:37:40+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 10:37:40 katarynka volumio[32629]: info: Starting UPNP Browser Mar 25 10:37:40 katarynka volumio[32629]: info: Loading plugin "alarm-clock"... Mar 25 10:37:40 katarynka go-librespot[32707]: time="2026-03-25T10:37:40+01:00" level=debug msg="completed keyexchange" Mar 25 10:37:40 katarynka go-librespot[32707]: time="2026-03-25T10:37:40+01:00" level=debug msg="completed challenge" Mar 25 10:37:40 katarynka go-librespot[32707]: time="2026-03-25T10:37: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 10:37:40 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 10:37:40 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 10:37:40 katarynka volumio[32629]: info: Loading plugin "airplay_emulation"... Mar 25 10:37:40 katarynka volumio[32629]: info: Starting Shairport Sync Mar 25 10:37:40 katarynka volumio[32629]: info: Loading plugin "last_100"... Mar 25 10:37:40 katarynka volumio[32629]: info: Loading plugin "webradio"... Mar 25 10:37:41 katarynka volumio[32629]: info: Loading plugin "i2s_dacs"... Mar 25 10:37:41 katarynka volumio[32629]: info: Loading plugin "volumiodiscovery"... Mar 25 10:37:41 katarynka volumio[32629]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Mar 25 10:37:41 katarynka volumio[32629]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 25 10:37:41 katarynka volumio[32629]: *** WARNING *** For more information see Mar 25 10:37:41 katarynka volumio[32629]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Mar 25 10:37:41 katarynka volumio[32629]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 25 10:37:41 katarynka volumio[32629]: *** WARNING *** For more information see Mar 25 10:37:41 katarynka node[32629]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Mar 25 10:37:41 katarynka node[32629]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 25 10:37:41 katarynka node[32629]: *** WARNING *** For more information see Mar 25 10:37:41 katarynka node[32629]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Mar 25 10:37:41 katarynka volumio[32629]: info: Applying required configuration parameters for plugin volumiodiscovery Mar 25 10:37:41 katarynka node[32629]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 25 10:37:41 katarynka node[32629]: *** WARNING *** For more information see Mar 25 10:37:41 katarynka volumio[32629]: info: Discovery: Started advertising with name: katarynka Mar 25 10:37:41 katarynka volumio[32629]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 25 10:37:41 katarynka volumio[32629]: info: Loading plugin "spop"... Mar 25 10:37:43 katarynka volumio[32629]: info: Loading plugin "outputs"... Mar 25 10:37:43 katarynka volumio[32629]: info: Loading plugin "albumart"... Mar 25 10:37:43 katarynka volumio[32629]: info: Plugin example_plugin is not enabled Mar 25 10:37:43 katarynka volumio[32629]: info: Loading plugin "inputs"... Mar 25 10:37:43 katarynka volumio[32629]: info: Loading plugin "updater_comm"... Mar 25 10:37:43 katarynka volumio[32629]: info: Plugin mpdemulation is not enabled Mar 25 10:37:43 katarynka volumio[32629]: info: Loading plugin "rest_api"... Mar 25 10:37:43 katarynka volumio[32629]: info: Loading plugin "websocket"... Mar 25 10:37:43 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 16. Mar 25 10:37:43 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 10:37:43 katarynka volumio[32629]: info: Starting Socket.io Server version 1.7.4 Mar 25 10:37:43 katarynka volumio[32629]: info: Loading i18n strings for locale pl Mar 25 10:37:43 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 10:37:43 katarynka go-librespot[32730]: go-librespot daemon starting... Mar 25 10:37:43 katarynka volumio[32629]: Updating browse sources language Mar 25 10:37:43 katarynka volumio[32629]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 25 10:37:43 katarynka go-librespot[32731]: time="2026-03-25T10:37:43+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 10:37:43 katarynka go-librespot[32731]: time="2026-03-25T10:37:43+01:00" level=debug msg="app state loaded" Mar 25 10:37:43 katarynka go-librespot[32731]: time="2026-03-25T10:37:43+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 10:37:44 katarynka volumio[32629]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 25 10:37:44 katarynka volumio[32629]: info: CoreCommandRouter::initPlayerControls Mar 25 10:37:44 katarynka volumio[32629]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 10:37:44 katarynka volumio[32629]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 10:37:44 katarynka volumio[32629]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 10:37:44 katarynka volumio[32629]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 10:37:44 katarynka volumio[32629]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 10:37:44 katarynka volumio[32629]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 10:37:44 katarynka volumio[32629]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 10:37:44 katarynka volumio[32629]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 10:37:44 katarynka volumio[32629]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 25 10:37:44 katarynka volumio[32629]: Express server listening on port 3000 Mar 25 10:37:44 katarynka volumio[32629]: [Metrics] WebUI: 12s 568.62ms Mar 25 10:37:44 katarynka volumio[32629]: info: CoreStateMachine::resetVolumioState Mar 25 10:37:44 katarynka volumio[32629]: info: CoreStateMachine::getcurrentVolume Mar 25 10:37:44 katarynka volumio[32629]: info: CoreCommandRouter::volumioRetrievevolume Mar 25 10:37:44 katarynka volumio[32629]: info: Cannot read play queue from file Mar 25 10:37:44 katarynka volumio[32629]: info: Volumio Network Manager: Network status updated: 2 Mar 25 10:37:44 katarynka go-librespot[32731]: time="2026-03-25T10:37:44+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 10:37:44 katarynka go-librespot[32731]: time="2026-03-25T10:37:44+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 10:37:44 katarynka go-librespot[32731]: time="2026-03-25T10:37:44+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 10:37:44 katarynka go-librespot[32731]: time="2026-03-25T10:37:44+01:00" level=info msg="zeroconf server listening on port 42803" Mar 25 10:37:44 katarynka go-librespot[32731]: time="2026-03-25T10:37:44+01:00" level=debug msg="obtained new client token: AAD/IXKvB4RqH3mWuMXkg7sOZvXGx4te/qihvgwMcS0mR3tb1tpejSOA8OIMppq2aK66ZUSUaYA/Z9+zEQ6POPqy9KWZ4cdbA2Bt4jZUb4TUPwBKp3wbANCJu0vw+r/TXDBewF7g50t/kDx8hl9TYJXG+qPxxID0m8PBcF2P73U9KEEMfW+0e6oeBzTZHdVEXE1BOBsglkdTY21ZeB2JrbAYPxZWpsyl6ejSoUU+5CZ3lSiBTm3CtZoDV5E=" Mar 25 10:37:44 katarynka volumio[32629]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 10:37:44 katarynka go-librespot[32731]: time="2026-03-25T10:37:44+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 10:37:44 katarynka volumio[32629]: info: CoreStateMachine::setRepeat null single undefined Mar 25 10:37:44 katarynka volumio[32629]: info: CoreStateMachine::pushState Mar 25 10:37:44 katarynka volumio[32629]: info: CorePlayQueue::getTrack 0 Mar 25 10:37:44 katarynka volumio[32629]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 25 10:37:44 katarynka volumio[32629]: info: CoreCommandRouter::volumioPushState Mar 25 10:37:44 katarynka volumio[32720]: Forking 3 albumart workers Mar 25 10:37:44 katarynka volumio[32629]: info: CoreStateMachine::setRandom null Mar 25 10:37:44 katarynka volumio[32629]: info: CoreStateMachine::pushState Mar 25 10:37:44 katarynka volumio[32629]: info: CorePlayQueue::getTrack 0 Mar 25 10:37:44 katarynka volumio[32629]: info: CoreCommandRouter::volumioPushState Mar 25 10:37:44 katarynka volumio[32629]: info: VolumeController:: Volume=96 Mute =false Mar 25 10:37:44 katarynka volumio[32629]: info: CoreStateMachine::pushState Mar 25 10:37:44 katarynka volumio[32629]: info: CorePlayQueue::getTrack 0 Mar 25 10:37:44 katarynka volumio[32629]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 25 10:37:44 katarynka volumio[32629]: info: CoreCommandRouter::volumioPushState Mar 25 10:37:44 katarynka volumio[32629]: info: CoreStateMachine::updateTrackBlock Mar 25 10:37:44 katarynka volumio[32629]: info: CorePlayQueue::getTrackBlock Mar 25 10:37:44 katarynka volumio[32629]: info: CoreCommandRouter::volumioRetrievevolume Mar 25 10:37:44 katarynka go-librespot[32731]: time="2026-03-25T10:37:44+01:00" level=debug msg="completed keyexchange" Mar 25 10:37:44 katarynka go-librespot[32731]: time="2026-03-25T10:37:44+01:00" level=debug msg="completed challenge" Mar 25 10:37:44 katarynka volumio[32629]: info: Setting Device type: Raspberry PI Mar 25 10:37:44 katarynka volumio[32629]: info: Completed loading Core Plugins Mar 25 10:37:44 katarynka go-librespot[32731]: time="2026-03-25T10:37: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 10:37:44 katarynka volumio[32629]: info: Preparing to generate the ALSA configuration file Mar 25 10:37:44 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 10:37:44 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 10:37:44 katarynka volumio[32629]: info: Asound.conf file unchanged, so no further update is needed Mar 25 10:37:44 katarynka volumio[32629]: info: Output device has changed, restarting MPD Mar 25 10:37:45 katarynka volumio[32629]: info: Output device has changed, restarting Shairport Sync Mar 25 10:37:45 katarynka volumio[32629]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 10:37:45 katarynka volumio[32629]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 10:37:45 katarynka sudo[320]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 25 10:37:45 katarynka sudo[320]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 10:37:45 katarynka volumio[32629]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 25 10:37:45 katarynka volumio[32629]: info: ___________ START PLUGINS ___________ Mar 25 10:37:45 katarynka sudo[316]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 25 10:37:45 katarynka sudo[316]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 10:37:45 katarynka sudo[316]: pam_unix(sudo:session): session closed for user root Mar 25 10:37:45 katarynka volumio[32629]: info: ControllerMpd::onStart: Initializing MPD Mar 25 10:37:45 katarynka volumio[32629]: info: Creating MPD Configuration file Mar 25 10:37:45 katarynka systemd[1]: Stopping mpd.service - Music Player Daemon... Mar 25 10:37:45 katarynka volumio[32629]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 25 10:37:45 katarynka volumio[32629]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 25 10:37:45 katarynka volumio[32629]: info: [1774431465295] CoreMusicLibrary::Adding element Serwery Mediów Mar 25 10:37:45 katarynka volumio[32629]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 25 10:37:45 katarynka systemd[1]: mpd.service: Deactivated successfully. Mar 25 10:37:45 katarynka systemd[1]: Stopped mpd.service - Music Player Daemon. Mar 25 10:37:45 katarynka systemd[1]: mpd.service: Consumed 7.682s CPU time. Mar 25 10:37:45 katarynka systemd[1]: mpd.socket: Deactivated successfully. Mar 25 10:37:45 katarynka systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Mar 25 10:37:45 katarynka systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Mar 25 10:37:45 katarynka sudo[330]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 25 10:37:45 katarynka sudo[328]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 25 10:37:45 katarynka sudo[330]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 10:37:45 katarynka sudo[328]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 10:37:45 katarynka volumio[32629]: info: UPNP Browser: Client initialized successfully Mar 25 10:37:45 katarynka sudo[328]: pam_unix(sudo:session): session closed for user root Mar 25 10:37:45 katarynka volumio[32629]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 10:37:45 katarynka volumio[32629]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 10:37:45 katarynka systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Mar 25 10:37:45 katarynka systemd[1]: Starting mpd.service - Music Player Daemon... Mar 25 10:37:45 katarynka volumio[32629]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 25 10:37:45 katarynka volumio[32629]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 10:37:45 katarynka systemd[1]: mpd.service: Deactivated successfully. Mar 25 10:37:45 katarynka systemd[1]: Stopped mpd.service - Music Player Daemon. Mar 25 10:37:45 katarynka volumio[32629]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 10:37:45 katarynka systemd[1]: mpd.socket: Deactivated successfully. Mar 25 10:37:45 katarynka systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Mar 25 10:37:45 katarynka systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Mar 25 10:37:45 katarynka systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Mar 25 10:37:45 katarynka systemd[1]: Starting mpd.service - Music Player Daemon... Mar 25 10:37:45 katarynka volumio[32629]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 25 10:37:45 katarynka volumio[32629]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 25 10:37:45 katarynka volumio[32629]: info: [1774431465638] CoreMusicLibrary::Adding element Last_100 Mar 25 10:37:45 katarynka volumio[32629]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 25 10:37:45 katarynka volumio[32629]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 25 10:37:45 katarynka volumio[32629]: info: [1774431465656] CoreMusicLibrary::Adding element Webradio Mar 25 10:37:45 katarynka volumio[32629]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 25 10:37:45 katarynka volumio[32629]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 25 10:37:45 katarynka volumio[32629]: info: Initializing BBC Radios Mar 25 10:37:45 katarynka volumio-remote-updater[622]: [2026-03-25 10:37:45] [connect] Successful connection Mar 25 10:37:45 katarynka volumio[32629]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 25 10:37:45 katarynka volumio[32629]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 10:37:45 katarynka volumio[32629]: info: Creating Spotify config file Mar 25 10:37:45 katarynka volumio[32629]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 10:37:46 katarynka sudo[344]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Mar 25 10:37:46 katarynka sudo[344]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Mar 25 10:37:46 katarynka sudo[344]: pam_unix(sudo:session): session closed for user root Mar 25 10:37:47 katarynka volumio[32629]: info: Volumio Calling Home Mar 25 10:37:47 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 17. Mar 25 10:37:47 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 10:37:47 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 10:37:47 katarynka go-librespot[379]: go-librespot daemon starting... Mar 25 10:37:48 katarynka go-librespot[382]: time="2026-03-25T10:37:48+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 10:37:48 katarynka volumio[32629]: info: Discovery: adding 4d616d77-6a8c-4da2-85a4-840d70f98e51 Mar 25 10:37:48 katarynka sudo[381]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 25 10:37:48 katarynka sudo[381]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 10:37:48 katarynka volumio[32629]: info: Discovery: Found device katarynka Mar 25 10:37:48 katarynka volumio[32629]: info: CoreCommandRouter::volumioGetState Mar 25 10:37:48 katarynka volumio[32629]: info: CorePlayQueue::getTrack 0 Mar 25 10:37:48 katarynka sudo[381]: pam_unix(sudo:session): session closed for user root Mar 25 10:37:48 katarynka sudo[392]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 25 10:37:48 katarynka sudo[392]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 10:37:48 katarynka volumio[32629]: info: Discovery: this is already registered, 4d616d77-6a8c-4da2-85a4-840d70f98e51 Mar 25 10:37:48 katarynka volumio[32629]: info: Discovery: Found device katarynka Mar 25 10:37:48 katarynka volumio[32629]: info: CoreCommandRouter::volumioGetState Mar 25 10:37:48 katarynka volumio[32629]: info: CorePlayQueue::getTrack 0 Mar 25 10:37:48 katarynka sudo[392]: pam_unix(sudo:session): session closed for user root Mar 25 10:37:48 katarynka volumio[32629]: info: MPD Permissions set Mar 25 10:37:48 katarynka volumio[32629]: info: MPD Permissions set Mar 25 10:37:48 katarynka volumio[32629]: info: VolumeController:: Volume=96 Mute =false Mar 25 10:37:48 katarynka volumio[32629]: info: CoreStateMachine::pushState Mar 25 10:37:48 katarynka volumio[32629]: info: CorePlayQueue::getTrack 0 Mar 25 10:37:48 katarynka volumio[32629]: info: CoreCommandRouter::volumioPushState Mar 25 10:37:48 katarynka volumio-remote-updater[622]: [2026-03-25 10:37:48] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1774431465 101 Mar 25 10:37:48 katarynka volumio[32749]: Starting albumart workers Mar 25 10:37:48 katarynka volumio[32629]: 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 10:37:48 katarynka volumio[32629]: info: Spotify config file written Mar 25 10:37:48 katarynka go-librespot[382]: time="2026-03-25T10:37:48+01:00" level=info msg="zeroconf server listening on port 37353" Mar 25 10:37:48 katarynka sudo[397]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Mar 25 10:37:48 katarynka sudo[397]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 10:37:49 katarynka volumio[32750]: Starting albumart workers Mar 25 10:37:49 katarynka systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Mar 25 10:37:49 katarynka systemd[1]: go-librespot-daemon.service: Deactivated successfully. Mar 25 10:37:49 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 10:37:49 katarynka volumio[32752]: Starting albumart workers Mar 25 10:37:49 katarynka volumio[32629]: 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 10:37:49 katarynka volumio[32629]: info: Volumio called home Mar 25 10:37:49 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 10:37:49 katarynka go-librespot[400]: go-librespot daemon starting... Mar 25 10:37:49 katarynka volumio[32629]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 10:37:49 katarynka volumio[32629]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 10:37:49 katarynka volumio[32629]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 10:37:49 katarynka volumio[32629]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 10:37:49 katarynka volumio[32629]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 10:37:49 katarynka volumio[32629]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 10:37:49 katarynka volumio[32629]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 10:37:49 katarynka volumio[32629]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 10:37:49 katarynka sudo[397]: pam_unix(sudo:session): session closed for user root Mar 25 10:37:49 katarynka go-librespot[401]: time="2026-03-25T10:37:49+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 10:37:49 katarynka go-librespot[401]: time="2026-03-25T10:37:49+01:00" level=debug msg="app state loaded" Mar 25 10:37:49 katarynka go-librespot[401]: time="2026-03-25T10:37:49+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 10:37:49 katarynka volumio[32629]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 10:37:49 katarynka volumio[32629]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 10:37:49 katarynka volumio[32629]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 10:37:49 katarynka volumio[32629]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 10:37:49 katarynka volumio[32629]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 10:37:49 katarynka volumio[32629]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 10:37:49 katarynka volumio[32629]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 10:37:49 katarynka volumio[32629]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 10:37:49 katarynka volumio[32629]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 10:37:49 katarynka volumio[32629]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 10:37:49 katarynka volumio[32629]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 10:37:49 katarynka volumio[32629]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 10:37:49 katarynka volumio[32629]: info: No need to fix Spotify hosts Mar 25 10:37:49 katarynka go-librespot[401]: time="2026-03-25T10:37:49+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Mar 25 10:37:49 katarynka go-librespot[401]: time="2026-03-25T10:37:49+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 10:37:49 katarynka go-librespot[401]: time="2026-03-25T10:37:49+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 10:37:49 katarynka go-librespot[401]: time="2026-03-25T10:37:49+01:00" level=info msg="zeroconf server listening on port 41887" Mar 25 10:37:50 katarynka go-librespot[401]: time="2026-03-25T10:37:50+01:00" level=debug msg="obtained new client token: AADKWBWkKcA/aOm6wpbg8+AaQDPe93yKt6hn6JMKPUSz+jscGyvCUPdI27fhA7eAawaptnDItMFDsK/a/QAYKbA9HzYo7cWW3rhiZIdr4iqInMo5d8vZ8n1nMNci2wvcYcl6bG6keJLXm0u0U9PK7OPum5cAYgLe6sqCPsGZ+zsNIFTnyuBGwettWq2+3p8lHnhiQMGB6jjF1FSxDl+kLDEoav2ikZ9gxPGEhCN9NKi4Ts5hYX4GJkBr" Mar 25 10:37:50 katarynka volumio[32629]: info: Starting Shairport Sync Mar 25 10:37:50 katarynka go-librespot[401]: time="2026-03-25T10:37:50+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 10:37:50 katarynka volumio[32629]: info: Starting Shairport Sync Mar 25 10:37:50 katarynka volumio[32629]: info: Starting Shairport Sync Mar 25 10:37:50 katarynka go-librespot[401]: time="2026-03-25T10:37:50+01:00" level=debug msg="completed keyexchange" Mar 25 10:37:50 katarynka go-librespot[401]: time="2026-03-25T10:37:50+01:00" level=debug msg="completed challenge" Mar 25 10:37:50 katarynka go-librespot[401]: time="2026-03-25T10:37:50+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 10:37:50 katarynka sudo[420]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 25 10:37:50 katarynka sudo[420]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 10:37:50 katarynka sudo[424]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 25 10:37:50 katarynka sudo[424]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 10:37:50 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 10:37:50 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 10:37:50 katarynka sudo[422]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 25 10:37:50 katarynka sudo[422]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 10:37:50 katarynka sudo[430]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Mar 25 10:37:50 katarynka sudo[430]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 10:37:50 katarynka systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Mar 25 10:37:50 katarynka systemd[1]: shairport-sync.service: Deactivated successfully. Mar 25 10:37:50 katarynka systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 25 10:37:50 katarynka systemd[1]: shairport-sync.service: Consumed 2.273s CPU time. Mar 25 10:37:50 katarynka systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 25 10:37:50 katarynka sudo[422]: pam_unix(sudo:session): session closed for user root Mar 25 10:37:50 katarynka sudo[420]: pam_unix(sudo:session): session closed for user root Mar 25 10:37:50 katarynka sudo[424]: pam_unix(sudo:session): session closed for user root Mar 25 10:37:50 katarynka sudo[430]: pam_unix(sudo:session): session closed for user root Mar 25 10:37:50 katarynka volumio[32629]: info: An error occurred while refreshing Spotify Token Error: Bad Request Mar 25 10:37:51 katarynka volumio[32629]: info: Shairport-Sync Started Mar 25 10:37:51 katarynka volumio[32629]: Error adding Membership: Error: addMembership EINVAL Mar 25 10:37:51 katarynka volumio[32629]: info: Shairport-Sync Started Mar 25 10:37:51 katarynka volumio[32629]: info: Shairport-Sync Started Mar 25 10:37:51 katarynka volumio[32629]: info: Upmpdcli Daemon Started Mar 25 10:37:51 katarynka volumio[32629]: info: CoreCommandRouter::volumioGetState Mar 25 10:37:51 katarynka volumio[32629]: info: CorePlayQueue::getTrack 0 Mar 25 10:37:53 katarynka volumio[32629]: info: go-librespot daemon successfully initialized Mar 25 10:37:53 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Mar 25 10:37:53 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 10:37:53 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 10:37:53 katarynka go-librespot[467]: go-librespot daemon starting... Mar 25 10:37:53 katarynka go-librespot[468]: time="2026-03-25T10:37:53+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 10:37:53 katarynka go-librespot[468]: time="2026-03-25T10:37:53+01:00" level=debug msg="app state loaded" Mar 25 10:37:53 katarynka go-librespot[468]: time="2026-03-25T10:37:53+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 10:37:53 katarynka mpd[361]: 2026-03-25T10:37:53 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Mar 25 10:37:53 katarynka systemd[1]: Started mpd.service - Music Player Daemon. Mar 25 10:37:53 katarynka sudo[330]: pam_unix(sudo:session): session closed for user root Mar 25 10:37:53 katarynka sudo[320]: pam_unix(sudo:session): session closed for user root Mar 25 10:37:53 katarynka volumio[32629]: info: Completed starting Core Plugins Mar 25 10:37:53 katarynka volumio[32629]: info: ------------------------------------------- Mar 25 10:37:53 katarynka volumio[32629]: info: ----- MyVolumio plugins startup ---- Mar 25 10:37:53 katarynka volumio[32629]: info: ------------------------------------------- Mar 25 10:37:53 katarynka volumio[32629]: info: [MyVolumio PluginManager] Fetching plans data.... Mar 25 10:37:53 katarynka go-librespot[468]: time="2026-03-25T10:37:53+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 10:37:53 katarynka go-librespot[468]: time="2026-03-25T10:37:53+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 10:37:53 katarynka go-librespot[468]: time="2026-03-25T10:37:53+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 10:37:54 katarynka go-librespot[468]: time="2026-03-25T10:37:54+01:00" level=info msg="zeroconf server listening on port 37907" Mar 25 10:37:54 katarynka go-librespot[468]: time="2026-03-25T10:37:54+01:00" level=debug msg="obtained new client token: AABIJNxdNAr7qM0lz+Ycr34eu6xIOJ64pBOrJ3tuWlExTgge7k6hfqPTOkr4+s/S2I8Mw5Mn4yjJEWJD07tHBHc2mZVAMbUrD8nsBFPRxvnk/Lhzxgxpv1NKBwAUXB/U7XQqyx7iJZuEl3Bhxj97LNcdfUi/K4jHZdSr/aQxZeLqTdeRg6YIDdUMze+vi3yXop3GACNZguoV8xa0pGCRfYDkM3z9ZiXRnLXZc9yH5KJybLIu3RNVRzRQ" Mar 25 10:37:54 katarynka volumio[32629]: error: MPD error: The expression evaluated to a falsy value: Mar 25 10:37:54 katarynka volumio[32629]: assert.ok(self.idling) Mar 25 10:37:54 katarynka volumio[32629]: error: The expression evaluated to a falsy value: Mar 25 10:37:54 katarynka volumio[32629]: assert.ok(self.idling) Mar 25 10:37:54 katarynka volumio[32629]: error: updateQueue error: null Mar 25 10:37:54 katarynka volumio[32629]: info: MPD running with PID361 Mar 25 10:37:54 katarynka volumio[32629]: ,establishing connection Mar 25 10:37:54 katarynka volumio[32629]: error: updateQueue error: null Mar 25 10:37:54 katarynka go-librespot[468]: time="2026-03-25T10:37:54+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 10:37:54 katarynka go-librespot[468]: time="2026-03-25T10:37:54+01:00" level=debug msg="completed keyexchange" Mar 25 10:37:54 katarynka go-librespot[468]: time="2026-03-25T10:37:54+01:00" level=debug msg="completed challenge" Mar 25 10:37:54 katarynka go-librespot[468]: time="2026-03-25T10:37:54+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 10:37:54 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 10:37:54 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 10:37:56 katarynka volumio[32629]: info: Initializing connection to go-librespot Websocket Mar 25 10:37:56 katarynka volumio[32629]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 25 10:37:56 katarynka sudo[494]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Mar 25 10:37:56 katarynka sudo[494]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 10:37:57 katarynka sudo[496]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Mar 25 10:37:57 katarynka sudo[496]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 10:37:57 katarynka systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Mar 25 10:37:57 katarynka systemd[1]: mpd_monitor.service: Deactivated successfully. Mar 25 10:37:57 katarynka systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Mar 25 10:37:57 katarynka systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Mar 25 10:37:57 katarynka sudo[494]: pam_unix(sudo:session): session closed for user root Mar 25 10:37:57 katarynka sudo[496]: pam_unix(sudo:session): session closed for user root Mar 25 10:37:57 katarynka mpd_monitor.sh[499]: MPD Monitor Service: Starting MPD Monitor Service Mar 25 10:37:57 katarynka volumio[32629]: info: Successfully started MPD Monitor Mar 25 10:37:57 katarynka volumio[32629]: info: Successfully started MPD Monitor Mar 25 10:37:57 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Mar 25 10:37:57 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 10:37:57 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 10:37:57 katarynka go-librespot[503]: go-librespot daemon starting... Mar 25 10:37:58 katarynka go-librespot[504]: time="2026-03-25T10:37:58+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 10:37:58 katarynka go-librespot[504]: time="2026-03-25T10:37:58+01:00" level=debug msg="app state loaded" Mar 25 10:37:58 katarynka go-librespot[504]: time="2026-03-25T10:37:58+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 10:37:58 katarynka go-librespot[504]: time="2026-03-25T10:37:58+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 10:37:58 katarynka go-librespot[504]: time="2026-03-25T10:37:58+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 10:37:58 katarynka go-librespot[504]: time="2026-03-25T10:37:58+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 10:37:58 katarynka go-librespot[504]: time="2026-03-25T10:37:58+01:00" level=info msg="zeroconf server listening on port 33063" Mar 25 10:37:58 katarynka go-librespot[504]: time="2026-03-25T10:37:58+01:00" level=debug msg="obtained new client token: AAB2pBfOuJencM9B70xPzgsDBofOmugdGgDBdak0AWQpVtysvzImk+MMj4lR+RlZbgg4SjvYtUXZXUc8toywUrXnNbkUw3Xixxw24Gob/R1qp2WxjxUXDjHPNCbhkPZ3Z6195y6wClabUW0L6GCB8dMWhStNHP5SkBRfPiW3RZnRpIki+SZoudsjydxoCV56ST/LKDt7HPOoyxnlKGsn9+JRYcmUEZzqga4G+ppKFgbt5F/54ZywonYtpuU=" Mar 25 10:37:58 katarynka go-librespot[504]: time="2026-03-25T10:37:58+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 10:37:58 katarynka go-librespot[504]: time="2026-03-25T10:37:58+01:00" level=debug msg="completed keyexchange" Mar 25 10:37:58 katarynka go-librespot[504]: time="2026-03-25T10:37:58+01:00" level=debug msg="completed challenge" Mar 25 10:37:58 katarynka go-librespot[504]: time="2026-03-25T10:37:58+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 10:37:58 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 10:37:58 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 10:37:59 katarynka volumio[32629]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Mar 25 10:37:59 katarynka volumio[32629]: info: Initializing connection to go-librespot Websocket Mar 25 10:37:59 katarynka volumio[32629]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 25 10:38:01 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Mar 25 10:38:01 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 10:38:02 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 10:38:02 katarynka go-librespot[511]: go-librespot daemon starting... Mar 25 10:38:02 katarynka go-librespot[512]: time="2026-03-25T10:38:02+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 10:38:02 katarynka go-librespot[512]: time="2026-03-25T10:38:02+01:00" level=debug msg="app state loaded" Mar 25 10:38:02 katarynka go-librespot[512]: time="2026-03-25T10:38:02+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 10:38:02 katarynka volumio[32629]: info: Initializing connection to go-librespot Websocket Mar 25 10:38:02 katarynka go-librespot[512]: time="2026-03-25T10:38:02+01:00" level=debug msg="new websocket client" Mar 25 10:38:02 katarynka volumio[32629]: info: Connection to go-librespot Websocket established Mar 25 10:38:02 katarynka go-librespot[512]: time="2026-03-25T10:38:02+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Mar 25 10:38:02 katarynka go-librespot[512]: time="2026-03-25T10:38:02+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Mar 25 10:38:02 katarynka go-librespot[512]: time="2026-03-25T10:38:02+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Mar 25 10:38:02 katarynka volumio[32629]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Mar 25 10:38:02 katarynka volumio[32629]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Mar 25 10:38:02 katarynka volumio[32629]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Mar 25 10:38:02 katarynka volumio[32629]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Mar 25 10:38:02 katarynka volumio[32629]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Mar 25 10:38:02 katarynka volumio[32629]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Mar 25 10:38:02 katarynka volumio[32629]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Mar 25 10:38:02 katarynka volumio[32629]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Mar 25 10:38:02 katarynka volumio[32629]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Mar 25 10:38:02 katarynka volumio[32629]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Mar 25 10:38:02 katarynka volumio[32629]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Mar 25 10:38:02 katarynka volumio[32629]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Mar 25 10:38:02 katarynka volumio[32629]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Mar 25 10:38:02 katarynka volumio[32629]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Mar 25 10:38:02 katarynka volumio[32629]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Mar 25 10:38:02 katarynka volumio[32629]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Mar 25 10:38:02 katarynka volumio[32629]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Mar 25 10:38:02 katarynka volumio[32629]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Mar 25 10:38:02 katarynka volumio[32629]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Mar 25 10:38:02 katarynka volumio[32629]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Mar 25 10:38:02 katarynka volumio[32629]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Mar 25 10:38:02 katarynka volumio[32629]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Mar 25 10:38:02 katarynka volumio[32629]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Mar 25 10:38:02 katarynka volumio[32629]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Mar 25 10:38:02 katarynka volumio[32629]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Mar 25 10:38:02 katarynka volumio[32629]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Mar 25 10:38:02 katarynka volumio[32629]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Mar 25 10:38:02 katarynka volumio[32629]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Mar 25 10:38:02 katarynka volumio[32629]: info: Adding plugin bluetooth to MyMusic Plugins Mar 25 10:38:02 katarynka volumio[32629]: info: Adding plugin multiroom to MyMusic Plugins Mar 25 10:38:02 katarynka go-librespot[512]: time="2026-03-25T10:38:02+01:00" level=info msg="zeroconf server listening on port 36075" Mar 25 10:38:02 katarynka volumio[32629]: info: Adding plugin metavolumio to MyMusic Plugins Mar 25 10:38:02 katarynka volumio[32629]: info: Adding plugin cd_controller to MyMusic Plugins Mar 25 10:38:02 katarynka volumio[32629]: info: Adding plugin qobuzconnect to MyMusic Plugins Mar 25 10:38:02 katarynka volumio[32629]: info: Adding plugin smart_inputs to MyMusic Plugins Mar 25 10:38:02 katarynka volumio[32629]: info: Adding plugin tidalconnect to MyMusic Plugins Mar 25 10:38:02 katarynka volumio[32629]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Mar 25 10:38:02 katarynka go-librespot[512]: time="2026-03-25T10:38:02+01:00" level=debug msg="obtained new client token: AAB7wAnn62xKrtY34dLEY0s0xo8BODSLUW63Htj35+xqMFRK/IucodpESkLH1FDBwv74R3kxVvTn6l1w59b943gzYMXpXVc5hJYncVJL+eRzi+bWGGadBsGTfez+Vqed4vtTWNPGWjKyUNmPqy2ot3a6FFwH0laJPblwz5UfT4y7F9NivavyvR8mDX9ILkSwnI+kfO3RySj5gswL/jg/1m9RBwN3mtDVcZPxPLNWbmSbWLMolxv8j5piQHc=" Mar 25 10:38:02 katarynka go-librespot[512]: time="2026-03-25T10:38:02+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 10:38:02 katarynka go-librespot[512]: time="2026-03-25T10:38:02+01:00" level=debug msg="connected to ap-gew4.spotify.com:443" Mar 25 10:38:03 katarynka go-librespot[512]: time="2026-03-25T10:38:03+01:00" level=debug msg="completed keyexchange" Mar 25 10:38:03 katarynka go-librespot[512]: time="2026-03-25T10:38:03+01:00" level=debug msg="completed challenge" Mar 25 10:38:03 katarynka go-librespot[512]: time="2026-03-25T10:38: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 10:38:03 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 10:38:03 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 10:38:04 katarynka volumio[32629]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Mar 25 10:38:04 katarynka volumio[32629]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Mar 25 10:38:04 katarynka volumio[32629]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 10:38:04 katarynka volumio[32629]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 10:38:04 katarynka volumio[32629]: info: Starting MyVolumio Remote Streaming Endpoints Mar 25 10:38:04 katarynka volumio[32629]: info: MyVolumio login type: Token Mar 25 10:38:04 katarynka volumio[32629]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Mar 25 10:38:04 katarynka volumio[32629]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Mar 25 10:38:06 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Mar 25 10:38:06 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 10:38:06 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 10:38:06 katarynka go-librespot[520]: go-librespot daemon starting... Mar 25 10:38:06 katarynka go-librespot[521]: time="2026-03-25T10:38:06+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 10:38:06 katarynka go-librespot[521]: time="2026-03-25T10:38:06+01:00" level=debug msg="app state loaded" Mar 25 10:38:06 katarynka go-librespot[521]: time="2026-03-25T10:38:06+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 10:38:06 katarynka volumio[32629]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Mar 25 10:38:06 katarynka volumio[32629]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Mar 25 10:38:06 katarynka volumio[32629]: info: Streaming services startup Mar 25 10:38:06 katarynka volumio[32629]: info: Starting Streaming Daemon Mar 25 10:38:06 katarynka sudo[528]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Mar 25 10:38:06 katarynka sudo[528]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 10:38:06 katarynka volumio[32629]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Mar 25 10:38:06 katarynka sudo[528]: pam_unix(sudo:session): session closed for user root Mar 25 10:38:06 katarynka volumio[32629]: info: Getting Spotify volume Mar 25 10:38:06 katarynka volumio[32629]: info: Connection to go-librespot Websocket closed Mar 25 10:38:06 katarynka volumio[32629]: error: Cannot start Volumio Streaming Daemon Mar 25 10:38:06 katarynka volumio[32629]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Mar 25 10:38:06 katarynka volumio[32629]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Mar 25 10:38:06 katarynka volumio[32629]: 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 10:38:06 katarynka go-librespot[521]: time="2026-03-25T10:38:06+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 25 10:38:06 katarynka go-librespot[521]: time="2026-03-25T10:38:06+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 25 10:38:06 katarynka go-librespot[521]: time="2026-03-25T10:38:06+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 25 10:38:06 katarynka go-librespot[521]: time="2026-03-25T10:38:06+01:00" level=info msg="zeroconf server listening on port 35741" Mar 25 10:38:06 katarynka go-librespot[521]: time="2026-03-25T10:38:06+01:00" level=debug msg="obtained new client token: AAA0eMNFeJZCRWuIeW2o97OsQ9mBIboFo2tt06ZceOWqmKhjz1jF4Q24fDXcEr/D5tjluylwZTjgx5S8qySWOc36s5Za2JUAMlSs7m8zxdJOk/jRpzjAFwYqLDa9XrSwpBpPqsIjY9qGDjZZgOC23kqxDjPROhRIlW6Zny23YqiVLU3N3uVa/KMfBDQ8cngDea736zU/SDCxL0BCypX9eiu0aos8Pgw4wigE91/RqU17xaky64pUYWGx/+Y=" Mar 25 10:38:06 katarynka volumio[32629]: info: CoreCommandRouter::volumioGetState Mar 25 10:38:06 katarynka volumio[32629]: info: CorePlayQueue::getTrack 0 Mar 25 10:38:06 katarynka volumio[32629]: SPOTIFY: RECEIVED VOLUMIO VOLUME 96 Mar 25 10:38:06 katarynka volumio[32629]: SPOTIFY: SPOTIFY VOLUME undefined Mar 25 10:38:06 katarynka volumio[32629]: SPOTIFY: VOLUMIO VOLUME 96 Mar 25 10:38:06 katarynka volumio[32629]: info: Aligning Spotify Volume to Volumio Volume Mar 25 10:38:06 katarynka volumio[32629]: info: CoreCommandRouter::volumioGetState Mar 25 10:38:06 katarynka volumio[32629]: info: CorePlayQueue::getTrack 0 Mar 25 10:38:06 katarynka volumio[32629]: info: Setting Spotify Volume from Volumio: 96 Mar 25 10:38:07 katarynka go-librespot[521]: time="2026-03-25T10:38:07+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 10:38:07 katarynka go-librespot[521]: time="2026-03-25T10:38:07+01:00" level=debug msg="completed keyexchange" Mar 25 10:38:07 katarynka go-librespot[521]: time="2026-03-25T10:38:07+01:00" level=debug msg="completed challenge" Mar 25 10:38:07 katarynka go-librespot[521]: time="2026-03-25T10:38:07+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 10:38:07 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 10:38:07 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 10:38:07 katarynka volumio[32629]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 25 10:38:07 katarynka volumio[32629]: Error: socket hang up Mar 25 10:38:07 katarynka volumio[32629]: at connResetException (node:internal/errors:720:14) Mar 25 10:38:07 katarynka volumio[32629]: at Socket.socketOnEnd (node:_http_client:519:23) Mar 25 10:38:07 katarynka volumio[32629]: at Socket.emit (node:events:526:35) Mar 25 10:38:07 katarynka volumio[32629]: at endReadableNT (node:internal/streams/readable:1376:12) Mar 25 10:38:07 katarynka volumio[32629]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Mar 25 10:38:07 katarynka volumio[32629]: code: 'ECONNRESET', Mar 25 10:38:07 katarynka volumio[32629]: response: undefined Mar 25 10:38:07 katarynka volumio[32629]: } Mar 25 10:38:07 katarynka volumio[32629]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 25 10:38:08 katarynka sudo[567]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-03-25 10:37' Mar 25 10:38:08 katarynka sudo[567]: 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"