Mar 24 19:40:00 katarynka go-librespot[6937]: time="2026-03-24T19:40:00+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Mar 24 19:40:00 katarynka go-librespot[6937]: time="2026-03-24T19:40:00+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Mar 24 19:40:00 katarynka go-librespot[6937]: time="2026-03-24T19:40:00+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Mar 24 19:40:00 katarynka go-librespot[6937]: time="2026-03-24T19:40:00+01:00" level=info msg="zeroconf server listening on port 36651" Mar 24 19:40:00 katarynka go-librespot[6937]: time="2026-03-24T19:40:00+01:00" level=debug msg="obtained new client token: AAA2LXvasD2s4uHjlzliPDe+u7u6SXE1UNNOaFSylCQvUJIg6QhA+UqvF0/Pk33AS76BIq1O2Aec/6kk7jMapDYhFs9aWL0I/RH4DRE+jfPNoxdfG+9bP+RTiLDmcXn7zbZaCnznBpn+3M8p5D6Loaez9OJqOFBXw7axNWP/vvoo0HsNR3+Cu0JXdXyJ/xSm7LZb3dtpVoplhh7CoDp1SXO08wX7FG6ibXcBd68ubkyewP6kfX5+MSapF4U=" Mar 24 19:40:00 katarynka go-librespot[6937]: time="2026-03-24T19:40:00+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 24 19:40:00 katarynka go-librespot[6937]: time="2026-03-24T19:40:00+01:00" level=debug msg="completed keyexchange" Mar 24 19:40:00 katarynka go-librespot[6937]: time="2026-03-24T19:40:00+01:00" level=debug msg="completed challenge" Mar 24 19:40:00 katarynka go-librespot[6937]: time="2026-03-24T19:40:00+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 24 19:40:00 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 24 19:40:00 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 24 19:40:01 katarynka volumio[6843]: info: Loading plugin "outputs"... Mar 24 19:40:01 katarynka volumio[6843]: info: Loading plugin "albumart"... Mar 24 19:40:01 katarynka volumio[6843]: info: Plugin example_plugin is not enabled Mar 24 19:40:01 katarynka volumio[6843]: info: Loading plugin "inputs"... Mar 24 19:40:01 katarynka volumio[6843]: info: Loading plugin "updater_comm"... Mar 24 19:40:01 katarynka volumio[6843]: info: Plugin mpdemulation is not enabled Mar 24 19:40:01 katarynka volumio[6843]: info: Loading plugin "rest_api"... Mar 24 19:40:01 katarynka volumio[6843]: info: Loading plugin "websocket"... Mar 24 19:40:01 katarynka volumio[6843]: info: Starting Socket.io Server version 1.7.4 Mar 24 19:40:01 katarynka volumio[6843]: info: Loading i18n strings for locale pl Mar 24 19:40:01 katarynka volumio[6843]: Updating browse sources language Mar 24 19:40:01 katarynka volumio[6843]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 24 19:40:01 katarynka volumio[6843]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 24 19:40:01 katarynka volumio[6843]: info: CoreCommandRouter::initPlayerControls Mar 24 19:40:01 katarynka volumio[6843]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 19:40:01 katarynka volumio[6843]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 19:40:01 katarynka volumio[6843]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 19:40:01 katarynka volumio[6843]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 19:40:01 katarynka volumio[6843]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 19:40:01 katarynka volumio[6843]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 19:40:01 katarynka volumio[6843]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 19:40:01 katarynka volumio[6843]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 19:40:01 katarynka volumio[6843]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 24 19:40:01 katarynka volumio[6843]: Express server listening on port 3000 Mar 24 19:40:01 katarynka volumio[6843]: [Metrics] WebUI: 12s 611.75ms Mar 24 19:40:01 katarynka volumio[6843]: info: CoreStateMachine::resetVolumioState Mar 24 19:40:01 katarynka volumio[6843]: info: CoreStateMachine::getcurrentVolume Mar 24 19:40:01 katarynka volumio[6843]: info: CoreCommandRouter::volumioRetrievevolume Mar 24 19:40:02 katarynka volumio[6843]: info: Cannot read play queue from file Mar 24 19:40:02 katarynka volumio[6843]: info: Volumio Network Manager: Network status updated: 2 Mar 24 19:40:02 katarynka volumio[6944]: Forking 3 albumart workers Mar 24 19:40:02 katarynka volumio[6843]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 24 19:40:02 katarynka volumio[6843]: info: CoreStateMachine::setRepeat null single undefined Mar 24 19:40:02 katarynka volumio[6843]: info: CoreStateMachine::pushState Mar 24 19:40:02 katarynka volumio[6843]: info: CorePlayQueue::getTrack 0 Mar 24 19:40:02 katarynka volumio[6843]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 24 19:40:02 katarynka volumio[6843]: info: CoreCommandRouter::volumioPushState Mar 24 19:40:02 katarynka volumio[6843]: info: CoreStateMachine::setRandom null Mar 24 19:40:02 katarynka volumio[6843]: info: CoreStateMachine::pushState Mar 24 19:40:02 katarynka volumio[6843]: info: CorePlayQueue::getTrack 0 Mar 24 19:40:02 katarynka volumio[6843]: info: CoreCommandRouter::volumioPushState Mar 24 19:40:02 katarynka volumio[6843]: info: Setting Device type: Raspberry PI Mar 24 19:40:02 katarynka volumio[6843]: info: Completed loading Core Plugins Mar 24 19:40:02 katarynka volumio[6843]: info: Preparing to generate the ALSA configuration file Mar 24 19:40:02 katarynka volumio[6843]: info: VolumeController:: Volume=96 Mute =false Mar 24 19:40:02 katarynka volumio[6843]: info: CoreStateMachine::pushState Mar 24 19:40:02 katarynka volumio[6843]: info: CorePlayQueue::getTrack 0 Mar 24 19:40:02 katarynka volumio[6843]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 24 19:40:02 katarynka volumio[6843]: info: CoreCommandRouter::volumioPushState Mar 24 19:40:02 katarynka volumio[6843]: info: CoreStateMachine::updateTrackBlock Mar 24 19:40:02 katarynka volumio[6843]: info: CorePlayQueue::getTrackBlock Mar 24 19:40:02 katarynka volumio[6843]: info: CoreCommandRouter::volumioRetrievevolume Mar 24 19:40:02 katarynka volumio[6843]: info: Asound.conf file unchanged, so no further update is needed Mar 24 19:40:02 katarynka volumio[6843]: info: Output device has changed, restarting MPD Mar 24 19:40:02 katarynka volumio[6843]: info: Output device has changed, restarting Shairport Sync Mar 24 19:40:02 katarynka volumio[6843]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 19:40:02 katarynka volumio[6843]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 24 19:40:02 katarynka sudo[7001]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 24 19:40:02 katarynka sudo[7001]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 19:40:02 katarynka sudo[6999]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 24 19:40:02 katarynka sudo[6999]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 19:40:02 katarynka sudo[6999]: pam_unix(sudo:session): session closed for user root Mar 24 19:40:02 katarynka volumio[6843]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 24 19:40:02 katarynka volumio[6843]: info: ___________ START PLUGINS ___________ Mar 24 19:40:02 katarynka systemd[1]: Stopping mpd.service - Music Player Daemon... Mar 24 19:40:02 katarynka volumio[6843]: info: ControllerMpd::onStart: Initializing MPD Mar 24 19:40:02 katarynka volumio[6843]: info: Creating MPD Configuration file Mar 24 19:40:03 katarynka systemd[1]: mpd.service: Deactivated successfully. Mar 24 19:40:03 katarynka systemd[1]: Stopped mpd.service - Music Player Daemon. Mar 24 19:40:03 katarynka systemd[1]: mpd.service: Consumed 7.614s CPU time. Mar 24 19:40:03 katarynka systemd[1]: mpd.socket: Deactivated successfully. Mar 24 19:40:03 katarynka systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Mar 24 19:40:03 katarynka systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Mar 24 19:40:03 katarynka volumio[6843]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 24 19:40:03 katarynka volumio[6843]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 24 19:40:03 katarynka volumio[6843]: info: [1774377603090] CoreMusicLibrary::Adding element Serwery Mediów Mar 24 19:40:03 katarynka volumio[6843]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 24 19:40:03 katarynka sudo[7009]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 24 19:40:03 katarynka sudo[7009]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 19:40:03 katarynka systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Mar 24 19:40:03 katarynka systemd[1]: Starting mpd.service - Music Player Daemon... Mar 24 19:40:03 katarynka sudo[7009]: pam_unix(sudo:session): session closed for user root Mar 24 19:40:03 katarynka volumio[6843]: info: UPNP Browser: Client initialized successfully Mar 24 19:40:03 katarynka sudo[7012]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 24 19:40:03 katarynka sudo[7012]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 19:40:03 katarynka volumio[6843]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 19:40:03 katarynka volumio[6843]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 24 19:40:03 katarynka systemd[1]: mpd.service: Deactivated successfully. Mar 24 19:40:03 katarynka systemd[1]: Stopped mpd.service - Music Player Daemon. Mar 24 19:40:03 katarynka volumio[6843]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 24 19:40:03 katarynka volumio[6843]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 19:40:03 katarynka volumio[6843]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 24 19:40:03 katarynka systemd[1]: mpd.socket: Deactivated successfully. Mar 24 19:40:03 katarynka systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Mar 24 19:40:03 katarynka systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Mar 24 19:40:03 katarynka systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Mar 24 19:40:03 katarynka systemd[1]: Starting mpd.service - Music Player Daemon... Mar 24 19:40:03 katarynka volumio[6843]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 24 19:40:03 katarynka volumio[6843]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 24 19:40:03 katarynka volumio[6843]: info: [1774377603444] CoreMusicLibrary::Adding element Last_100 Mar 24 19:40:03 katarynka volumio[6843]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 24 19:40:03 katarynka volumio[6843]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 24 19:40:03 katarynka volumio[6843]: info: [1774377603453] CoreMusicLibrary::Adding element Webradio Mar 24 19:40:03 katarynka volumio[6843]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 24 19:40:03 katarynka volumio[6843]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 24 19:40:03 katarynka volumio[6843]: info: Initializing BBC Radios Mar 24 19:40:03 katarynka volumio[6843]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 24 19:40:03 katarynka volumio[6843]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 24 19:40:03 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Mar 24 19:40:03 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 24 19:40:03 katarynka volumio[6843]: info: Creating Spotify config file Mar 24 19:40:03 katarynka volumio[6843]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 19:40:03 katarynka volumio-remote-updater[622]: [2026-03-24 19:40:03] [connect] Successful connection Mar 24 19:40:03 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 24 19:40:03 katarynka go-librespot[7040]: go-librespot daemon starting... Mar 24 19:40:03 katarynka go-librespot[7041]: time="2026-03-24T19:40:03+01:00" level=info msg="running go-librespot 0.4.0" Mar 24 19:40:03 katarynka sudo[7026]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Mar 24 19:40:03 katarynka sudo[7026]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Mar 24 19:40:03 katarynka sudo[7026]: pam_unix(sudo:session): session closed for user root Mar 24 19:40:04 katarynka go-librespot[7041]: time="2026-03-24T19:40:04+01:00" level=info msg="zeroconf server listening on port 43915" Mar 24 19:40:04 katarynka volumio[6843]: info: Volumio Calling Home Mar 24 19:40:05 katarynka volumio[6965]: Starting albumart workers Mar 24 19:40:06 katarynka volumio[6843]: info: Discovery: adding 4d616d77-6a8c-4da2-85a4-840d70f98e51 Mar 24 19:40:06 katarynka volumio[6843]: info: Discovery: Found device katarynka Mar 24 19:40:06 katarynka volumio[6843]: info: CoreCommandRouter::volumioGetState Mar 24 19:40:06 katarynka volumio[6843]: info: CorePlayQueue::getTrack 0 Mar 24 19:40:06 katarynka sudo[7068]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 24 19:40:06 katarynka sudo[7068]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 19:40:06 katarynka sudo[7068]: pam_unix(sudo:session): session closed for user root Mar 24 19:40:06 katarynka sudo[7070]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 24 19:40:06 katarynka sudo[7070]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 19:40:06 katarynka volumio[6843]: info: MPD Permissions set Mar 24 19:40:06 katarynka volumio[6843]: info: MPD Permissions set Mar 24 19:40:06 katarynka volumio[6843]: info: VolumeController:: Volume=96 Mute =false Mar 24 19:40:06 katarynka sudo[7070]: pam_unix(sudo:session): session closed for user root Mar 24 19:40:06 katarynka volumio[6843]: info: CoreStateMachine::pushState Mar 24 19:40:06 katarynka volumio[6843]: info: CorePlayQueue::getTrack 0 Mar 24 19:40:06 katarynka volumio[6843]: info: CoreCommandRouter::volumioPushState Mar 24 19:40:06 katarynka volumio-remote-updater[622]: [2026-03-24 19:40:06] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1774377603 101 Mar 24 19:40:06 katarynka volumio[6843]: 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 24 19:40:06 katarynka volumio[6843]: info: Volumio called home Mar 24 19:40:06 katarynka volumio[6843]: info: Spotify config file written Mar 24 19:40:06 katarynka volumio[6843]: info: Discovery: this is already registered, 4d616d77-6a8c-4da2-85a4-840d70f98e51 Mar 24 19:40:06 katarynka volumio[6843]: info: Discovery: Found device katarynka Mar 24 19:40:06 katarynka sudo[7074]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Mar 24 19:40:06 katarynka sudo[7074]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 19:40:06 katarynka volumio[6843]: info: CoreCommandRouter::volumioGetState Mar 24 19:40:06 katarynka volumio[6843]: info: CorePlayQueue::getTrack 0 Mar 24 19:40:06 katarynka systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Mar 24 19:40:06 katarynka systemd[1]: go-librespot-daemon.service: Deactivated successfully. Mar 24 19:40:06 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 24 19:40:06 katarynka volumio[6966]: Starting albumart workers Mar 24 19:40:06 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 24 19:40:06 katarynka go-librespot[7076]: go-librespot daemon starting... Mar 24 19:40:06 katarynka sudo[7074]: pam_unix(sudo:session): session closed for user root Mar 24 19:40:06 katarynka go-librespot[7077]: time="2026-03-24T19:40:06+01:00" level=info msg="running go-librespot 0.4.0" Mar 24 19:40:06 katarynka go-librespot[7077]: time="2026-03-24T19:40:06+01:00" level=debug msg="app state loaded" Mar 24 19:40:06 katarynka go-librespot[7077]: time="2026-03-24T19:40:06+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 24 19:40:07 katarynka volumio[6964]: Starting albumart workers Mar 24 19:40:07 katarynka volumio[6843]: 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 24 19:40:07 katarynka volumio[6843]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 19:40:07 katarynka volumio[6843]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 19:40:07 katarynka volumio[6843]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 19:40:07 katarynka volumio[6843]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 19:40:07 katarynka volumio[6843]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 19:40:07 katarynka volumio[6843]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 19:40:07 katarynka volumio[6843]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 19:40:07 katarynka volumio[6843]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 19:40:07 katarynka volumio[6843]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 24 19:40:07 katarynka volumio[6843]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 19:40:07 katarynka volumio[6843]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 19:40:07 katarynka volumio[6843]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 19:40:07 katarynka volumio[6843]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 19:40:07 katarynka volumio[6843]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 19:40:07 katarynka volumio[6843]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 19:40:07 katarynka volumio[6843]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 19:40:07 katarynka volumio[6843]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 19:40:07 katarynka volumio[6843]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 19:40:07 katarynka volumio[6843]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 24 19:40:07 katarynka volumio[6843]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 19:40:07 katarynka volumio[6843]: info: No need to fix Spotify hosts Mar 24 19:40:07 katarynka go-librespot[7077]: time="2026-03-24T19:40:07+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Mar 24 19:40:07 katarynka go-librespot[7077]: time="2026-03-24T19:40:07+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 24 19:40:07 katarynka go-librespot[7077]: time="2026-03-24T19:40:07+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 24 19:40:07 katarynka go-librespot[7077]: time="2026-03-24T19:40:07+01:00" level=info msg="zeroconf server listening on port 35791" Mar 24 19:40:07 katarynka go-librespot[7077]: time="2026-03-24T19:40:07+01:00" level=debug msg="obtained new client token: AADQ8yOp04wTKorknQ00I+By7y/0YytPf4trfdym1x4pGEUT7wQiVUsO2tGHnNZXvumd/t5ROaliKuNiEoqYdO2d7c5EfQ9scx5Vbb8Qrk7pM+3sgi/iPCGKHZqxWwHFUakCm+sQml1UxTM9TkwG4rylQFMQtWDQzjFE9W/nyx+TqeoVM2bSlq4mEB61y5GUOvEMAlkXXTlSw2DLutCGBUEw6p4cLoNv98lju1LobYahpSa9/3duOoSp8dw=" Mar 24 19:40:07 katarynka go-librespot[7077]: time="2026-03-24T19:40:07+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 24 19:40:07 katarynka go-librespot[7077]: time="2026-03-24T19:40:07+01:00" level=debug msg="completed keyexchange" Mar 24 19:40:07 katarynka go-librespot[7077]: time="2026-03-24T19:40:07+01:00" level=debug msg="completed challenge" Mar 24 19:40:07 katarynka go-librespot[7077]: time="2026-03-24T19:40: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 24 19:40:07 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 24 19:40:07 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 24 19:40:08 katarynka volumio[6843]: info: Starting Shairport Sync Mar 24 19:40:08 katarynka volumio[6843]: info: Starting Shairport Sync Mar 24 19:40:08 katarynka volumio[6843]: info: Starting Shairport Sync Mar 24 19:40:08 katarynka sudo[7102]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 24 19:40:08 katarynka sudo[7102]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 19:40:08 katarynka sudo[7103]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 24 19:40:08 katarynka sudo[7103]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 19:40:08 katarynka sudo[7109]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Mar 24 19:40:08 katarynka sudo[7109]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 19:40:08 katarynka sudo[7105]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 24 19:40:08 katarynka sudo[7105]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 19:40:08 katarynka systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Mar 24 19:40:08 katarynka sudo[7109]: pam_unix(sudo:session): session closed for user root Mar 24 19:40:08 katarynka systemd[1]: shairport-sync.service: Deactivated successfully. Mar 24 19:40:08 katarynka systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 24 19:40:08 katarynka systemd[1]: shairport-sync.service: Consumed 2.417s CPU time. Mar 24 19:40:08 katarynka systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 24 19:40:08 katarynka sudo[7103]: pam_unix(sudo:session): session closed for user root Mar 24 19:40:08 katarynka sudo[7105]: pam_unix(sudo:session): session closed for user root Mar 24 19:40:08 katarynka volumio[6843]: info: An error occurred while refreshing Spotify Token Error: Bad Request Mar 24 19:40:08 katarynka sudo[7102]: pam_unix(sudo:session): session closed for user root Mar 24 19:40:08 katarynka volumio[6843]: info: Upmpdcli Daemon Started Mar 24 19:40:08 katarynka volumio[6843]: info: CoreCommandRouter::volumioGetState Mar 24 19:40:08 katarynka volumio[6843]: info: CorePlayQueue::getTrack 0 Mar 24 19:40:08 katarynka volumio[6843]: info: Shairport-Sync Started Mar 24 19:40:08 katarynka volumio[6843]: Error adding Membership: Error: addMembership EINVAL Mar 24 19:40:08 katarynka volumio[6843]: info: Shairport-Sync Started Mar 24 19:40:08 katarynka volumio[6843]: info: Shairport-Sync Started Mar 24 19:40:10 katarynka volumio[6843]: info: go-librespot daemon successfully initialized Mar 24 19:40:11 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Mar 24 19:40:11 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 24 19:40:11 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 24 19:40:11 katarynka go-librespot[7140]: go-librespot daemon starting... Mar 24 19:40:11 katarynka go-librespot[7141]: time="2026-03-24T19:40:11+01:00" level=info msg="running go-librespot 0.4.0" Mar 24 19:40:11 katarynka go-librespot[7141]: time="2026-03-24T19:40:11+01:00" level=debug msg="app state loaded" Mar 24 19:40:11 katarynka go-librespot[7141]: time="2026-03-24T19:40:11+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 24 19:40:11 katarynka go-librespot[7141]: time="2026-03-24T19:40:11+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 24 19:40:11 katarynka go-librespot[7141]: time="2026-03-24T19:40:11+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 24 19:40:11 katarynka go-librespot[7141]: time="2026-03-24T19:40:11+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 24 19:40:11 katarynka mpd[7048]: 2026-03-24T19:40:11 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Mar 24 19:40:11 katarynka systemd[1]: Started mpd.service - Music Player Daemon. Mar 24 19:40:11 katarynka sudo[7012]: pam_unix(sudo:session): session closed for user root Mar 24 19:40:11 katarynka go-librespot[7141]: time="2026-03-24T19:40:11+01:00" level=info msg="zeroconf server listening on port 44869" Mar 24 19:40:11 katarynka sudo[7001]: pam_unix(sudo:session): session closed for user root Mar 24 19:40:11 katarynka volumio[6843]: info: Completed starting Core Plugins Mar 24 19:40:11 katarynka volumio[6843]: info: ------------------------------------------- Mar 24 19:40:11 katarynka volumio[6843]: info: ----- MyVolumio plugins startup ---- Mar 24 19:40:11 katarynka volumio[6843]: info: ------------------------------------------- Mar 24 19:40:11 katarynka volumio[6843]: info: [MyVolumio PluginManager] Fetching plans data.... Mar 24 19:40:11 katarynka go-librespot[7141]: time="2026-03-24T19:40:11+01:00" level=debug msg="obtained new client token: AABEzLk8mB3+uewfICE058lfUzV+n5fOZHelLGJMr1ISQ2w1jMM9HAerRgpiMvCUh8YWD+JjmVZFCvnkwsrPFghbrmmfOhj1U3/VcwHwFvzEzwNYk+TA6RFq9GRwTzMf37y6MdBgDV9ID4uX4xY++IzqGNeC/LraxdPU4YqArNT9chMG15py6LHRJxo4lFdX8R9q/KmnKS9+cRd/PkWg/VcyMV5TT4q0DG1mZMc9/GOcnqNpBqZpVqj7tfk=" Mar 24 19:40:11 katarynka go-librespot[7141]: time="2026-03-24T19:40:11+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 24 19:40:11 katarynka volumio[6843]: error: MPD error: The expression evaluated to a falsy value: Mar 24 19:40:11 katarynka volumio[6843]: assert.ok(self.idling) Mar 24 19:40:11 katarynka volumio[6843]: error: The expression evaluated to a falsy value: Mar 24 19:40:11 katarynka volumio[6843]: assert.ok(self.idling) Mar 24 19:40:11 katarynka volumio[6843]: error: updateQueue error: null Mar 24 19:40:11 katarynka volumio[6843]: info: MPD running with PID7048 Mar 24 19:40:11 katarynka volumio[6843]: ,establishing connection Mar 24 19:40:11 katarynka volumio[6843]: error: updateQueue error: null Mar 24 19:40:11 katarynka go-librespot[7141]: time="2026-03-24T19:40:11+01:00" level=debug msg="completed keyexchange" Mar 24 19:40:11 katarynka go-librespot[7141]: time="2026-03-24T19:40:11+01:00" level=debug msg="completed challenge" Mar 24 19:40:12 katarynka go-librespot[7141]: time="2026-03-24T19:40:12+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 24 19:40:12 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 24 19:40:12 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 24 19:40:13 katarynka volumio[6843]: info: Initializing connection to go-librespot Websocket Mar 24 19:40:13 katarynka volumio[6843]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 24 19:40:14 katarynka sudo[7171]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Mar 24 19:40:14 katarynka sudo[7171]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 19:40:14 katarynka sudo[7173]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Mar 24 19:40:14 katarynka sudo[7173]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 19:40:14 katarynka systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Mar 24 19:40:14 katarynka systemd[1]: mpd_monitor.service: Deactivated successfully. Mar 24 19:40:14 katarynka systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Mar 24 19:40:14 katarynka systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Mar 24 19:40:15 katarynka sudo[7171]: pam_unix(sudo:session): session closed for user root Mar 24 19:40:15 katarynka mpd_monitor.sh[7176]: MPD Monitor Service: Starting MPD Monitor Service Mar 24 19:40:15 katarynka sudo[7173]: pam_unix(sudo:session): session closed for user root Mar 24 19:40:15 katarynka volumio[6843]: info: Successfully started MPD Monitor Mar 24 19:40:15 katarynka volumio[6843]: info: Successfully started MPD Monitor Mar 24 19:40:15 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Mar 24 19:40:15 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 24 19:40:15 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 24 19:40:15 katarynka go-librespot[7180]: go-librespot daemon starting... Mar 24 19:40:15 katarynka go-librespot[7181]: time="2026-03-24T19:40:15+01:00" level=info msg="running go-librespot 0.4.0" Mar 24 19:40:15 katarynka go-librespot[7181]: time="2026-03-24T19:40:15+01:00" level=debug msg="app state loaded" Mar 24 19:40:15 katarynka go-librespot[7181]: time="2026-03-24T19:40:15+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 24 19:40:15 katarynka go-librespot[7181]: time="2026-03-24T19:40:15+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 24 19:40:15 katarynka go-librespot[7181]: time="2026-03-24T19:40:15+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 24 19:40:15 katarynka go-librespot[7181]: time="2026-03-24T19:40:15+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 24 19:40:15 katarynka go-librespot[7181]: time="2026-03-24T19:40:15+01:00" level=info msg="zeroconf server listening on port 34737" Mar 24 19:40:15 katarynka go-librespot[7181]: time="2026-03-24T19:40:15+01:00" level=debug msg="obtained new client token: AACULSnnZjg0ENGM46RA2l8B268Rj1Xy2J1BMIKMEP7rop7rwk21bLDvPBJRCRi2+bQwmwSlIcdckFsw2RQNe+Jp7oKfFpPebRvqIBilAWW6PQG+NzxlhZD7mJcZNEBHlr/s5JQq68p6fpNy/JBLfZDTJrhlsZ72rbcGmgCD4UyHzmf2mhuJVVMZ0EjwxIZ6mX3LXZZZamGLU5TTgtcMrzv+ze3p7sjPRT5ZEJ/jf2blpEjfSt+bYGQiAKE=" Mar 24 19:40:15 katarynka go-librespot[7181]: time="2026-03-24T19:40:15+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 24 19:40:15 katarynka go-librespot[7181]: time="2026-03-24T19:40:15+01:00" level=debug msg="completed keyexchange" Mar 24 19:40:15 katarynka go-librespot[7181]: time="2026-03-24T19:40:15+01:00" level=debug msg="completed challenge" Mar 24 19:40:16 katarynka go-librespot[7181]: time="2026-03-24T19:40:16+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 24 19:40:16 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 24 19:40:16 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 24 19:40:16 katarynka volumio[6843]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Mar 24 19:40:16 katarynka volumio[6843]: info: Initializing connection to go-librespot Websocket Mar 24 19:40:16 katarynka volumio[6843]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 24 19:40:19 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Mar 24 19:40:19 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 24 19:40:19 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 24 19:40:19 katarynka go-librespot[7188]: go-librespot daemon starting... Mar 24 19:40:19 katarynka go-librespot[7189]: time="2026-03-24T19:40:19+01:00" level=info msg="running go-librespot 0.4.0" Mar 24 19:40:19 katarynka go-librespot[7189]: time="2026-03-24T19:40:19+01:00" level=debug msg="app state loaded" Mar 24 19:40:19 katarynka go-librespot[7189]: time="2026-03-24T19:40:19+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 24 19:40:19 katarynka go-librespot[7189]: time="2026-03-24T19:40:19+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 24 19:40:19 katarynka go-librespot[7189]: time="2026-03-24T19:40:19+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 24 19:40:19 katarynka go-librespot[7189]: time="2026-03-24T19:40:19+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 24 19:40:19 katarynka go-librespot[7189]: time="2026-03-24T19:40:19+01:00" level=info msg="zeroconf server listening on port 44249" Mar 24 19:40:19 katarynka go-librespot[7189]: time="2026-03-24T19:40:19+01:00" level=debug msg="obtained new client token: AAC2xtDgEU2WLqQppxSO07gdE5rg7xKNR2HlyVVeIs+8bqSgh5lo8Ow0lM3jZUYEQyAXRg+WeKO8P52y9pmOjrvF8BeH4paEDtaGQojjbIYXGl+26DqKhk7ngksge2d6oBlnvNTm6km0JgtfOEM07jj1j2QB8SUqK8mHS9+YEaUUwT6OGrR4ir7t0M1ic5lrppdUaAUzgyqKIwfwEMttyQJdiJ5gWS0ZJ80/lU8VekbhaCaRUwSnsaIsATg=" Mar 24 19:40:19 katarynka go-librespot[7189]: time="2026-03-24T19:40:19+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 24 19:40:19 katarynka volumio[6843]: info: Initializing connection to go-librespot Websocket Mar 24 19:40:19 katarynka go-librespot[7189]: time="2026-03-24T19:40:19+01:00" level=debug msg="new websocket client" Mar 24 19:40:19 katarynka volumio[6843]: info: Connection to go-librespot Websocket established Mar 24 19:40:19 katarynka go-librespot[7189]: time="2026-03-24T19:40:19+01:00" level=debug msg="connected to ap-gew4.spotify.com:443" Mar 24 19:40:19 katarynka go-librespot[7189]: time="2026-03-24T19:40:19+01:00" level=debug msg="completed keyexchange" Mar 24 19:40:19 katarynka go-librespot[7189]: time="2026-03-24T19:40:19+01:00" level=debug msg="completed challenge" Mar 24 19:40:20 katarynka go-librespot[7189]: time="2026-03-24T19:40:20+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 24 19:40:20 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 24 19:40:20 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 24 19:40:20 katarynka volumio[6843]: info: Connection to go-librespot Websocket closed Mar 24 19:40:20 katarynka volumio[6843]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Mar 24 19:40:20 katarynka volumio[6843]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Mar 24 19:40:20 katarynka volumio[6843]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Mar 24 19:40:20 katarynka volumio[6843]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Mar 24 19:40:20 katarynka volumio[6843]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Mar 24 19:40:20 katarynka volumio[6843]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Mar 24 19:40:20 katarynka volumio[6843]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Mar 24 19:40:20 katarynka volumio[6843]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Mar 24 19:40:20 katarynka volumio[6843]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Mar 24 19:40:20 katarynka volumio[6843]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Mar 24 19:40:20 katarynka volumio[6843]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Mar 24 19:40:20 katarynka volumio[6843]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Mar 24 19:40:20 katarynka volumio[6843]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Mar 24 19:40:20 katarynka volumio[6843]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Mar 24 19:40:20 katarynka volumio[6843]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Mar 24 19:40:20 katarynka volumio[6843]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Mar 24 19:40:20 katarynka volumio[6843]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Mar 24 19:40:20 katarynka volumio[6843]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Mar 24 19:40:20 katarynka volumio[6843]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Mar 24 19:40:20 katarynka volumio[6843]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Mar 24 19:40:20 katarynka volumio[6843]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Mar 24 19:40:20 katarynka volumio[6843]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Mar 24 19:40:20 katarynka volumio[6843]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Mar 24 19:40:20 katarynka volumio[6843]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Mar 24 19:40:20 katarynka volumio[6843]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Mar 24 19:40:20 katarynka volumio[6843]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Mar 24 19:40:20 katarynka volumio[6843]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Mar 24 19:40:20 katarynka volumio[6843]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Mar 24 19:40:20 katarynka volumio[6843]: info: Adding plugin bluetooth to MyMusic Plugins Mar 24 19:40:20 katarynka volumio[6843]: info: Adding plugin multiroom to MyMusic Plugins Mar 24 19:40:20 katarynka volumio[6843]: info: Adding plugin metavolumio to MyMusic Plugins Mar 24 19:40:20 katarynka volumio[6843]: info: Adding plugin cd_controller to MyMusic Plugins Mar 24 19:40:20 katarynka volumio[6843]: info: Adding plugin qobuzconnect to MyMusic Plugins Mar 24 19:40:20 katarynka volumio[6843]: info: Adding plugin smart_inputs to MyMusic Plugins Mar 24 19:40:20 katarynka volumio[6843]: info: Adding plugin tidalconnect to MyMusic Plugins Mar 24 19:40:20 katarynka volumio[6843]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Mar 24 19:40:22 katarynka volumio[6843]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Mar 24 19:40:22 katarynka volumio[6843]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Mar 24 19:40:22 katarynka volumio[6843]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 24 19:40:22 katarynka volumio[6843]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 24 19:40:22 katarynka volumio[6843]: info: Starting MyVolumio Remote Streaming Endpoints Mar 24 19:40:22 katarynka volumio[6843]: info: MyVolumio login type: Token Mar 24 19:40:22 katarynka volumio[6843]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Mar 24 19:40:22 katarynka volumio[6843]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Mar 24 19:40:23 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Mar 24 19:40:23 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 24 19:40:23 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 24 19:40:23 katarynka go-librespot[7196]: go-librespot daemon starting... Mar 24 19:40:23 katarynka go-librespot[7197]: time="2026-03-24T19:40:23+01:00" level=info msg="running go-librespot 0.4.0" Mar 24 19:40:23 katarynka go-librespot[7197]: time="2026-03-24T19:40:23+01:00" level=debug msg="app state loaded" Mar 24 19:40:23 katarynka go-librespot[7197]: time="2026-03-24T19:40:23+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 24 19:40:23 katarynka go-librespot[7197]: time="2026-03-24T19:40:23+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Mar 24 19:40:23 katarynka go-librespot[7197]: time="2026-03-24T19:40:23+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 24 19:40:23 katarynka go-librespot[7197]: time="2026-03-24T19:40:23+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 24 19:40:23 katarynka go-librespot[7197]: time="2026-03-24T19:40:23+01:00" level=info msg="zeroconf server listening on port 44007" Mar 24 19:40:23 katarynka go-librespot[7197]: time="2026-03-24T19:40:23+01:00" level=debug msg="obtained new client token: AACoctk+ZmZ7Td1DhV68MpqbPdSarQbRCy0ZHc0ApwMqnscJvg6B0wJrRRkQ1huAVaPYdAgGsHwSL+dBZGuY41UdGq77bZ6zLbDDxoQHZLOgzBsZ80cSuWYMI1zYw74KxNgu185UKu2ec3K8Ce2OjmLqzzcq3+q8cw3AHIxh6VcOp6buWoOkhv/vvhE5xawV3cHaSZIY91u1bGS/nv7Nq27F7uf711k62rcl/PHbRy3PSPZSaFaUUiUoBkg=" Mar 24 19:40:23 katarynka go-librespot[7197]: time="2026-03-24T19:40:23+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 24 19:40:24 katarynka go-librespot[7197]: time="2026-03-24T19:40:24+01:00" level=debug msg="completed keyexchange" Mar 24 19:40:24 katarynka go-librespot[7197]: time="2026-03-24T19:40:24+01:00" level=debug msg="completed challenge" Mar 24 19:40:24 katarynka go-librespot[7197]: time="2026-03-24T19:40:24+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 24 19:40:24 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 24 19:40:24 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 24 19:40:24 katarynka volumio[6843]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Mar 24 19:40:24 katarynka volumio[6843]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Mar 24 19:40:24 katarynka volumio[6843]: info: Streaming services startup Mar 24 19:40:24 katarynka volumio[6843]: info: Starting Streaming Daemon Mar 24 19:40:24 katarynka sudo[7205]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Mar 24 19:40:24 katarynka sudo[7205]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 19:40:24 katarynka volumio[6843]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Mar 24 19:40:24 katarynka sudo[7205]: pam_unix(sudo:session): session closed for user root Mar 24 19:40:24 katarynka volumio[6843]: info: Getting Spotify volume Mar 24 19:40:24 katarynka volumio[6843]: info: Initializing connection to go-librespot Websocket Mar 24 19:40:24 katarynka volumio[6843]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 24 19:40:24 katarynka volumio[6843]: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 24 19:40:24 katarynka volumio[6843]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Mar 24 19:40:24 katarynka volumio[6843]: errno: -111, Mar 24 19:40:24 katarynka volumio[6843]: code: 'ECONNREFUSED', Mar 24 19:40:24 katarynka volumio[6843]: syscall: 'connect', Mar 24 19:40:24 katarynka volumio[6843]: address: '127.0.0.1', Mar 24 19:40:24 katarynka volumio[6843]: port: 9879, Mar 24 19:40:24 katarynka volumio[6843]: response: undefined Mar 24 19:40:24 katarynka volumio[6843]: } Mar 24 19:40:24 katarynka volumio[6843]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 24 19:40:26 katarynka sudo[7240]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-03-24 19:39' Mar 24 19:40:26 katarynka sudo[7240]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 19:40:26 katarynka sudo[7240]: pam_unix(sudo:session): session closed for user root Mar 24 19:40:27 katarynka volumio-remote-updater[622]: [2026-03-24 19:40:27] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Mar 24 19:40:27 katarynka volumio-remote-updater[622]: [2026-03-24 19:40:27] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Mar 24 19:40:27 katarynka systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Mar 24 19:40:27 katarynka systemd[1]: volumio.service: Failed with result 'exit-code'. Mar 24 19:40:27 katarynka systemd[1]: volumio.service: Consumed 48.932s CPU time. Mar 24 19:40:27 katarynka systemd[1]: Started dynamicswap.service - dynamicswap service. Mar 24 19:40:27 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Mar 24 19:40:27 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 24 19:40:27 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 24 19:40:27 katarynka systemd[1]: dynamicswap.service: Deactivated successfully. Mar 24 19:40:27 katarynka systemd[1]: volumio.service: Scheduled restart job, restart counter is at 25311. Mar 24 19:40:27 katarynka go-librespot[7259]: go-librespot daemon starting... Mar 24 19:40:27 katarynka systemd[1]: Started dynamicswap.service - dynamicswap service. Mar 24 19:40:27 katarynka systemd[1]: Stopped volumio.service - Volumio Backend Module. Mar 24 19:40:27 katarynka systemd[1]: volumio.service: Consumed 48.932s CPU time. Mar 24 19:40:27 katarynka systemd[1]: Started volumio.service - Volumio Backend Module. Mar 24 19:40:27 katarynka go-librespot[7260]: time="2026-03-24T19:40:27+01:00" level=info msg="running go-librespot 0.4.0" Mar 24 19:40:27 katarynka go-librespot[7260]: time="2026-03-24T19:40:27+01:00" level=debug msg="app state loaded" Mar 24 19:40:27 katarynka go-librespot[7260]: time="2026-03-24T19:40:27+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 24 19:40:27 katarynka systemd[1]: dynamicswap.service: Deactivated successfully. Mar 24 19:40:27 katarynka go-librespot[7260]: time="2026-03-24T19:40: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-gew1.spotify.com:80]" Mar 24 19:40:27 katarynka go-librespot[7260]: time="2026-03-24T19:40:27+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 24 19:40:27 katarynka go-librespot[7260]: time="2026-03-24T19:40:27+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 24 19:40:27 katarynka go-librespot[7260]: time="2026-03-24T19:40:27+01:00" level=info msg="zeroconf server listening on port 46657" Mar 24 19:40:27 katarynka go-librespot[7260]: time="2026-03-24T19:40:27+01:00" level=debug msg="obtained new client token: AADcLsYF6BKyOcxz1AHriQQzNdcpPNxSlvaa6URv9XJg7eN49HSuEbXgZf2deoz56aadP9zSsd0IaKnJQH1dBvR4I84B/JRE6Vg1zLDCBP+fdyEVXVCj962px68wQOnCFshILRCcpYfeSp6rKwipxtgzUHqgfiL47Jdd8ZDnBKXI41IgRTsNByZ/e4RNhJUgKOR/XFQ33E+7vlV0eONMLU4uFdf/rfALrEW7XbSxPykYOtiTUXiKGHmffgM=" Mar 24 19:40:27 katarynka go-librespot[7260]: time="2026-03-24T19:40: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 24 19:40:27 katarynka go-librespot[7260]: time="2026-03-24T19:40:27+01:00" level=debug msg="connected to ap-gew4.spotify.com:443" Mar 24 19:40:28 katarynka go-librespot[7260]: time="2026-03-24T19:40:28+01:00" level=debug msg="completed keyexchange" Mar 24 19:40:28 katarynka go-librespot[7260]: time="2026-03-24T19:40:28+01:00" level=debug msg="completed challenge" Mar 24 19:40:28 katarynka go-librespot[7260]: time="2026-03-24T19:40:28+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 24 19:40:28 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 24 19:40:28 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 24 19:40:31 katarynka volumio[7267]: info: ------------------------------------------- Mar 24 19:40:31 katarynka volumio[7267]: info: ----- Volumio3 ---- Mar 24 19:40:31 katarynka volumio[7267]: info: ------------------------------------------- Mar 24 19:40:31 katarynka volumio[7267]: info: ----- System startup ---- Mar 24 19:40:31 katarynka volumio[7267]: info: ------------------------------------------- Mar 24 19:40:31 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Mar 24 19:40:31 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 24 19:40:31 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 24 19:40:31 katarynka go-librespot[7290]: go-librespot daemon starting... Mar 24 19:40:31 katarynka go-librespot[7291]: time="2026-03-24T19:40:31+01:00" level=info msg="running go-librespot 0.4.0" Mar 24 19:40:31 katarynka go-librespot[7291]: time="2026-03-24T19:40:31+01:00" level=debug msg="app state loaded" Mar 24 19:40:31 katarynka go-librespot[7291]: time="2026-03-24T19:40:31+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 24 19:40:31 katarynka go-librespot[7291]: time="2026-03-24T19:40: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 24 19:40:31 katarynka go-librespot[7291]: time="2026-03-24T19:40: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 24 19:40:31 katarynka go-librespot[7291]: time="2026-03-24T19:40: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 24 19:40:31 katarynka go-librespot[7291]: time="2026-03-24T19:40:31+01:00" level=info msg="zeroconf server listening on port 43505" Mar 24 19:40:31 katarynka go-librespot[7291]: time="2026-03-24T19:40:31+01:00" level=debug msg="obtained new client token: AADfkfF4y0/hnaZD5rnsSNc79SjI7iAJeycXqGVgAE5COgNkXxvmv7eWOc7opd3dATE8V61MEJmD7HftQJ0Ng28dv2R5HnmdL3QooU2Olr3qoSX6MuVKhQzgR8s41BBTYMrMWt5260BYYnySp3T3xhZLMsCwSKPup9ZzkKDtN4XBa8VOcberG7OgLaLQLxPacnond2+f9hhXHgWtiuhfdBdRXDpBj0EUYkWl/l1HJ6tuMYwF8JwdQYdo8vo=" Mar 24 19:40:31 katarynka go-librespot[7291]: time="2026-03-24T19:40:31+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 24 19:40:32 katarynka volumio-remote-updater[622]: [2026-03-24 19:40:32] [connect] Successful connection Mar 24 19:40:32 katarynka go-librespot[7291]: time="2026-03-24T19:40:32+01:00" level=debug msg="completed keyexchange" Mar 24 19:40:32 katarynka go-librespot[7291]: time="2026-03-24T19:40:32+01:00" level=debug msg="completed challenge" Mar 24 19:40:32 katarynka go-librespot[7291]: time="2026-03-24T19:40:32+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 24 19:40:32 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 24 19:40:32 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 24 19:40:32 katarynka volumio[7267]: info: MYVOLUMIO Environment detected Mar 24 19:40:32 katarynka volumio[7267]: info: Plugin folders cleanup Mar 24 19:40:32 katarynka volumio[7267]: info: Scanning into folder /volumio/app/plugins/ Mar 24 19:40:32 katarynka volumio[7267]: info: Scanning category audio_interface Mar 24 19:40:32 katarynka volumio[7267]: info: Scanning category miscellanea Mar 24 19:40:32 katarynka volumio[7267]: info: Scanning category music_service Mar 24 19:40:32 katarynka volumio[7267]: info: Scanning category plugins.json Mar 24 19:40:32 katarynka volumio[7267]: info: Scanning category system_controller Mar 24 19:40:32 katarynka volumio[7267]: info: Scanning category user_interface Mar 24 19:40:32 katarynka volumio[7267]: info: Scanning into folder /data/plugins/ Mar 24 19:40:32 katarynka volumio[7267]: info: Scanning category music_service Mar 24 19:40:32 katarynka volumio[7267]: info: Plugin folders cleanup completed Mar 24 19:40:32 katarynka volumio[7267]: info: ------------------------------------------- Mar 24 19:40:32 katarynka volumio[7267]: info: ----- Core plugins startup ---- Mar 24 19:40:32 katarynka volumio[7267]: info: ------------------------------------------- Mar 24 19:40:32 katarynka volumio[7267]: info: Loading plugins from folder /volumio/app/plugins/ Mar 24 19:40:32 katarynka volumio[7267]: info: Adding plugin upnp to MyMusic Plugins Mar 24 19:40:32 katarynka volumio[7267]: info: Adding plugin airplay_emulation to MyMusic Plugins Mar 24 19:40:32 katarynka volumio[7267]: info: Adding plugin upnp_browser to MyMusic Plugins Mar 24 19:40:32 katarynka volumio[7267]: info: Loading plugins from folder /data/plugins/ Mar 24 19:40:32 katarynka volumio[7267]: info: Loading plugin "system"... Mar 24 19:40:32 katarynka volumio[7267]: info: Loading plugin "appearance"... Mar 24 19:40:34 katarynka volumio[7267]: info: Loading plugin "network"... Mar 24 19:40:34 katarynka volumio[7267]: info: Refreshing Cached IP Addresses Mar 24 19:40:34 katarynka sudo[7307]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 24 19:40:34 katarynka sudo[7307]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 19:40:35 katarynka sudo[7309]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 24 19:40:35 katarynka sudo[7309]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 19:40:35 katarynka volumio[7267]: info: Loading plugin "services"... Mar 24 19:40:35 katarynka sudo[7309]: pam_unix(sudo:session): session closed for user root Mar 24 19:40:35 katarynka sudo[7307]: pam_unix(sudo:session): session closed for user root Mar 24 19:40:35 katarynka volumio[7267]: info: Loading plugin "alsa_controller"... Mar 24 19:40:35 katarynka sudo[7317]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Mar 24 19:40:35 katarynka sudo[7317]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 19:40:35 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Mar 24 19:40:35 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 24 19:40:35 katarynka volumio[7267]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 24 19:40:35 katarynka volumio[7267]: info: Loading plugin "wizard"... Mar 24 19:40:35 katarynka volumio[7267]: info: Loading plugin "networkfs"... Mar 24 19:40:35 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 24 19:40:35 katarynka go-librespot[7342]: go-librespot daemon starting... Mar 24 19:40:35 katarynka volumio[7267]: info: Starting Udev Watcher for removable devices Mar 24 19:40:35 katarynka go-librespot[7344]: time="2026-03-24T19:40:35+01:00" level=info msg="running go-librespot 0.4.0" Mar 24 19:40:35 katarynka go-librespot[7344]: time="2026-03-24T19:40:35+01:00" level=debug msg="app state loaded" Mar 24 19:40:35 katarynka go-librespot[7344]: time="2026-03-24T19:40:35+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 24 19:40:35 katarynka volumio[7267]: info: Ignoring mount for partition: boot Mar 24 19:40:35 katarynka volumio[7267]: info: Ignoring mount for partition: volumio Mar 24 19:40:35 katarynka volumio[7267]: info: Ignoring mount for partition: volumio_data Mar 24 19:40:35 katarynka volumio[7267]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 24 19:40:35 katarynka volumio[7267]: info: Loading plugin "volumio_command_line_client"... Mar 24 19:40:35 katarynka volumio[7267]: info: Loading plugin "upnp"... Mar 24 19:40:35 katarynka volumio[7267]: info: [1774377635390] Starting Upmpd Daemon Mar 24 19:40:35 katarynka volumio[7267]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 24 19:40:35 katarynka volumio[7267]: info: Loading plugin "my_music"... Mar 24 19:40:35 katarynka volumio[7267]: info: Loading plugin "mpd"... Mar 24 19:40:35 katarynka go-librespot[7344]: time="2026-03-24T19:40: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-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 24 19:40:35 katarynka go-librespot[7344]: time="2026-03-24T19:40:35+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 24 19:40:35 katarynka go-librespot[7344]: time="2026-03-24T19:40:35+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 24 19:40:35 katarynka sudo[7317]: pam_unix(sudo:session): session closed for user root Mar 24 19:40:35 katarynka go-librespot[7344]: time="2026-03-24T19:40:35+01:00" level=info msg="zeroconf server listening on port 37529" Mar 24 19:40:36 katarynka go-librespot[7344]: time="2026-03-24T19:40:36+01:00" level=debug msg="obtained new client token: AAAFwksaGRi35mwEf/S4NcOVs1sF3y9ywOrMGNSUC7xc+X+HWiiPHcHJTT0CsF1FnX4XkNeBR1NF9KI78FLFBCKtFDXb9WvP2VCCmHnje0/+UKYu5wRD2wYb0H/IsGmFtDBR9HgQB+AFmDd/MVeUTqeA6yhn67xX6vQwNDEiY5NbPHodn4Vz2fu06WVA0HzdaABZtMBRpQ4Nm3VBjiOqgd+/wehfQAUC4WoeSKCWSFlCyzwpnjqZBuk/" Mar 24 19:40:36 katarynka go-librespot[7344]: time="2026-03-24T19:40:36+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 24 19:40:36 katarynka volumio[7267]: info: Loading plugin "upnp_browser"... Mar 24 19:40:36 katarynka go-librespot[7344]: time="2026-03-24T19:40:36+01:00" level=debug msg="completed keyexchange" Mar 24 19:40:36 katarynka go-librespot[7344]: time="2026-03-24T19:40:36+01:00" level=debug msg="completed challenge" Mar 24 19:40:36 katarynka go-librespot[7344]: time="2026-03-24T19:40: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 24 19:40:36 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 24 19:40:36 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 24 19:40:39 katarynka volumio[7267]: info: Starting UPNP Browser Mar 24 19:40:39 katarynka volumio[7267]: info: Loading plugin "alarm-clock"... Mar 24 19:40:39 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Mar 24 19:40:39 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 24 19:40:39 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 24 19:40:39 katarynka go-librespot[7352]: go-librespot daemon starting... Mar 24 19:40:39 katarynka volumio[7267]: info: Loading plugin "airplay_emulation"... Mar 24 19:40:39 katarynka go-librespot[7353]: time="2026-03-24T19:40:39+01:00" level=info msg="running go-librespot 0.4.0" Mar 24 19:40:39 katarynka go-librespot[7353]: time="2026-03-24T19:40:39+01:00" level=debug msg="app state loaded" Mar 24 19:40:39 katarynka go-librespot[7353]: time="2026-03-24T19:40:39+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 24 19:40:39 katarynka volumio[7267]: info: Starting Shairport Sync Mar 24 19:40:39 katarynka volumio[7267]: info: Loading plugin "last_100"... Mar 24 19:40:39 katarynka volumio[7267]: info: Loading plugin "webradio"... Mar 24 19:40:39 katarynka volumio[7267]: info: Loading plugin "i2s_dacs"... Mar 24 19:40:39 katarynka volumio[7267]: info: Loading plugin "volumiodiscovery"... Mar 24 19:40:39 katarynka volumio[7267]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Mar 24 19:40:39 katarynka volumio[7267]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 24 19:40:39 katarynka volumio[7267]: *** WARNING *** For more information see Mar 24 19:40:39 katarynka volumio[7267]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Mar 24 19:40:39 katarynka volumio[7267]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 24 19:40:39 katarynka volumio[7267]: *** WARNING *** For more information see Mar 24 19:40:39 katarynka node[7267]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Mar 24 19:40:39 katarynka node[7267]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 24 19:40:39 katarynka node[7267]: *** WARNING *** For more information see Mar 24 19:40:39 katarynka node[7267]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Mar 24 19:40:39 katarynka node[7267]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 24 19:40:39 katarynka node[7267]: *** WARNING *** For more information see Mar 24 19:40:39 katarynka volumio[7267]: info: Applying required configuration parameters for plugin volumiodiscovery Mar 24 19:40:39 katarynka volumio[7267]: info: Discovery: Started advertising with name: katarynka Mar 24 19:40:40 katarynka volumio[7267]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 24 19:40:40 katarynka volumio[7267]: info: Loading plugin "spop"... Mar 24 19:40:40 katarynka go-librespot[7353]: time="2026-03-24T19:40: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-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 24 19:40:40 katarynka go-librespot[7353]: time="2026-03-24T19:40:40+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 24 19:40:40 katarynka go-librespot[7353]: time="2026-03-24T19:40:40+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 24 19:40:40 katarynka go-librespot[7353]: time="2026-03-24T19:40:40+01:00" level=info msg="zeroconf server listening on port 45705" Mar 24 19:40:40 katarynka go-librespot[7353]: time="2026-03-24T19:40:40+01:00" level=debug msg="obtained new client token: AADNeE3beJXu7V5Mrp+fnR/Ud6DxP6hf8zHwUIeUfXcuglfC6QfbO4CMzNzH2ygyLpmyEs6Cbd2oK0ZGSUea5v+SAXLxnRtCWVZzDSaaIlSTZEqZSwd6eKIrlWV4yqz8Elt1zkzbTRNrGkYg7CPy5shrrDxTgLBEQ6puMbMBcVXvF/QXSrJZ2tlk5vwBNhgW85dwYdeqcxA4RCRFWaxbVatv6T0C53/fFyLEA1E2+ZQOYlEf0i1yDRkw" Mar 24 19:40:40 katarynka go-librespot[7353]: time="2026-03-24T19:40:40+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 24 19:40:40 katarynka go-librespot[7353]: time="2026-03-24T19:40:40+01:00" level=debug msg="completed keyexchange" Mar 24 19:40:40 katarynka go-librespot[7353]: time="2026-03-24T19:40:40+01:00" level=debug msg="completed challenge" Mar 24 19:40:40 katarynka go-librespot[7353]: time="2026-03-24T19:40: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 24 19:40:40 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 24 19:40:40 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 24 19:40:42 katarynka volumio[7267]: info: Loading plugin "outputs"... Mar 24 19:40:42 katarynka volumio[7267]: info: Loading plugin "albumart"... Mar 24 19:40:42 katarynka volumio[7267]: info: Plugin example_plugin is not enabled Mar 24 19:40:42 katarynka volumio[7267]: info: Loading plugin "inputs"... Mar 24 19:40:42 katarynka volumio[7267]: info: Loading plugin "updater_comm"... Mar 24 19:40:42 katarynka volumio[7267]: info: Plugin mpdemulation is not enabled Mar 24 19:40:42 katarynka volumio[7267]: info: Loading plugin "rest_api"... Mar 24 19:40:42 katarynka volumio[7267]: info: Loading plugin "websocket"... Mar 24 19:40:42 katarynka volumio[7267]: info: Starting Socket.io Server version 1.7.4 Mar 24 19:40:42 katarynka volumio[7267]: info: Loading i18n strings for locale pl Mar 24 19:40:42 katarynka volumio[7267]: Updating browse sources language Mar 24 19:40:42 katarynka volumio[7267]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 24 19:40:42 katarynka volumio[7267]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 24 19:40:42 katarynka volumio[7267]: info: CoreCommandRouter::initPlayerControls Mar 24 19:40:42 katarynka volumio[7267]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 19:40:42 katarynka volumio[7267]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 19:40:42 katarynka volumio[7267]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 19:40:42 katarynka volumio[7267]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 19:40:42 katarynka volumio[7267]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 19:40:42 katarynka volumio[7267]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 19:40:42 katarynka volumio[7267]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 19:40:42 katarynka volumio[7267]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 19:40:42 katarynka volumio[7267]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 24 19:40:42 katarynka volumio[7267]: Express server listening on port 3000 Mar 24 19:40:42 katarynka volumio[7267]: [Metrics] WebUI: 12s 716.46ms Mar 24 19:40:42 katarynka volumio[7267]: info: CoreStateMachine::resetVolumioState Mar 24 19:40:42 katarynka volumio[7267]: info: CoreStateMachine::getcurrentVolume Mar 24 19:40:42 katarynka volumio[7267]: info: CoreCommandRouter::volumioRetrievevolume Mar 24 19:40:42 katarynka volumio[7267]: info: Cannot read play queue from file Mar 24 19:40:42 katarynka volumio[7267]: info: Volumio Network Manager: Network status updated: 2 Mar 24 19:40:43 katarynka volumio[7362]: Forking 3 albumart workers Mar 24 19:40:43 katarynka volumio[7267]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 24 19:40:43 katarynka volumio[7267]: info: Setting Device type: Raspberry PI Mar 24 19:40:43 katarynka volumio[7267]: info: CoreStateMachine::setRepeat null single undefined Mar 24 19:40:43 katarynka volumio[7267]: info: CoreStateMachine::pushState Mar 24 19:40:43 katarynka volumio[7267]: info: CorePlayQueue::getTrack 0 Mar 24 19:40:43 katarynka volumio[7267]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 24 19:40:43 katarynka volumio[7267]: info: CoreCommandRouter::volumioPushState Mar 24 19:40:43 katarynka volumio[7267]: info: CoreStateMachine::setRandom null Mar 24 19:40:43 katarynka volumio[7267]: info: CoreStateMachine::pushState Mar 24 19:40:43 katarynka volumio[7267]: info: CorePlayQueue::getTrack 0 Mar 24 19:40:43 katarynka volumio[7267]: info: CoreCommandRouter::volumioPushState Mar 24 19:40:43 katarynka volumio[7267]: info: Completed loading Core Plugins Mar 24 19:40:43 katarynka volumio[7267]: info: Preparing to generate the ALSA configuration file Mar 24 19:40:43 katarynka volumio[7267]: info: VolumeController:: Volume=96 Mute =false Mar 24 19:40:43 katarynka volumio[7267]: info: CoreStateMachine::pushState Mar 24 19:40:43 katarynka volumio[7267]: info: CorePlayQueue::getTrack 0 Mar 24 19:40:43 katarynka volumio[7267]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 24 19:40:43 katarynka volumio[7267]: info: CoreCommandRouter::volumioPushState Mar 24 19:40:43 katarynka volumio[7267]: info: CoreStateMachine::updateTrackBlock Mar 24 19:40:43 katarynka volumio[7267]: info: CorePlayQueue::getTrackBlock Mar 24 19:40:43 katarynka volumio[7267]: info: CoreCommandRouter::volumioRetrievevolume Mar 24 19:40:43 katarynka volumio[7267]: info: Asound.conf file unchanged, so no further update is needed Mar 24 19:40:43 katarynka volumio[7267]: info: Output device has changed, restarting MPD Mar 24 19:40:43 katarynka volumio[7267]: info: Output device has changed, restarting Shairport Sync Mar 24 19:40:43 katarynka volumio[7267]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 19:40:43 katarynka volumio[7267]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 24 19:40:43 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Mar 24 19:40:43 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 24 19:40:43 katarynka volumio[7267]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 24 19:40:43 katarynka volumio[7267]: info: ___________ START PLUGINS ___________ Mar 24 19:40:43 katarynka sudo[7417]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 24 19:40:43 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 24 19:40:43 katarynka sudo[7417]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 19:40:43 katarynka go-librespot[7424]: go-librespot daemon starting... Mar 24 19:40:43 katarynka volumio[7267]: info: ControllerMpd::onStart: Initializing MPD Mar 24 19:40:43 katarynka volumio[7267]: info: Creating MPD Configuration file Mar 24 19:40:43 katarynka sudo[7417]: pam_unix(sudo:session): session closed for user root Mar 24 19:40:43 katarynka volumio[7267]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 24 19:40:43 katarynka volumio[7267]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 24 19:40:43 katarynka volumio[7267]: info: [1774377643797] CoreMusicLibrary::Adding element Serwery Mediów Mar 24 19:40:43 katarynka sudo[7419]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 24 19:40:43 katarynka sudo[7419]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 19:40:43 katarynka volumio[7267]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 24 19:40:43 katarynka go-librespot[7425]: time="2026-03-24T19:40:43+01:00" level=info msg="running go-librespot 0.4.0" Mar 24 19:40:43 katarynka go-librespot[7425]: time="2026-03-24T19:40:43+01:00" level=debug msg="app state loaded" Mar 24 19:40:43 katarynka go-librespot[7425]: time="2026-03-24T19:40:43+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 24 19:40:43 katarynka volumio[7267]: info: UPNP Browser: Client initialized successfully Mar 24 19:40:43 katarynka sudo[7433]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 24 19:40:43 katarynka sudo[7433]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 19:40:43 katarynka sudo[7434]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 24 19:40:43 katarynka sudo[7434]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 19:40:43 katarynka sudo[7433]: pam_unix(sudo:session): session closed for user root Mar 24 19:40:43 katarynka volumio[7267]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 19:40:43 katarynka volumio[7267]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 24 19:40:43 katarynka systemd[1]: Stopping mpd.service - Music Player Daemon... Mar 24 19:40:43 katarynka volumio[7267]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 24 19:40:43 katarynka volumio[7267]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 19:40:43 katarynka volumio[7267]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 24 19:40:44 katarynka systemd[1]: mpd.service: Deactivated successfully. Mar 24 19:40:44 katarynka systemd[1]: Stopped mpd.service - Music Player Daemon. Mar 24 19:40:44 katarynka systemd[1]: mpd.service: Consumed 7.771s CPU time. Mar 24 19:40:44 katarynka systemd[1]: mpd.socket: Deactivated successfully. Mar 24 19:40:44 katarynka systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Mar 24 19:40:44 katarynka systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Mar 24 19:40:44 katarynka volumio[7267]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 24 19:40:44 katarynka volumio[7267]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 24 19:40:44 katarynka volumio[7267]: info: [1774377644154] CoreMusicLibrary::Adding element Last_100 Mar 24 19:40:44 katarynka volumio[7267]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 24 19:40:44 katarynka volumio[7267]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 24 19:40:44 katarynka volumio[7267]: info: [1774377644180] CoreMusicLibrary::Adding element Webradio Mar 24 19:40:44 katarynka volumio[7267]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 24 19:40:44 katarynka systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Mar 24 19:40:44 katarynka systemd[1]: Starting mpd.service - Music Player Daemon... Mar 24 19:40:44 katarynka volumio[7267]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 24 19:40:44 katarynka volumio[7267]: info: Initializing BBC Radios Mar 24 19:40:44 katarynka volumio[7267]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 24 19:40:44 katarynka volumio[7267]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 24 19:40:44 katarynka volumio-remote-updater[622]: [2026-03-24 19:40:44] [connect] Successful connection Mar 24 19:40:44 katarynka volumio[7267]: info: Creating Spotify config file Mar 24 19:40:44 katarynka volumio[7267]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 19:40:44 katarynka go-librespot[7425]: time="2026-03-24T19:40: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-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Mar 24 19:40:44 katarynka go-librespot[7425]: time="2026-03-24T19:40:44+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 24 19:40:44 katarynka go-librespot[7425]: time="2026-03-24T19:40:44+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 24 19:40:44 katarynka go-librespot[7425]: time="2026-03-24T19:40:44+01:00" level=info msg="zeroconf server listening on port 34813" Mar 24 19:40:44 katarynka go-librespot[7425]: time="2026-03-24T19:40:44+01:00" level=debug msg="obtained new client token: AACd/NKYbXE6oL502DKy+qbg+NbUPe4ckZrJJlHKDvMiE6WCqUedI/dSQRPl82KkAIUCrDxqlyGKOOm0aFMQSB+CkcK825z9LBOCEu4VxqS2BANfG/GKHB+kM1MXGr1RCzJW27D4OWUTFV+uYpK42kHLBGZCFTP0k+4WjJN11lzoJP0vGUBeWimM3dO192nNxoMkgONxB6PmkpajaM98tZ1yrotp04b00B9+QQ8FQN4dLI7LVAxgLRFWoME=" Mar 24 19:40:44 katarynka sudo[7448]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Mar 24 19:40:44 katarynka sudo[7448]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Mar 24 19:40:44 katarynka sudo[7448]: pam_unix(sudo:session): session closed for user root Mar 24 19:40:44 katarynka go-librespot[7425]: time="2026-03-24T19:40:44+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 24 19:40:44 katarynka go-librespot[7425]: time="2026-03-24T19:40:44+01:00" level=debug msg="completed keyexchange" Mar 24 19:40:44 katarynka go-librespot[7425]: time="2026-03-24T19:40:44+01:00" level=debug msg="completed challenge" Mar 24 19:40:45 katarynka go-librespot[7425]: time="2026-03-24T19:40:45+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 24 19:40:45 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 24 19:40:45 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 24 19:40:45 katarynka volumio[7267]: info: Volumio Calling Home Mar 24 19:40:46 katarynka sudo[7483]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 24 19:40:46 katarynka sudo[7483]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 19:40:46 katarynka sudo[7483]: pam_unix(sudo:session): session closed for user root Mar 24 19:40:46 katarynka volumio[7267]: info: Discovery: adding 4d616d77-6a8c-4da2-85a4-840d70f98e51 Mar 24 19:40:46 katarynka volumio[7267]: info: Discovery: Found device katarynka Mar 24 19:40:46 katarynka volumio[7267]: info: CoreCommandRouter::volumioGetState Mar 24 19:40:46 katarynka volumio[7267]: info: CorePlayQueue::getTrack 0 Mar 24 19:40:46 katarynka sudo[7485]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 24 19:40:46 katarynka sudo[7485]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 19:40:46 katarynka volumio[7267]: info: MPD Permissions set Mar 24 19:40:46 katarynka volumio[7267]: info: MPD Permissions set Mar 24 19:40:46 katarynka volumio[7267]: info: VolumeController:: Volume=96 Mute =false Mar 24 19:40:46 katarynka volumio[7267]: info: CoreStateMachine::pushState Mar 24 19:40:46 katarynka volumio[7267]: info: CorePlayQueue::getTrack 0 Mar 24 19:40:46 katarynka volumio[7267]: info: CoreCommandRouter::volumioPushState Mar 24 19:40:46 katarynka sudo[7485]: pam_unix(sudo:session): session closed for user root Mar 24 19:40:46 katarynka volumio-remote-updater[622]: [2026-03-24 19:40:46] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1774377644 101 Mar 24 19:40:46 katarynka volumio[7267]: 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 24 19:40:46 katarynka volumio[7267]: info: Volumio called home Mar 24 19:40:46 katarynka volumio[7267]: info: Spotify config file written Mar 24 19:40:46 katarynka volumio[7267]: info: Discovery: this is already registered, 4d616d77-6a8c-4da2-85a4-840d70f98e51 Mar 24 19:40:46 katarynka volumio[7267]: info: Discovery: Found device katarynka Mar 24 19:40:46 katarynka volumio[7267]: info: CoreCommandRouter::volumioGetState Mar 24 19:40:46 katarynka volumio[7267]: info: CorePlayQueue::getTrack 0 Mar 24 19:40:46 katarynka sudo[7489]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Mar 24 19:40:46 katarynka sudo[7489]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 19:40:46 katarynka volumio[7267]: 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 24 19:40:46 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 24 19:40:46 katarynka volumio[7267]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 19:40:46 katarynka volumio[7267]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 19:40:46 katarynka volumio[7267]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 19:40:46 katarynka volumio[7267]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 19:40:46 katarynka volumio[7267]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 19:40:47 katarynka volumio[7267]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 19:40:47 katarynka volumio[7267]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 19:40:47 katarynka volumio[7267]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 19:40:47 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 24 19:40:47 katarynka go-librespot[7491]: go-librespot daemon starting... Mar 24 19:40:47 katarynka volumio[7267]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 24 19:40:47 katarynka volumio[7267]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 19:40:47 katarynka sudo[7489]: pam_unix(sudo:session): session closed for user root Mar 24 19:40:47 katarynka volumio[7267]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 19:40:47 katarynka volumio[7267]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 19:40:47 katarynka volumio[7267]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 19:40:47 katarynka volumio[7267]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 19:40:47 katarynka volumio[7267]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 19:40:47 katarynka volumio[7267]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 19:40:47 katarynka volumio[7267]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 19:40:47 katarynka volumio[7267]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 19:40:47 katarynka go-librespot[7497]: time="2026-03-24T19:40:47+01:00" level=info msg="running go-librespot 0.4.0" Mar 24 19:40:47 katarynka go-librespot[7497]: time="2026-03-24T19:40:47+01:00" level=debug msg="app state loaded" Mar 24 19:40:47 katarynka go-librespot[7497]: time="2026-03-24T19:40:47+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 24 19:40:47 katarynka volumio[7379]: Starting albumart workers Mar 24 19:40:47 katarynka volumio[7267]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 24 19:40:47 katarynka volumio[7267]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 19:40:47 katarynka volumio[7267]: info: No need to fix Spotify hosts Mar 24 19:40:47 katarynka go-librespot[7497]: time="2026-03-24T19:40:47+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 24 19:40:47 katarynka go-librespot[7497]: time="2026-03-24T19:40:47+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 24 19:40:47 katarynka go-librespot[7497]: time="2026-03-24T19:40:47+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 24 19:40:47 katarynka go-librespot[7497]: time="2026-03-24T19:40:47+01:00" level=info msg="zeroconf server listening on port 40501" Mar 24 19:40:47 katarynka go-librespot[7497]: time="2026-03-24T19:40:47+01:00" level=debug msg="obtained new client token: AACvfHwcMVKfMwrBvhwvaTQPo4+pc/OwW581iUtPr2pOGu0MTc2EUF0sWI9VJlxgVToFoVXpnNusoIt9dsHA8yRYbL5GraEncD/zIr6eCpuG1WZUuEXYhicX9iZ1aP080sYAO4JOMl+LgAX0DzKE7dBVIiBC23W2ADkVjSP9V9ZcSJXGyC1R9s3RsWdh9PhyO/w9MFk/AQDxhF8Yxqwe1VpuReYWHV0gq89P8NB75i+UjxVpfekIlZ88UP8=" Mar 24 19:40:47 katarynka volumio[7381]: Starting albumart workers Mar 24 19:40:48 katarynka go-librespot[7497]: time="2026-03-24T19:40:48+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 24 19:40:48 katarynka volumio[7378]: Starting albumart workers Mar 24 19:40:48 katarynka go-librespot[7497]: time="2026-03-24T19:40:48+01:00" level=debug msg="connected to ap-gew4.spotify.com:443" Mar 24 19:40:48 katarynka go-librespot[7497]: time="2026-03-24T19:40:48+01:00" level=debug msg="completed keyexchange" Mar 24 19:40:48 katarynka go-librespot[7497]: time="2026-03-24T19:40:48+01:00" level=debug msg="completed challenge" Mar 24 19:40:48 katarynka go-librespot[7497]: time="2026-03-24T19:40:48+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 24 19:40:48 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 24 19:40:48 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 24 19:40:48 katarynka volumio[7267]: info: Starting Shairport Sync Mar 24 19:40:48 katarynka volumio[7267]: info: Starting Shairport Sync Mar 24 19:40:48 katarynka volumio[7267]: info: Starting Shairport Sync Mar 24 19:40:48 katarynka sudo[7510]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 24 19:40:48 katarynka sudo[7510]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 19:40:48 katarynka sudo[7512]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 24 19:40:48 katarynka sudo[7514]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 24 19:40:48 katarynka sudo[7514]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 19:40:48 katarynka sudo[7512]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 19:40:48 katarynka systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Mar 24 19:40:48 katarynka systemd[1]: shairport-sync.service: Deactivated successfully. Mar 24 19:40:48 katarynka systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 24 19:40:48 katarynka systemd[1]: shairport-sync.service: Consumed 2.316s CPU time. Mar 24 19:40:48 katarynka systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 24 19:40:48 katarynka sudo[7517]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Mar 24 19:40:48 katarynka sudo[7510]: pam_unix(sudo:session): session closed for user root Mar 24 19:40:48 katarynka sudo[7517]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 19:40:48 katarynka systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Mar 24 19:40:48 katarynka systemd[1]: shairport-sync.service: Deactivated successfully. Mar 24 19:40:48 katarynka systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 24 19:40:49 katarynka systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 24 19:40:49 katarynka sudo[7514]: pam_unix(sudo:session): session closed for user root Mar 24 19:40:49 katarynka volumio[7267]: info: Shairport-Sync Started Mar 24 19:40:49 katarynka volumio[7267]: Error adding Membership: Error: addMembership EINVAL Mar 24 19:40:49 katarynka sudo[7512]: pam_unix(sudo:session): session closed for user root Mar 24 19:40:49 katarynka sudo[7517]: pam_unix(sudo:session): session closed for user root Mar 24 19:40:49 katarynka volumio[7267]: info: An error occurred while refreshing Spotify Token Error: Bad Request Mar 24 19:40:49 katarynka volumio[7267]: info: CoreCommandRouter::volumioGetState Mar 24 19:40:49 katarynka volumio[7267]: info: CorePlayQueue::getTrack 0 Mar 24 19:40:49 katarynka volumio[7267]: info: Upmpdcli Daemon Started Mar 24 19:40:49 katarynka volumio[7267]: info: Shairport-Sync Started Mar 24 19:40:49 katarynka volumio[7267]: info: Shairport-Sync Started Mar 24 19:40:51 katarynka volumio[7267]: info: go-librespot daemon successfully initialized Mar 24 19:40:51 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Mar 24 19:40:51 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 24 19:40:51 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 24 19:40:51 katarynka go-librespot[7556]: go-librespot daemon starting... Mar 24 19:40:51 katarynka go-librespot[7557]: time="2026-03-24T19:40:51+01:00" level=info msg="running go-librespot 0.4.0" Mar 24 19:40:51 katarynka go-librespot[7557]: time="2026-03-24T19:40:51+01:00" level=debug msg="app state loaded" Mar 24 19:40:51 katarynka go-librespot[7557]: time="2026-03-24T19:40:51+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 24 19:40:51 katarynka go-librespot[7557]: time="2026-03-24T19:40:51+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 24 19:40:51 katarynka go-librespot[7557]: time="2026-03-24T19:40:51+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 24 19:40:51 katarynka go-librespot[7557]: time="2026-03-24T19:40:51+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 24 19:40:51 katarynka go-librespot[7557]: time="2026-03-24T19:40:51+01:00" level=info msg="zeroconf server listening on port 42269" Mar 24 19:40:52 katarynka go-librespot[7557]: time="2026-03-24T19:40:52+01:00" level=debug msg="obtained new client token: AADZ42z6+KA4HytQeXrTnkuY1nR28XrRNcT6wWaqhxjGm7D2Pr3BlIgQmfAVDdNx8TMKC/7bNVdc2P0AAAuLtcRRXjJ1QYu5k582n4hrvO+dFC3UxmEWtg5OYNUrQ1L4OC0GaleqWGAQ/xxYGMTuNatSU66c6qlT5iRXaclPxepyKWWa+G+pbQXaCThd/wgYbmCsv+meRVgMHpR/XynRnpKmw2YmieL0FnoLduBcGzCjdKsFf+V/I2Ck" Mar 24 19:40:52 katarynka go-librespot[7557]: time="2026-03-24T19:40:52+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 24 19:40:52 katarynka go-librespot[7557]: time="2026-03-24T19:40:52+01:00" level=debug msg="completed keyexchange" Mar 24 19:40:52 katarynka go-librespot[7557]: time="2026-03-24T19:40:52+01:00" level=debug msg="completed challenge" Mar 24 19:40:52 katarynka go-librespot[7557]: time="2026-03-24T19:40:52+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 24 19:40:52 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 24 19:40:52 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 24 19:40:52 katarynka mpd[7464]: 2026-03-24T19:40:52 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Mar 24 19:40:52 katarynka systemd[1]: Started mpd.service - Music Player Daemon. Mar 24 19:40:52 katarynka sudo[7419]: pam_unix(sudo:session): session closed for user root Mar 24 19:40:52 katarynka sudo[7434]: pam_unix(sudo:session): session closed for user root Mar 24 19:40:52 katarynka volumio[7267]: info: Completed starting Core Plugins Mar 24 19:40:52 katarynka volumio[7267]: info: ------------------------------------------- Mar 24 19:40:52 katarynka volumio[7267]: info: ----- MyVolumio plugins startup ---- Mar 24 19:40:52 katarynka volumio[7267]: info: ------------------------------------------- Mar 24 19:40:52 katarynka volumio[7267]: info: [MyVolumio PluginManager] Fetching plans data.... Mar 24 19:40:52 katarynka volumio[7267]: error: MPD error: The expression evaluated to a falsy value: Mar 24 19:40:52 katarynka volumio[7267]: assert.ok(self.idling) Mar 24 19:40:52 katarynka volumio[7267]: error: The expression evaluated to a falsy value: Mar 24 19:40:52 katarynka volumio[7267]: assert.ok(self.idling) Mar 24 19:40:52 katarynka volumio[7267]: info: MPD running with PID7464 Mar 24 19:40:52 katarynka volumio[7267]: ,establishing connection Mar 24 19:40:52 katarynka volumio[7267]: error: updateQueue error: null Mar 24 19:40:52 katarynka volumio[7267]: error: updateQueue error: null Mar 24 19:40:54 katarynka volumio[7267]: info: Initializing connection to go-librespot Websocket Mar 24 19:40:54 katarynka volumio[7267]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 24 19:40:55 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 11. Mar 24 19:40:55 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 24 19:40:55 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 24 19:40:55 katarynka go-librespot[7586]: go-librespot daemon starting... Mar 24 19:40:55 katarynka go-librespot[7587]: time="2026-03-24T19:40:55+01:00" level=info msg="running go-librespot 0.4.0" Mar 24 19:40:55 katarynka go-librespot[7587]: time="2026-03-24T19:40:55+01:00" level=debug msg="app state loaded" Mar 24 19:40:55 katarynka go-librespot[7587]: time="2026-03-24T19:40:55+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 24 19:40:55 katarynka sudo[7594]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Mar 24 19:40:55 katarynka sudo[7594]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 19:40:55 katarynka sudo[7596]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Mar 24 19:40:55 katarynka sudo[7596]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 19:40:55 katarynka systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Mar 24 19:40:55 katarynka systemd[1]: mpd_monitor.service: Deactivated successfully. Mar 24 19:40:55 katarynka systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Mar 24 19:40:55 katarynka systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Mar 24 19:40:55 katarynka sudo[7596]: pam_unix(sudo:session): session closed for user root Mar 24 19:40:55 katarynka mpd_monitor.sh[7599]: MPD Monitor Service: Starting MPD Monitor Service Mar 24 19:40:55 katarynka sudo[7594]: pam_unix(sudo:session): session closed for user root Mar 24 19:40:55 katarynka volumio[7267]: info: Successfully started MPD Monitor Mar 24 19:40:55 katarynka volumio[7267]: info: Successfully started MPD Monitor Mar 24 19:40:55 katarynka go-librespot[7587]: time="2026-03-24T19:40:55+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 24 19:40:55 katarynka go-librespot[7587]: time="2026-03-24T19:40:55+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 24 19:40:55 katarynka go-librespot[7587]: time="2026-03-24T19:40:55+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 24 19:40:56 katarynka go-librespot[7587]: time="2026-03-24T19:40:56+01:00" level=info msg="zeroconf server listening on port 38845" Mar 24 19:40:56 katarynka go-librespot[7587]: time="2026-03-24T19:40:56+01:00" level=debug msg="obtained new client token: AAAfg1JYe1zP6u09+pw4C41nF87JMKFVX3LVPV2HBKXmiZOKWOXKQLuMoSrHJjdbVcxFnA90SpiLy7oPyAz67Wy3/cc95jxv8FnmhDWIKxqWhkPAFINzYgvzR3zvrnpqR+xHPPYYYpgI24hmtgx3XrsQFSXQil9o7J3cX54+ZJ7OWNujx+uuSWHY/0jyl6dfNwDVCfCt5hQcRCFtR1X6rESxwpH3mfpTamTre0u7LAJPvMtCX72gLiMd" Mar 24 19:40:56 katarynka go-librespot[7587]: time="2026-03-24T19:40:56+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 24 19:40:56 katarynka go-librespot[7587]: time="2026-03-24T19:40:56+01:00" level=debug msg="completed keyexchange" Mar 24 19:40:56 katarynka go-librespot[7587]: time="2026-03-24T19:40:56+01:00" level=debug msg="completed challenge" Mar 24 19:40:56 katarynka go-librespot[7587]: time="2026-03-24T19:40:56+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 24 19:40:56 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 24 19:40:56 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 24 19:40:57 katarynka volumio[7267]: info: Initializing connection to go-librespot Websocket Mar 24 19:40:57 katarynka volumio[7267]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 24 19:40:57 katarynka volumio[7267]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Mar 24 19:40:59 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 12. Mar 24 19:40:59 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 24 19:40:59 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 24 19:40:59 katarynka go-librespot[7604]: go-librespot daemon starting... Mar 24 19:40:59 katarynka go-librespot[7605]: time="2026-03-24T19:40:59+01:00" level=info msg="running go-librespot 0.4.0" Mar 24 19:40:59 katarynka go-librespot[7605]: time="2026-03-24T19:40:59+01:00" level=debug msg="app state loaded" Mar 24 19:40:59 katarynka go-librespot[7605]: time="2026-03-24T19:40:59+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 24 19:40:59 katarynka go-librespot[7605]: time="2026-03-24T19:40:59+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 24 19:40:59 katarynka go-librespot[7605]: time="2026-03-24T19:40:59+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 24 19:40:59 katarynka go-librespot[7605]: time="2026-03-24T19:40:59+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 24 19:40:59 katarynka go-librespot[7605]: time="2026-03-24T19:40:59+01:00" level=info msg="zeroconf server listening on port 46881" Mar 24 19:41:00 katarynka go-librespot[7605]: time="2026-03-24T19:41:00+01:00" level=debug msg="obtained new client token: AACML/XwUfcCXayUahbqAEeDlg3M/RIRUQIEu+p0nr5FCofcv4goDcCeeqW9BF1fMeAcGdBB4bW/hF8jwGMyMu/Wlh+yb7FweUqYWSYrj/iRLJf0a5wmBx1I5mG9FhuUcKwqLap1hmOuQfDNjUqYnZK43Ta4p1Okp1yPi70WqP3y6qWpEo+cmiwWne5Zei3xqvyrLk/gstyxA+xxdQuCyEp96RDk4bPQ7r1/aGcbPDxtUfU9sB3VNnCf" Mar 24 19:41:00 katarynka go-librespot[7605]: time="2026-03-24T19:41:00+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 24 19:41:00 katarynka go-librespot[7605]: time="2026-03-24T19:41:00+01:00" level=debug msg="completed keyexchange" Mar 24 19:41:00 katarynka go-librespot[7605]: time="2026-03-24T19:41:00+01:00" level=debug msg="completed challenge" Mar 24 19:41:00 katarynka go-librespot[7605]: time="2026-03-24T19:41:00+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 24 19:41:00 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 24 19:41:00 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 24 19:41:00 katarynka volumio[7267]: info: Initializing connection to go-librespot Websocket Mar 24 19:41:00 katarynka volumio[7267]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 24 19:41:00 katarynka volumio[7267]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Mar 24 19:41:00 katarynka volumio[7267]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Mar 24 19:41:00 katarynka volumio[7267]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Mar 24 19:41:00 katarynka volumio[7267]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Mar 24 19:41:00 katarynka volumio[7267]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Mar 24 19:41:00 katarynka volumio[7267]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Mar 24 19:41:00 katarynka volumio[7267]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Mar 24 19:41:00 katarynka volumio[7267]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Mar 24 19:41:00 katarynka volumio[7267]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Mar 24 19:41:00 katarynka volumio[7267]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Mar 24 19:41:00 katarynka volumio[7267]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Mar 24 19:41:00 katarynka volumio[7267]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Mar 24 19:41:00 katarynka volumio[7267]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Mar 24 19:41:00 katarynka volumio[7267]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Mar 24 19:41:00 katarynka volumio[7267]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Mar 24 19:41:00 katarynka volumio[7267]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Mar 24 19:41:00 katarynka volumio[7267]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Mar 24 19:41:00 katarynka volumio[7267]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Mar 24 19:41:00 katarynka volumio[7267]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Mar 24 19:41:00 katarynka volumio[7267]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Mar 24 19:41:00 katarynka volumio[7267]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Mar 24 19:41:00 katarynka volumio[7267]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Mar 24 19:41:00 katarynka volumio[7267]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Mar 24 19:41:00 katarynka volumio[7267]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Mar 24 19:41:00 katarynka volumio[7267]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Mar 24 19:41:00 katarynka volumio[7267]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Mar 24 19:41:00 katarynka volumio[7267]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Mar 24 19:41:00 katarynka volumio[7267]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Mar 24 19:41:00 katarynka volumio[7267]: info: Adding plugin bluetooth to MyMusic Plugins Mar 24 19:41:00 katarynka volumio[7267]: info: Adding plugin multiroom to MyMusic Plugins Mar 24 19:41:00 katarynka volumio[7267]: info: Adding plugin metavolumio to MyMusic Plugins Mar 24 19:41:00 katarynka volumio[7267]: info: Adding plugin cd_controller to MyMusic Plugins Mar 24 19:41:00 katarynka volumio[7267]: info: Adding plugin qobuzconnect to MyMusic Plugins Mar 24 19:41:00 katarynka volumio[7267]: info: Adding plugin smart_inputs to MyMusic Plugins Mar 24 19:41:00 katarynka volumio[7267]: info: Adding plugin tidalconnect to MyMusic Plugins Mar 24 19:41:00 katarynka volumio[7267]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Mar 24 19:41:02 katarynka volumio[7267]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Mar 24 19:41:02 katarynka volumio[7267]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Mar 24 19:41:02 katarynka volumio[7267]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 24 19:41:02 katarynka volumio[7267]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 24 19:41:02 katarynka volumio[7267]: info: Starting MyVolumio Remote Streaming Endpoints Mar 24 19:41:03 katarynka volumio[7267]: info: MyVolumio login type: Token Mar 24 19:41:03 katarynka volumio[7267]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Mar 24 19:41:03 katarynka volumio[7267]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Mar 24 19:41:03 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 13. Mar 24 19:41:03 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 24 19:41:03 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 24 19:41:03 katarynka go-librespot[7612]: go-librespot daemon starting... Mar 24 19:41:03 katarynka go-librespot[7613]: time="2026-03-24T19:41:03+01:00" level=info msg="running go-librespot 0.4.0" Mar 24 19:41:03 katarynka go-librespot[7613]: time="2026-03-24T19:41:03+01:00" level=debug msg="app state loaded" Mar 24 19:41:03 katarynka go-librespot[7613]: time="2026-03-24T19:41:03+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 24 19:41:03 katarynka go-librespot[7613]: time="2026-03-24T19:41:03+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 24 19:41:03 katarynka go-librespot[7613]: time="2026-03-24T19:41:03+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 24 19:41:03 katarynka go-librespot[7613]: time="2026-03-24T19:41:03+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 24 19:41:04 katarynka go-librespot[7613]: time="2026-03-24T19:41:04+01:00" level=info msg="zeroconf server listening on port 33581" Mar 24 19:41:04 katarynka go-librespot[7613]: time="2026-03-24T19:41:04+01:00" level=debug msg="obtained new client token: AAB5aJuE07/LSqlaqszRgtRq1i2RchxRZzCwX6TJoYVlDfM3x+GKHLkCudVZ5Fpc0OkKm3ABKciu5h6koER9zKElrLlyYQkY/9IUnGb/5Gkc+a8uNfFG2+kyhsCO/lqRCnDfq9UNjxzrpy4ynLyMgZJJ83wPl7nV2WrG8J9nJN2vx+PKOSlKf+xF6Km5K+dl0mxzHFebGf28ENJArAV47sAPE3O1ksUjdeh9DVvypGEeHAxbktd++hqt" Mar 24 19:41:04 katarynka go-librespot[7613]: time="2026-03-24T19:41:04+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 24 19:41:04 katarynka go-librespot[7613]: time="2026-03-24T19:41:04+01:00" level=debug msg="completed keyexchange" Mar 24 19:41:04 katarynka go-librespot[7613]: time="2026-03-24T19:41:04+01:00" level=debug msg="completed challenge" Mar 24 19:41:04 katarynka go-librespot[7613]: time="2026-03-24T19:41:04+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 24 19:41:04 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 24 19:41:04 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 24 19:41:04 katarynka volumio[7267]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Mar 24 19:41:04 katarynka volumio[7267]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Mar 24 19:41:04 katarynka volumio[7267]: info: Streaming services startup Mar 24 19:41:04 katarynka volumio[7267]: info: Starting Streaming Daemon Mar 24 19:41:04 katarynka sudo[7621]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Mar 24 19:41:04 katarynka sudo[7621]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 19:41:04 katarynka volumio[7267]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Mar 24 19:41:04 katarynka sudo[7621]: pam_unix(sudo:session): session closed for user root Mar 24 19:41:04 katarynka volumio[7267]: info: Initializing connection to go-librespot Websocket Mar 24 19:41:05 katarynka volumio[7267]: error: Cannot start Volumio Streaming Daemon Mar 24 19:41:05 katarynka volumio[7267]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Mar 24 19:41:05 katarynka volumio[7267]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Mar 24 19:41:05 katarynka volumio[7267]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 24 19:41:05 katarynka volumio[7267]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Mar 24 19:41:06 katarynka volumio[7267]: info: MyVolumio token set successfully Mar 24 19:41:06 katarynka volumio[7267]: info: MYVOLUMIO: Adding device Mar 24 19:41:06 katarynka volumio[7267]: info: MYVOLUMIO: Evaluating Server Mar 24 19:41:06 katarynka volumio[7267]: info: MyVolumio status changed Mar 24 19:41:06 katarynka volumio[7267]: info: Streaming services startup Mar 24 19:41:06 katarynka volumio[7267]: info: Starting Streaming Daemon Mar 24 19:41:06 katarynka volumio[7267]: info: Removing browser output: myVolumio user plan is not superstar Mar 24 19:41:06 katarynka volumio[7267]: info: Removing audio output: Mar 24 19:41:06 katarynka volumio[7267]: info: Stoppping Tunnel 1 Mar 24 19:41:06 katarynka sudo[7663]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Mar 24 19:41:06 katarynka sudo[7663]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 19:41:06 katarynka sudo[7665]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Mar 24 19:41:06 katarynka sudo[7665]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 19:41:06 katarynka sudo[7663]: pam_unix(sudo:session): session closed for user root Mar 24 19:41:06 katarynka volumio[7267]: error: Cannot start Volumio Streaming Daemon Mar 24 19:41:06 katarynka volumio[7267]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Mar 24 19:41:06 katarynka volumio[7267]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Mar 24 19:41:07 katarynka systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Mar 24 19:41:07 katarynka systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Mar 24 19:41:07 katarynka systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Mar 24 19:41:07 katarynka systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Mar 24 19:41:07 katarynka systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Mar 24 19:41:07 katarynka systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Mar 24 19:41:07 katarynka sudo[7665]: pam_unix(sudo:session): session closed for user root Mar 24 19:41:07 katarynka volumio[7267]: info: Remote SSH Stopped Mar 24 19:41:07 katarynka volumio[7267]: info: Setting Geolocation for MyVolumio to eu11 Mar 24 19:41:07 katarynka volumio[7267]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 24 19:41:07 katarynka volumio[7267]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 24 19:41:07 katarynka volumio[7267]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 24 19:41:07 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 14. Mar 24 19:41:07 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 24 19:41:07 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 24 19:41:07 katarynka go-librespot[7668]: go-librespot daemon starting... Mar 24 19:41:07 katarynka volumio[7267]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Mar 24 19:41:07 katarynka go-librespot[7669]: time="2026-03-24T19:41:07+01:00" level=info msg="running go-librespot 0.4.0" Mar 24 19:41:07 katarynka go-librespot[7669]: time="2026-03-24T19:41:07+01:00" level=debug msg="app state loaded" Mar 24 19:41:07 katarynka go-librespot[7669]: time="2026-03-24T19:41:07+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 24 19:41:07 katarynka go-librespot[7669]: time="2026-03-24T19:41:07+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 24 19:41:07 katarynka go-librespot[7669]: time="2026-03-24T19:41:07+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 24 19:41:07 katarynka go-librespot[7669]: time="2026-03-24T19:41:07+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 24 19:41:07 katarynka go-librespot[7669]: time="2026-03-24T19:41:07+01:00" level=info msg="zeroconf server listening on port 36355" Mar 24 19:41:08 katarynka go-librespot[7669]: time="2026-03-24T19:41:08+01:00" level=debug msg="obtained new client token: AACmpIHIs4zJod58CS65nSKTaM6e+oMli6TdvDY4HIaUVf+SiTP0pudqiegJQGyAoWp6E94MO/GInHJF3MMEe7jhnzMTQPv9dWUg+iaMWn4kNVzjiHzEiIA3dWrAVaSxAZEW2y3c82JwQzO7qyJPj+0AUw6Zz/9VCejUV5i6dqOpcOK93Y+7Xh5EYGPNi70mFRRuCla0pTrDPTzn5PjsMUNt2RmrT8pDqVWIT8AZum9/zCy1u0gLkMNy" Mar 24 19:41:08 katarynka volumio[7267]: info: Initializing connection to go-librespot Websocket Mar 24 19:41:08 katarynka go-librespot[7669]: time="2026-03-24T19:41:08+01:00" level=debug msg="new websocket client" Mar 24 19:41:08 katarynka volumio[7267]: info: Connection to go-librespot Websocket established Mar 24 19:41:08 katarynka go-librespot[7669]: time="2026-03-24T19:41:08+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 24 19:41:08 katarynka go-librespot[7669]: time="2026-03-24T19:41:08+01:00" level=debug msg="completed keyexchange" Mar 24 19:41:08 katarynka go-librespot[7669]: time="2026-03-24T19:41:08+01:00" level=debug msg="completed challenge" Mar 24 19:41:08 katarynka volumio[7267]: info: Updating MyVolumio device info Mar 24 19:41:08 katarynka volumio[7267]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 24 19:41:08 katarynka volumio[7267]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 24 19:41:08 katarynka volumio[7267]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 24 19:41:08 katarynka go-librespot[7669]: time="2026-03-24T19:41:08+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 24 19:41:08 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 24 19:41:08 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 24 19:41:08 katarynka volumio[7267]: info: Connection to go-librespot Websocket closed Mar 24 19:41:08 katarynka volumio[7267]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Mar 24 19:41:11 katarynka volumio[7267]: info: Getting Spotify volume Mar 24 19:41:11 katarynka volumio[7267]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 24 19:41:11 katarynka volumio[7267]: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 24 19:41:11 katarynka volumio[7267]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Mar 24 19:41:11 katarynka volumio[7267]: errno: -111, Mar 24 19:41:11 katarynka volumio[7267]: code: 'ECONNREFUSED', Mar 24 19:41:11 katarynka volumio[7267]: syscall: 'connect', Mar 24 19:41:11 katarynka volumio[7267]: address: '127.0.0.1', Mar 24 19:41:11 katarynka volumio[7267]: port: 9879, Mar 24 19:41:11 katarynka volumio[7267]: response: undefined Mar 24 19:41:11 katarynka volumio[7267]: } Mar 24 19:41:11 katarynka volumio[7267]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 24 19:41:11 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 15. Mar 24 19:41:11 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 24 19:41:11 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 24 19:41:11 katarynka go-librespot[7689]: go-librespot daemon starting... Mar 24 19:41:11 katarynka go-librespot[7690]: time="2026-03-24T19:41:11+01:00" level=info msg="running go-librespot 0.4.0" Mar 24 19:41:11 katarynka go-librespot[7690]: time="2026-03-24T19:41:11+01:00" level=debug msg="app state loaded" Mar 24 19:41:11 katarynka go-librespot[7690]: time="2026-03-24T19:41:11+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 24 19:41:11 katarynka go-librespot[7690]: time="2026-03-24T19:41:11+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 24 19:41:11 katarynka go-librespot[7690]: time="2026-03-24T19:41:11+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 24 19:41:11 katarynka go-librespot[7690]: time="2026-03-24T19:41:11+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 24 19:41:11 katarynka go-librespot[7690]: time="2026-03-24T19:41:11+01:00" level=info msg="zeroconf server listening on port 40757" Mar 24 19:41:12 katarynka go-librespot[7690]: time="2026-03-24T19:41:12+01:00" level=debug msg="obtained new client token: AADPliQt65/R/cC3AYJukrpY6CFDnKer9Hob2kQvZcPe+Roe6XUWfEmbOIwDe04oN/Z1zIeuvnivq9yRyBUI8zkMBsVMQOm6bYq7bQbi0IIltJSjI2u1EwQjDCBLbM8qLexQb2+YN/l7q+5KmHLRxbdKUbcf0ZWQNpHQfS4h2meeGKRYg7xRS8GM1oCCKVVgswVOsOAj0CdXbPJFf1XgJ4DW9iHgwWr9ZLCEOzIdrMVg8CWmSLcBjmQd" Mar 24 19:41:12 katarynka go-librespot[7690]: time="2026-03-24T19:41:12+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 24 19:41:12 katarynka go-librespot[7690]: time="2026-03-24T19:41:12+01:00" level=debug msg="completed keyexchange" Mar 24 19:41:12 katarynka go-librespot[7690]: time="2026-03-24T19:41:12+01:00" level=debug msg="completed challenge" Mar 24 19:41:12 katarynka go-librespot[7690]: time="2026-03-24T19:41:12+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 24 19:41:12 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 24 19:41:12 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 24 19:41:12 katarynka sudo[7699]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-03-24 19:40' Mar 24 19:41:12 katarynka sudo[7699]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 19:41:13 katarynka sudo[7699]: pam_unix(sudo:session): session closed for user root Mar 24 19:41:13 katarynka volumio-remote-updater[622]: [2026-03-24 19:41:13] [error] handle_read_frame error: asio.system:104 (Connection reset by peer) Mar 24 19:41:13 katarynka volumio-remote-updater[622]: [2026-03-24 19:41:13] [disconnect] Disconnect close local:[1006,Connection reset by peer] remote:[1006] Mar 24 19:41:13 katarynka systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Mar 24 19:41:13 katarynka systemd[1]: volumio.service: Failed with result 'exit-code'. Mar 24 19:41:13 katarynka systemd[1]: volumio.service: Consumed 50.906s CPU time. Mar 24 19:41:13 katarynka systemd[1]: Started dynamicswap.service - dynamicswap service. Mar 24 19:41:13 katarynka systemd[1]: dynamicswap.service: Deactivated successfully. Mar 24 19:41:13 katarynka systemd[1]: volumio.service: Scheduled restart job, restart counter is at 25312. Mar 24 19:41:13 katarynka systemd[1]: Started dynamicswap.service - dynamicswap service. Mar 24 19:41:13 katarynka systemd[1]: Stopped volumio.service - Volumio Backend Module. Mar 24 19:41:13 katarynka systemd[1]: volumio.service: Consumed 50.906s CPU time. Mar 24 19:41:13 katarynka systemd[1]: Started volumio.service - Volumio Backend Module. Mar 24 19:41:13 katarynka systemd[1]: dynamicswap.service: Deactivated successfully. Mar 24 19:41:15 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 16. Mar 24 19:41:15 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 24 19:41:15 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 24 19:41:15 katarynka go-librespot[7727]: go-librespot daemon starting... Mar 24 19:41:15 katarynka go-librespot[7728]: time="2026-03-24T19:41:15+01:00" level=info msg="running go-librespot 0.4.0" Mar 24 19:41:15 katarynka go-librespot[7728]: time="2026-03-24T19:41:15+01:00" level=debug msg="app state loaded" Mar 24 19:41:15 katarynka go-librespot[7728]: time="2026-03-24T19:41:15+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 24 19:41:16 katarynka go-librespot[7728]: time="2026-03-24T19:41:16+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Mar 24 19:41:16 katarynka go-librespot[7728]: time="2026-03-24T19:41:16+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 24 19:41:16 katarynka go-librespot[7728]: time="2026-03-24T19:41:16+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 24 19:41:16 katarynka go-librespot[7728]: time="2026-03-24T19:41:16+01:00" level=info msg="zeroconf server listening on port 36107" Mar 24 19:41:16 katarynka go-librespot[7728]: time="2026-03-24T19:41:16+01:00" level=debug msg="obtained new client token: AACtsFxI12rAZHsUSdJIHdJ+hUYMlSH6v2Q4PidqBIfTo7apcGPlndi3RiqHPAsTSgnEVL12BNKD999XAWrz9RbPR/QqWIKQdKf9eelHbi0oogo0TLozrfj5YDgZPfI84Ab7HmEHEwH5FZxaOVXhdxTmew737/Vg2kQ4ySHV+pNGxp3tGxbDqP3RGCMrm2jKGoCcuGBugCrbfJ7jjo1+vIB9Mk8SRbYFZBJROXaOkUjdTxlBxqqt7mPN" Mar 24 19:41:16 katarynka go-librespot[7728]: time="2026-03-24T19:41:16+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 24 19:41:16 katarynka go-librespot[7728]: time="2026-03-24T19:41:16+01:00" level=debug msg="completed keyexchange" Mar 24 19:41:16 katarynka go-librespot[7728]: time="2026-03-24T19:41:16+01:00" level=debug msg="completed challenge" Mar 24 19:41:16 katarynka go-librespot[7728]: time="2026-03-24T19:41:16+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 24 19:41:16 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 24 19:41:16 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 24 19:41:17 katarynka volumio[7711]: info: ------------------------------------------- Mar 24 19:41:17 katarynka volumio[7711]: info: ----- Volumio3 ---- Mar 24 19:41:17 katarynka volumio[7711]: info: ------------------------------------------- Mar 24 19:41:17 katarynka volumio[7711]: info: ----- System startup ---- Mar 24 19:41:17 katarynka volumio[7711]: info: ------------------------------------------- Mar 24 19:41:18 katarynka volumio-remote-updater[622]: [2026-03-24 19:41:18] [connect] Successful connection Mar 24 19:41:18 katarynka volumio[7711]: info: MYVOLUMIO Environment detected Mar 24 19:41:18 katarynka volumio[7711]: info: Plugin folders cleanup Mar 24 19:41:18 katarynka volumio[7711]: info: Scanning into folder /volumio/app/plugins/ Mar 24 19:41:18 katarynka volumio[7711]: info: Scanning category audio_interface Mar 24 19:41:18 katarynka volumio[7711]: info: Scanning category miscellanea Mar 24 19:41:18 katarynka volumio[7711]: info: Scanning category music_service Mar 24 19:41:18 katarynka volumio[7711]: info: Scanning category plugins.json Mar 24 19:41:18 katarynka volumio[7711]: info: Scanning category system_controller Mar 24 19:41:18 katarynka volumio[7711]: info: Scanning category user_interface Mar 24 19:41:18 katarynka volumio[7711]: info: Scanning into folder /data/plugins/ Mar 24 19:41:18 katarynka volumio[7711]: info: Scanning category music_service Mar 24 19:41:18 katarynka volumio[7711]: info: Plugin folders cleanup completed Mar 24 19:41:18 katarynka volumio[7711]: info: ------------------------------------------- Mar 24 19:41:18 katarynka volumio[7711]: info: ----- Core plugins startup ---- Mar 24 19:41:18 katarynka volumio[7711]: info: ------------------------------------------- Mar 24 19:41:18 katarynka volumio[7711]: info: Loading plugins from folder /volumio/app/plugins/ Mar 24 19:41:18 katarynka volumio[7711]: info: Adding plugin upnp to MyMusic Plugins Mar 24 19:41:18 katarynka volumio[7711]: info: Adding plugin airplay_emulation to MyMusic Plugins Mar 24 19:41:18 katarynka volumio[7711]: info: Adding plugin upnp_browser to MyMusic Plugins Mar 24 19:41:18 katarynka volumio[7711]: info: Loading plugins from folder /data/plugins/ Mar 24 19:41:18 katarynka volumio[7711]: info: Loading plugin "system"... Mar 24 19:41:18 katarynka volumio[7711]: info: Loading plugin "appearance"... Mar 24 19:41:19 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 17. Mar 24 19:41:19 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 24 19:41:19 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 24 19:41:19 katarynka go-librespot[7750]: go-librespot daemon starting... Mar 24 19:41:19 katarynka go-librespot[7751]: time="2026-03-24T19:41:19+01:00" level=info msg="running go-librespot 0.4.0" Mar 24 19:41:19 katarynka go-librespot[7751]: time="2026-03-24T19:41:19+01:00" level=debug msg="app state loaded" Mar 24 19:41:19 katarynka go-librespot[7751]: time="2026-03-24T19:41:19+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 24 19:41:19 katarynka go-librespot[7751]: time="2026-03-24T19:41:19+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 24 19:41:19 katarynka go-librespot[7751]: time="2026-03-24T19:41:19+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 24 19:41:19 katarynka go-librespot[7751]: time="2026-03-24T19:41:19+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 24 19:41:20 katarynka go-librespot[7751]: time="2026-03-24T19:41:20+01:00" level=info msg="zeroconf server listening on port 40227" Mar 24 19:41:20 katarynka go-librespot[7751]: time="2026-03-24T19:41:20+01:00" level=debug msg="obtained new client token: AADPstOTQfRDS+NbwQU77Y2biCUfKvVJ6lglvTl/mEiW2nUb/RdaAY8pl3WSaHsTjr12z54OML+kFpTeYwyaPl8jONgGDTWDgXvX1vxWs3tow/jMxz2CedBD9NBDUA4tR2P56WOjMpt51hfkEQPva/dukx535ZudY8Tp32SdZKE24vswepttM2C6OiBUhkdzKiP8lPqRfqNIyYmfV2a6M0H8wLUvBqk6b4iVjMfCjbSdblFLq1akkivZ" Mar 24 19:41:20 katarynka go-librespot[7751]: time="2026-03-24T19:41:20+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 24 19:41:20 katarynka go-librespot[7751]: time="2026-03-24T19:41:20+01:00" level=debug msg="completed keyexchange" Mar 24 19:41:20 katarynka go-librespot[7751]: time="2026-03-24T19:41:20+01:00" level=debug msg="completed challenge" Mar 24 19:41:20 katarynka go-librespot[7751]: time="2026-03-24T19:41:20+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 24 19:41:20 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 24 19:41:20 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 24 19:41:21 katarynka volumio[7711]: info: Loading plugin "network"... Mar 24 19:41:21 katarynka volumio[7711]: info: Refreshing Cached IP Addresses Mar 24 19:41:21 katarynka sudo[7759]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 24 19:41:21 katarynka sudo[7759]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 19:41:21 katarynka sudo[7759]: pam_unix(sudo:session): session closed for user root Mar 24 19:41:21 katarynka volumio[7711]: info: Loading plugin "services"... Mar 24 19:41:21 katarynka sudo[7761]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 24 19:41:21 katarynka sudo[7761]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 19:41:21 katarynka volumio[7711]: info: Loading plugin "alsa_controller"... Mar 24 19:41:21 katarynka sudo[7761]: pam_unix(sudo:session): session closed for user root Mar 24 19:41:21 katarynka sudo[7768]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Mar 24 19:41:21 katarynka sudo[7768]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 19:41:21 katarynka volumio[7711]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 24 19:41:21 katarynka volumio[7711]: info: Loading plugin "wizard"... Mar 24 19:41:21 katarynka volumio[7711]: info: Loading plugin "networkfs"... Mar 24 19:41:21 katarynka volumio[7711]: info: Starting Udev Watcher for removable devices Mar 24 19:41:21 katarynka volumio[7711]: info: Ignoring mount for partition: boot Mar 24 19:41:21 katarynka volumio[7711]: info: Ignoring mount for partition: volumio Mar 24 19:41:21 katarynka volumio[7711]: info: Ignoring mount for partition: volumio_data Mar 24 19:41:21 katarynka volumio[7711]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 24 19:41:21 katarynka volumio[7711]: info: Loading plugin "volumio_command_line_client"... Mar 24 19:41:21 katarynka volumio[7711]: info: Loading plugin "upnp"... Mar 24 19:41:21 katarynka volumio[7711]: info: [1774377681564] Starting Upmpd Daemon Mar 24 19:41:21 katarynka volumio[7711]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 24 19:41:21 katarynka volumio[7711]: info: Loading plugin "my_music"... Mar 24 19:41:21 katarynka volumio[7711]: info: Loading plugin "mpd"... Mar 24 19:41:22 katarynka sudo[7768]: pam_unix(sudo:session): session closed for user root Mar 24 19:41:22 katarynka volumio[7711]: info: Loading plugin "upnp_browser"... Mar 24 19:41:23 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 18. Mar 24 19:41:23 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 24 19:41:23 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 24 19:41:23 katarynka go-librespot[7792]: go-librespot daemon starting... Mar 24 19:41:23 katarynka go-librespot[7793]: time="2026-03-24T19:41:23+01:00" level=info msg="running go-librespot 0.4.0" Mar 24 19:41:23 katarynka go-librespot[7793]: time="2026-03-24T19:41:23+01:00" level=debug msg="app state loaded" Mar 24 19:41:23 katarynka go-librespot[7793]: time="2026-03-24T19:41:23+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 24 19:41:23 katarynka go-librespot[7793]: time="2026-03-24T19:41:23+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 24 19:41:23 katarynka go-librespot[7793]: time="2026-03-24T19:41:23+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 24 19:41:23 katarynka go-librespot[7793]: time="2026-03-24T19:41:23+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 24 19:41:23 katarynka go-librespot[7793]: time="2026-03-24T19:41:23+01:00" level=info msg="zeroconf server listening on port 37241" Mar 24 19:41:24 katarynka go-librespot[7793]: time="2026-03-24T19:41:24+01:00" level=debug msg="obtained new client token: AADwnHzY9V3gtmY6ZZTXMNjaO+1FehugUjDsc/N1fG9c7PIdRSqBmWkL7Ko5tbVbUOb9+rF8DG41VhgkAyGhrTrGkii2rMXvtqztR+sinqZD5SUcQjFcRQxr+XgpqAyJbDXeIOXLZK1aLNzSFm08QNiKicN4qBviIPhW1A2BaTHLw/6mK1CCP83HBtkdaqu3sPv+jequma0Z44/WUzpRS0gPqcTqWgZXSiz7qIfug+lu6JP1XfuU3jxc" Mar 24 19:41:24 katarynka go-librespot[7793]: time="2026-03-24T19:41:24+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 24 19:41:24 katarynka go-librespot[7793]: time="2026-03-24T19:41:24+01:00" level=debug msg="completed keyexchange" Mar 24 19:41:24 katarynka go-librespot[7793]: time="2026-03-24T19:41:24+01:00" level=debug msg="completed challenge" Mar 24 19:41:24 katarynka go-librespot[7793]: time="2026-03-24T19:41:24+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 24 19:41:24 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 24 19:41:24 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 24 19:41:25 katarynka volumio[7711]: info: Starting UPNP Browser Mar 24 19:41:25 katarynka volumio[7711]: info: Loading plugin "alarm-clock"... Mar 24 19:41:25 katarynka volumio[7711]: info: Loading plugin "airplay_emulation"... Mar 24 19:41:25 katarynka volumio[7711]: info: Starting Shairport Sync Mar 24 19:41:25 katarynka volumio[7711]: info: Loading plugin "last_100"... Mar 24 19:41:25 katarynka volumio[7711]: info: Loading plugin "webradio"... Mar 24 19:41:25 katarynka volumio[7711]: info: Loading plugin "i2s_dacs"... Mar 24 19:41:25 katarynka volumio[7711]: info: Loading plugin "volumiodiscovery"... Mar 24 19:41:26 katarynka volumio[7711]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Mar 24 19:41:26 katarynka volumio[7711]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 24 19:41:26 katarynka volumio[7711]: *** WARNING *** For more information see Mar 24 19:41:26 katarynka volumio[7711]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Mar 24 19:41:26 katarynka volumio[7711]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 24 19:41:26 katarynka volumio[7711]: *** WARNING *** For more information see Mar 24 19:41:26 katarynka node[7711]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Mar 24 19:41:26 katarynka node[7711]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 24 19:41:26 katarynka node[7711]: *** WARNING *** For more information see Mar 24 19:41:26 katarynka node[7711]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Mar 24 19:41:26 katarynka node[7711]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 24 19:41:26 katarynka node[7711]: *** WARNING *** For more information see Mar 24 19:41:26 katarynka volumio[7711]: info: Applying required configuration parameters for plugin volumiodiscovery Mar 24 19:41:26 katarynka volumio[7711]: info: Discovery: Started advertising with name: katarynka Mar 24 19:41:26 katarynka volumio[7711]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 24 19:41:26 katarynka volumio[7711]: info: Loading plugin "spop"... Mar 24 19:41:28 katarynka volumio[7711]: info: Loading plugin "outputs"... Mar 24 19:41:28 katarynka volumio[7711]: info: Loading plugin "albumart"... Mar 24 19:41:28 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 19. Mar 24 19:41:28 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 24 19:41:28 katarynka volumio[7711]: info: Plugin example_plugin is not enabled Mar 24 19:41:28 katarynka volumio[7711]: info: Loading plugin "inputs"... Mar 24 19:41:28 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 24 19:41:28 katarynka go-librespot[7803]: go-librespot daemon starting... Mar 24 19:41:28 katarynka volumio[7711]: info: Loading plugin "updater_comm"... Mar 24 19:41:28 katarynka go-librespot[7812]: time="2026-03-24T19:41:28+01:00" level=info msg="running go-librespot 0.4.0" Mar 24 19:41:28 katarynka go-librespot[7812]: time="2026-03-24T19:41:28+01:00" level=debug msg="app state loaded" Mar 24 19:41:28 katarynka go-librespot[7812]: time="2026-03-24T19:41:28+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 24 19:41:28 katarynka volumio[7711]: info: Plugin mpdemulation is not enabled Mar 24 19:41:28 katarynka volumio[7711]: info: Loading plugin "rest_api"... Mar 24 19:41:28 katarynka volumio[7711]: info: Loading plugin "websocket"... Mar 24 19:41:28 katarynka volumio[7711]: info: Starting Socket.io Server version 1.7.4 Mar 24 19:41:28 katarynka volumio[7711]: info: Loading i18n strings for locale pl Mar 24 19:41:28 katarynka volumio[7711]: Updating browse sources language Mar 24 19:41:28 katarynka volumio[7711]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 24 19:41:28 katarynka go-librespot[7812]: time="2026-03-24T19:41:28+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 24 19:41:28 katarynka go-librespot[7812]: time="2026-03-24T19:41:28+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 24 19:41:28 katarynka go-librespot[7812]: time="2026-03-24T19:41:28+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 24 19:41:28 katarynka go-librespot[7812]: time="2026-03-24T19:41:28+01:00" level=info msg="zeroconf server listening on port 43363" Mar 24 19:41:28 katarynka volumio[7711]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 24 19:41:28 katarynka volumio[7711]: info: CoreCommandRouter::initPlayerControls Mar 24 19:41:28 katarynka volumio[7711]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 19:41:28 katarynka volumio[7711]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 19:41:28 katarynka volumio[7711]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 19:41:28 katarynka volumio[7711]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 19:41:28 katarynka volumio[7711]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 19:41:28 katarynka volumio[7711]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 19:41:28 katarynka volumio[7711]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 19:41:28 katarynka volumio[7711]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 19:41:28 katarynka volumio[7711]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 24 19:41:28 katarynka volumio[7711]: Express server listening on port 3000 Mar 24 19:41:28 katarynka volumio[7711]: [Metrics] WebUI: 12s 726.86ms Mar 24 19:41:28 katarynka go-librespot[7812]: time="2026-03-24T19:41:28+01:00" level=debug msg="obtained new client token: AADpsJzm0KUOnLuVhz1dj2PquCxr0LRK1Xs+unZu9ReD7XUgMkPmhIzGjlCzDo2e2VPxfwTWV4p6o2/ggzLP3WttpTX0lafSov1+T5lFr0uLDz3SVPeykr1oBXAHFakQajkMqjSYm80EDbiDWvAR9RR+agKrROmbBaO7Hb+SkznXxT0i4GlFAOGT+oVQ/lku389S8QU2Z8NZSdGRohTjbGxrXxaWxWzK4NL5pUDQYugbvSSK2x7hmV5tj+I=" Mar 24 19:41:29 katarynka volumio[7711]: info: CoreStateMachine::resetVolumioState Mar 24 19:41:29 katarynka volumio[7711]: info: CoreStateMachine::getcurrentVolume Mar 24 19:41:29 katarynka volumio[7711]: info: CoreCommandRouter::volumioRetrievevolume Mar 24 19:41:29 katarynka go-librespot[7812]: time="2026-03-24T19:41:29+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 24 19:41:29 katarynka volumio[7711]: info: Cannot read play queue from file Mar 24 19:41:29 katarynka go-librespot[7812]: time="2026-03-24T19:41:29+01:00" level=debug msg="completed keyexchange" Mar 24 19:41:29 katarynka volumio[7711]: info: Volumio Network Manager: Network status updated: 2 Mar 24 19:41:29 katarynka go-librespot[7812]: time="2026-03-24T19:41:29+01:00" level=debug msg="completed challenge" Mar 24 19:41:29 katarynka go-librespot[7812]: time="2026-03-24T19:41:29+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 24 19:41:29 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 24 19:41:29 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 24 19:41:29 katarynka volumio[7802]: Forking 3 albumart workers Mar 24 19:41:29 katarynka volumio[7711]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 24 19:41:29 katarynka volumio[7711]: info: CoreStateMachine::setRepeat null single undefined Mar 24 19:41:29 katarynka volumio[7711]: info: CoreStateMachine::pushState Mar 24 19:41:29 katarynka volumio[7711]: info: CorePlayQueue::getTrack 0 Mar 24 19:41:29 katarynka volumio[7711]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 24 19:41:29 katarynka volumio[7711]: info: CoreCommandRouter::volumioPushState Mar 24 19:41:29 katarynka volumio[7711]: info: CoreStateMachine::setRandom null Mar 24 19:41:29 katarynka volumio[7711]: info: CoreStateMachine::pushState Mar 24 19:41:29 katarynka volumio[7711]: info: CorePlayQueue::getTrack 0 Mar 24 19:41:29 katarynka volumio[7711]: info: CoreCommandRouter::volumioPushState Mar 24 19:41:29 katarynka volumio[7711]: info: Setting Device type: Raspberry PI Mar 24 19:41:29 katarynka volumio[7711]: info: Completed loading Core Plugins Mar 24 19:41:29 katarynka volumio[7711]: info: Preparing to generate the ALSA configuration file Mar 24 19:41:29 katarynka volumio[7711]: info: VolumeController:: Volume=96 Mute =false Mar 24 19:41:29 katarynka volumio[7711]: info: CoreStateMachine::pushState Mar 24 19:41:29 katarynka volumio[7711]: info: CorePlayQueue::getTrack 0 Mar 24 19:41:29 katarynka volumio[7711]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 24 19:41:29 katarynka volumio[7711]: info: CoreCommandRouter::volumioPushState Mar 24 19:41:29 katarynka volumio[7711]: info: CoreStateMachine::updateTrackBlock Mar 24 19:41:29 katarynka volumio[7711]: info: CorePlayQueue::getTrackBlock Mar 24 19:41:29 katarynka volumio[7711]: info: CoreCommandRouter::volumioRetrievevolume Mar 24 19:41:29 katarynka volumio[7711]: info: Asound.conf file unchanged, so no further update is needed Mar 24 19:41:29 katarynka volumio[7711]: info: Output device has changed, restarting MPD Mar 24 19:41:29 katarynka volumio[7711]: info: Output device has changed, restarting Shairport Sync Mar 24 19:41:29 katarynka volumio[7711]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 19:41:29 katarynka sudo[7865]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 24 19:41:29 katarynka sudo[7865]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 19:41:29 katarynka volumio[7711]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 24 19:41:29 katarynka sudo[7865]: pam_unix(sudo:session): session closed for user root Mar 24 19:41:29 katarynka sudo[7867]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 24 19:41:29 katarynka sudo[7867]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 19:41:29 katarynka volumio[7711]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 24 19:41:29 katarynka volumio[7711]: info: ___________ START PLUGINS ___________ Mar 24 19:41:30 katarynka systemd[1]: Stopping mpd.service - Music Player Daemon... Mar 24 19:41:30 katarynka volumio[7711]: info: ControllerMpd::onStart: Initializing MPD Mar 24 19:41:30 katarynka volumio[7711]: info: Creating MPD Configuration file Mar 24 19:41:30 katarynka systemd[1]: mpd.service: Deactivated successfully. Mar 24 19:41:30 katarynka systemd[1]: Stopped mpd.service - Music Player Daemon. Mar 24 19:41:30 katarynka systemd[1]: mpd.service: Consumed 7.799s CPU time. Mar 24 19:41:30 katarynka systemd[1]: mpd.socket: Deactivated successfully. Mar 24 19:41:30 katarynka systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Mar 24 19:41:30 katarynka systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Mar 24 19:41:30 katarynka volumio[7711]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 24 19:41:30 katarynka volumio[7711]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 24 19:41:30 katarynka volumio[7711]: info: [1774377690209] CoreMusicLibrary::Adding element Serwery Mediów Mar 24 19:41:30 katarynka volumio[7711]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 24 19:41:30 katarynka sudo[7877]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 24 19:41:30 katarynka sudo[7877]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 19:41:30 katarynka sudo[7875]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 24 19:41:30 katarynka systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Mar 24 19:41:30 katarynka sudo[7875]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 19:41:30 katarynka systemd[1]: Starting mpd.service - Music Player Daemon... Mar 24 19:41:30 katarynka sudo[7875]: pam_unix(sudo:session): session closed for user root Mar 24 19:41:30 katarynka volumio[7711]: info: UPNP Browser: Client initialized successfully Mar 24 19:41:30 katarynka systemd[1]: mpd.service: Deactivated successfully. Mar 24 19:41:30 katarynka systemd[1]: Stopped mpd.service - Music Player Daemon. Mar 24 19:41:30 katarynka systemd[1]: mpd.socket: Deactivated successfully. Mar 24 19:41:30 katarynka volumio[7711]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 19:41:30 katarynka volumio[7711]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 24 19:41:30 katarynka systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Mar 24 19:41:30 katarynka systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Mar 24 19:41:30 katarynka volumio[7711]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 24 19:41:30 katarynka volumio[7711]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 19:41:30 katarynka volumio[7711]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 24 19:41:30 katarynka systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Mar 24 19:41:30 katarynka systemd[1]: Starting mpd.service - Music Player Daemon... Mar 24 19:41:30 katarynka volumio[7711]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 24 19:41:30 katarynka volumio[7711]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 24 19:41:30 katarynka volumio[7711]: info: [1774377690568] CoreMusicLibrary::Adding element Last_100 Mar 24 19:41:30 katarynka volumio[7711]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 24 19:41:30 katarynka volumio[7711]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 24 19:41:30 katarynka volumio[7711]: info: [1774377690599] CoreMusicLibrary::Adding element Webradio Mar 24 19:41:30 katarynka volumio[7711]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 24 19:41:30 katarynka volumio[7711]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 24 19:41:30 katarynka volumio[7711]: info: Initializing BBC Radios Mar 24 19:41:30 katarynka volumio-remote-updater[622]: [2026-03-24 19:41:30] [connect] Successful connection Mar 24 19:41:30 katarynka volumio[7711]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 24 19:41:30 katarynka volumio[7711]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 24 19:41:30 katarynka volumio[7711]: info: Creating Spotify config file Mar 24 19:41:30 katarynka volumio[7711]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 19:41:30 katarynka sudo[7889]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Mar 24 19:41:30 katarynka sudo[7889]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Mar 24 19:41:31 katarynka sudo[7889]: pam_unix(sudo:session): session closed for user root Mar 24 19:41:31 katarynka volumio[7711]: info: Volumio Calling Home Mar 24 19:41:32 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 20. Mar 24 19:41:32 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 24 19:41:32 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 24 19:41:32 katarynka go-librespot[7924]: go-librespot daemon starting... Mar 24 19:41:32 katarynka go-librespot[7925]: time="2026-03-24T19:41:32+01:00" level=info msg="running go-librespot 0.4.0" Mar 24 19:41:32 katarynka volumio[7831]: Starting albumart workers Mar 24 19:41:33 katarynka volumio[7711]: info: Discovery: adding 4d616d77-6a8c-4da2-85a4-840d70f98e51 Mar 24 19:41:33 katarynka volumio[7711]: info: Discovery: Found device katarynka Mar 24 19:41:33 katarynka volumio[7711]: info: CoreCommandRouter::volumioGetState Mar 24 19:41:33 katarynka volumio[7711]: info: CorePlayQueue::getTrack 0 Mar 24 19:41:33 katarynka sudo[7933]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 24 19:41:33 katarynka sudo[7933]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 19:41:33 katarynka sudo[7934]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 24 19:41:33 katarynka sudo[7934]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 19:41:33 katarynka volumio[7832]: Starting albumart workers Mar 24 19:41:33 katarynka sudo[7933]: pam_unix(sudo:session): session closed for user root Mar 24 19:41:33 katarynka sudo[7934]: pam_unix(sudo:session): session closed for user root Mar 24 19:41:33 katarynka volumio[7711]: info: MPD Permissions set Mar 24 19:41:33 katarynka volumio[7711]: info: MPD Permissions set Mar 24 19:41:33 katarynka volumio[7711]: info: VolumeController:: Volume=96 Mute =false Mar 24 19:41:33 katarynka volumio[7711]: info: CoreStateMachine::pushState Mar 24 19:41:33 katarynka volumio[7711]: info: CorePlayQueue::getTrack 0 Mar 24 19:41:33 katarynka volumio[7711]: info: CoreCommandRouter::volumioPushState Mar 24 19:41:33 katarynka volumio[7711]: info: Discovery: this is already registered, 4d616d77-6a8c-4da2-85a4-840d70f98e51 Mar 24 19:41:33 katarynka volumio[7711]: info: Discovery: Found device katarynka Mar 24 19:41:33 katarynka volumio[7711]: info: CoreCommandRouter::volumioGetState Mar 24 19:41:33 katarynka volumio[7711]: info: CorePlayQueue::getTrack 0 Mar 24 19:41:33 katarynka volumio-remote-updater[622]: [2026-03-24 19:41:33] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1774377690 101 Mar 24 19:41:33 katarynka volumio[7827]: Starting albumart workers Mar 24 19:41:33 katarynka volumio[7711]: 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 24 19:41:33 katarynka volumio[7711]: info: Volumio called home Mar 24 19:41:33 katarynka volumio[7711]: info: Spotify config file written Mar 24 19:41:33 katarynka sudo[7938]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Mar 24 19:41:33 katarynka sudo[7938]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 19:41:34 katarynka volumio[7711]: 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 24 19:41:34 katarynka volumio[7711]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 19:41:34 katarynka volumio[7711]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 19:41:34 katarynka volumio[7711]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 19:41:34 katarynka volumio[7711]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 19:41:34 katarynka systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Mar 24 19:41:34 katarynka volumio[7711]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 19:41:34 katarynka volumio[7711]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 19:41:34 katarynka volumio[7711]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 19:41:34 katarynka volumio[7711]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 19:41:34 katarynka systemd[1]: go-librespot-daemon.service: Deactivated successfully. Mar 24 19:41:34 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 24 19:41:34 katarynka volumio[7711]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 24 19:41:34 katarynka volumio[7711]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 19:41:34 katarynka volumio[7711]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 19:41:34 katarynka volumio[7711]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 19:41:34 katarynka volumio[7711]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 19:41:34 katarynka volumio[7711]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 19:41:34 katarynka volumio[7711]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 19:41:34 katarynka volumio[7711]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 19:41:34 katarynka volumio[7711]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 19:41:34 katarynka volumio[7711]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 19:41:34 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 24 19:41:34 katarynka go-librespot[7945]: go-librespot daemon starting... Mar 24 19:41:34 katarynka sudo[7938]: pam_unix(sudo:session): session closed for user root Mar 24 19:41:34 katarynka volumio[7711]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 24 19:41:34 katarynka volumio[7711]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 19:41:34 katarynka go-librespot[7949]: time="2026-03-24T19:41:34+01:00" level=info msg="running go-librespot 0.4.0" Mar 24 19:41:34 katarynka go-librespot[7949]: time="2026-03-24T19:41:34+01:00" level=debug msg="app state loaded" Mar 24 19:41:34 katarynka go-librespot[7949]: time="2026-03-24T19:41:34+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 24 19:41:34 katarynka volumio[7711]: info: No need to fix Spotify hosts Mar 24 19:41:35 katarynka volumio[7711]: info: Starting Shairport Sync Mar 24 19:41:35 katarynka go-librespot[7949]: time="2026-03-24T19:41: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 24 19:41:35 katarynka go-librespot[7949]: time="2026-03-24T19:41:35+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 24 19:41:35 katarynka go-librespot[7949]: time="2026-03-24T19:41:35+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 24 19:41:35 katarynka go-librespot[7949]: time="2026-03-24T19:41:35+01:00" level=info msg="zeroconf server listening on port 33017" Mar 24 19:41:35 katarynka volumio[7711]: info: Starting Shairport Sync Mar 24 19:41:35 katarynka volumio[7711]: info: Starting Shairport Sync Mar 24 19:41:35 katarynka sudo[7972]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 24 19:41:35 katarynka sudo[7972]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 19:41:35 katarynka go-librespot[7949]: time="2026-03-24T19:41:35+01:00" level=debug msg="obtained new client token: AAAQfF67M9SrkjJ1reGdVhBEnN2wWd20ZphW4J4VYgUunYdRY10nOWvJ9fpfe0RhmQwQHSNL4TDoLQzQP8IJn+k1869fzLADX7JAmw8q4PZNpE+VFbBvhdtyMZDs+kjLmj7+P3n3cbDjgTi3OjMpIuoAl8bz43iF8qOOxZhZck9mzDpuUhXwUj4CaxK//MN4oWaxdUoIKiKsLC1wDnv5GEnwkBirmZU/Or5zVF/IKC0S/kMSx1lRAMA8" Mar 24 19:41:35 katarynka sudo[7974]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 24 19:41:35 katarynka go-librespot[7949]: time="2026-03-24T19:41:35+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 24 19:41:35 katarynka systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Mar 24 19:41:35 katarynka systemd[1]: shairport-sync.service: Deactivated successfully. Mar 24 19:41:35 katarynka systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 24 19:41:35 katarynka systemd[1]: shairport-sync.service: Consumed 2.423s CPU time. Mar 24 19:41:35 katarynka sudo[7974]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 19:41:35 katarynka sudo[7979]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Mar 24 19:41:35 katarynka go-librespot[7949]: time="2026-03-24T19:41:35+01:00" level=debug msg="completed keyexchange" Mar 24 19:41:35 katarynka go-librespot[7949]: time="2026-03-24T19:41:35+01:00" level=debug msg="completed challenge" Mar 24 19:41:35 katarynka sudo[7979]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 19:41:35 katarynka sudo[7976]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 24 19:41:35 katarynka sudo[7976]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 19:41:35 katarynka systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 24 19:41:35 katarynka go-librespot[7949]: time="2026-03-24T19:41:35+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 24 19:41:35 katarynka sudo[7972]: pam_unix(sudo:session): session closed for user root Mar 24 19:41:35 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 24 19:41:35 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 24 19:41:35 katarynka volumio[7711]: info: CoreCommandRouter::volumioGetState Mar 24 19:41:35 katarynka volumio[7711]: info: CorePlayQueue::getTrack 0 Mar 24 19:41:35 katarynka systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Mar 24 19:41:35 katarynka volumio[7711]: info: Shairport-Sync Started Mar 24 19:41:35 katarynka systemd[1]: shairport-sync.service: Deactivated successfully. Mar 24 19:41:35 katarynka systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 24 19:41:35 katarynka volumio[7711]: Error adding Membership: Error: addMembership EINVAL Mar 24 19:41:35 katarynka sudo[7979]: pam_unix(sudo:session): session closed for user root Mar 24 19:41:35 katarynka volumio[7711]: info: An error occurred while refreshing Spotify Token Error: Bad Request Mar 24 19:41:35 katarynka systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 24 19:41:35 katarynka volumio[7711]: info: Upmpdcli Daemon Started Mar 24 19:41:35 katarynka sudo[7974]: pam_unix(sudo:session): session closed for user root Mar 24 19:41:35 katarynka volumio[7711]: info: Shairport-Sync Started Mar 24 19:41:35 katarynka sudo[7976]: pam_unix(sudo:session): session closed for user root Mar 24 19:41:35 katarynka volumio[7711]: info: Shairport-Sync Started Mar 24 19:41:38 katarynka volumio[7711]: info: go-librespot daemon successfully initialized Mar 24 19:41:38 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Mar 24 19:41:38 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 24 19:41:38 katarynka mpd[7906]: 2026-03-24T19:41:38 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Mar 24 19:41:38 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 24 19:41:38 katarynka go-librespot[8022]: go-librespot daemon starting... Mar 24 19:41:38 katarynka systemd[1]: Started mpd.service - Music Player Daemon. Mar 24 19:41:38 katarynka sudo[7877]: pam_unix(sudo:session): session closed for user root Mar 24 19:41:38 katarynka sudo[7867]: pam_unix(sudo:session): session closed for user root Mar 24 19:41:38 katarynka go-librespot[8025]: time="2026-03-24T19:41:38+01:00" level=info msg="running go-librespot 0.4.0" Mar 24 19:41:38 katarynka go-librespot[8025]: time="2026-03-24T19:41:38+01:00" level=debug msg="app state loaded" Mar 24 19:41:38 katarynka go-librespot[8025]: time="2026-03-24T19:41:38+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 24 19:41:38 katarynka volumio[7711]: info: Completed starting Core Plugins Mar 24 19:41:38 katarynka volumio[7711]: info: ------------------------------------------- Mar 24 19:41:38 katarynka volumio[7711]: info: ----- MyVolumio plugins startup ---- Mar 24 19:41:38 katarynka volumio[7711]: info: ------------------------------------------- Mar 24 19:41:38 katarynka volumio[7711]: info: [MyVolumio PluginManager] Fetching plans data.... Mar 24 19:41:39 katarynka volumio[7711]: error: MPD error: The expression evaluated to a falsy value: Mar 24 19:41:39 katarynka volumio[7711]: assert.ok(self.idling) Mar 24 19:41:39 katarynka volumio[7711]: error: The expression evaluated to a falsy value: Mar 24 19:41:39 katarynka volumio[7711]: assert.ok(self.idling) Mar 24 19:41:39 katarynka volumio[7711]: error: updateQueue error: null Mar 24 19:41:39 katarynka volumio[7711]: info: MPD running with PID7906 Mar 24 19:41:39 katarynka volumio[7711]: ,establishing connection Mar 24 19:41:39 katarynka volumio[7711]: error: updateQueue error: null Mar 24 19:41:39 katarynka go-librespot[8025]: time="2026-03-24T19:41:39+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 24 19:41:39 katarynka go-librespot[8025]: time="2026-03-24T19:41:39+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 24 19:41:39 katarynka go-librespot[8025]: time="2026-03-24T19:41:39+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 24 19:41:39 katarynka go-librespot[8025]: time="2026-03-24T19:41:39+01:00" level=info msg="zeroconf server listening on port 36645" Mar 24 19:41:39 katarynka go-librespot[8025]: time="2026-03-24T19:41:39+01:00" level=debug msg="obtained new client token: AABHmsx1T4FkEYvtvuCXGPU98OrMYbva2VeB5/v9VgN5kSspPyjDxudTKuVXPIq+xt+MiXddskjJVzcLKlfJIaG9QSXPFMlXk658DRRyild6WdpzOOkWFGp3qfZDO1KRUhJ2MpvUUQZjZlpDgT77cQQo2gou/6gfLim7QO+Mi4gnkAQY6PsTyrnTeaXjMoUosfYFhAD//WEeawwVPZyQ2+g0F2ZxCegAWhS339ismF0Chzbv3iwqZEeynmc=" Mar 24 19:41:39 katarynka go-librespot[8025]: time="2026-03-24T19:41:39+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 24 19:41:39 katarynka go-librespot[8025]: time="2026-03-24T19:41:39+01:00" level=debug msg="completed keyexchange" Mar 24 19:41:39 katarynka go-librespot[8025]: time="2026-03-24T19:41:39+01:00" level=debug msg="completed challenge" Mar 24 19:41:39 katarynka go-librespot[8025]: time="2026-03-24T19:41:39+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 24 19:41:39 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 24 19:41:39 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 24 19:41:41 katarynka volumio[7711]: info: Initializing connection to go-librespot Websocket Mar 24 19:41:41 katarynka volumio[7711]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 24 19:41:41 katarynka sudo[8051]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Mar 24 19:41:41 katarynka sudo[8051]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 19:41:41 katarynka sudo[8053]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Mar 24 19:41:41 katarynka sudo[8053]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 19:41:41 katarynka systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Mar 24 19:41:41 katarynka systemd[1]: mpd_monitor.service: Deactivated successfully. Mar 24 19:41:41 katarynka systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Mar 24 19:41:42 katarynka systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Mar 24 19:41:42 katarynka sudo[8051]: pam_unix(sudo:session): session closed for user root Mar 24 19:41:42 katarynka sudo[8053]: pam_unix(sudo:session): session closed for user root Mar 24 19:41:42 katarynka mpd_monitor.sh[8056]: MPD Monitor Service: Starting MPD Monitor Service Mar 24 19:41:42 katarynka volumio[7711]: info: Successfully started MPD Monitor Mar 24 19:41:42 katarynka volumio[7711]: info: Successfully started MPD Monitor Mar 24 19:41:42 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Mar 24 19:41:42 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 24 19:41:42 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 24 19:41:42 katarynka go-librespot[8060]: go-librespot daemon starting... Mar 24 19:41:42 katarynka go-librespot[8061]: time="2026-03-24T19:41:42+01:00" level=info msg="running go-librespot 0.4.0" Mar 24 19:41:42 katarynka go-librespot[8061]: time="2026-03-24T19:41:42+01:00" level=debug msg="app state loaded" Mar 24 19:41:42 katarynka go-librespot[8061]: time="2026-03-24T19:41:42+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 24 19:41:43 katarynka go-librespot[8061]: time="2026-03-24T19:41:43+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Mar 24 19:41:43 katarynka go-librespot[8061]: time="2026-03-24T19:41:43+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Mar 24 19:41:43 katarynka go-librespot[8061]: time="2026-03-24T19:41:43+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Mar 24 19:41:43 katarynka go-librespot[8061]: time="2026-03-24T19:41:43+01:00" level=info msg="zeroconf server listening on port 39523" Mar 24 19:41:43 katarynka go-librespot[8061]: time="2026-03-24T19:41:43+01:00" level=debug msg="obtained new client token: AABZ9hX6TvaDLe3m9oUGFvey7xOw5UuBFcNpFCg1RD8YcYD0YoQZgBhsFSs5f/s1okDzbR3QQ0FYJaGjbNPJpyaupgtFxUO2KKC9kQQDn49MJSGSBMb9m16EzEDqKKUAL73ZRWxSh6mVdGRSJvRQonzJ1f5629MUjaQgxwgPVT8FYR0CgWOgmoVjGuixy34XrVVFZcVSfw2d+qQoXEiak1NLQ9KLhhw+6FMiGHktxNxua1slpyDpxu/mDxY=" Mar 24 19:41:43 katarynka go-librespot[8061]: time="2026-03-24T19:41:43+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 24 19:41:43 katarynka go-librespot[8061]: time="2026-03-24T19:41:43+01:00" level=debug msg="completed keyexchange" Mar 24 19:41:43 katarynka go-librespot[8061]: time="2026-03-24T19:41:43+01:00" level=debug msg="completed challenge" Mar 24 19:41:43 katarynka go-librespot[8061]: time="2026-03-24T19:41:43+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 24 19:41:43 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 24 19:41:43 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 24 19:41:43 katarynka volumio[7711]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Mar 24 19:41:44 katarynka volumio[7711]: info: Initializing connection to go-librespot Websocket Mar 24 19:41:44 katarynka volumio[7711]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 24 19:41:46 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Mar 24 19:41:46 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 24 19:41:46 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 24 19:41:46 katarynka go-librespot[8068]: go-librespot daemon starting... Mar 24 19:41:46 katarynka go-librespot[8069]: time="2026-03-24T19:41:46+01:00" level=info msg="running go-librespot 0.4.0" Mar 24 19:41:46 katarynka go-librespot[8069]: time="2026-03-24T19:41:46+01:00" level=debug msg="app state loaded" Mar 24 19:41:46 katarynka go-librespot[8069]: time="2026-03-24T19:41:46+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 24 19:41:47 katarynka volumio[7711]: info: Initializing connection to go-librespot Websocket Mar 24 19:41:47 katarynka go-librespot[8069]: time="2026-03-24T19:41:47+01:00" level=debug msg="new websocket client" Mar 24 19:41:47 katarynka volumio[7711]: info: Connection to go-librespot Websocket established Mar 24 19:41:47 katarynka go-librespot[8069]: time="2026-03-24T19:41:47+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 24 19:41:47 katarynka go-librespot[8069]: time="2026-03-24T19:41:47+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 24 19:41:47 katarynka go-librespot[8069]: time="2026-03-24T19:41:47+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 24 19:41:47 katarynka go-librespot[8069]: time="2026-03-24T19:41:47+01:00" level=info msg="zeroconf server listening on port 44507" Mar 24 19:41:47 katarynka volumio[7711]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Mar 24 19:41:47 katarynka volumio[7711]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Mar 24 19:41:47 katarynka volumio[7711]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Mar 24 19:41:47 katarynka volumio[7711]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Mar 24 19:41:47 katarynka volumio[7711]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Mar 24 19:41:47 katarynka volumio[7711]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Mar 24 19:41:47 katarynka volumio[7711]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Mar 24 19:41:47 katarynka volumio[7711]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Mar 24 19:41:47 katarynka volumio[7711]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Mar 24 19:41:47 katarynka volumio[7711]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Mar 24 19:41:47 katarynka volumio[7711]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Mar 24 19:41:47 katarynka volumio[7711]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Mar 24 19:41:47 katarynka volumio[7711]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Mar 24 19:41:47 katarynka volumio[7711]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Mar 24 19:41:47 katarynka volumio[7711]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Mar 24 19:41:47 katarynka volumio[7711]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Mar 24 19:41:47 katarynka volumio[7711]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Mar 24 19:41:47 katarynka volumio[7711]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Mar 24 19:41:47 katarynka volumio[7711]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Mar 24 19:41:47 katarynka volumio[7711]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Mar 24 19:41:47 katarynka volumio[7711]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Mar 24 19:41:47 katarynka volumio[7711]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Mar 24 19:41:47 katarynka volumio[7711]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Mar 24 19:41:47 katarynka volumio[7711]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Mar 24 19:41:47 katarynka volumio[7711]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Mar 24 19:41:47 katarynka volumio[7711]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Mar 24 19:41:47 katarynka volumio[7711]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Mar 24 19:41:47 katarynka volumio[7711]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Mar 24 19:41:47 katarynka volumio[7711]: info: Adding plugin bluetooth to MyMusic Plugins Mar 24 19:41:47 katarynka volumio[7711]: info: Adding plugin multiroom to MyMusic Plugins Mar 24 19:41:47 katarynka volumio[7711]: info: Adding plugin metavolumio to MyMusic Plugins Mar 24 19:41:47 katarynka volumio[7711]: info: Adding plugin cd_controller to MyMusic Plugins Mar 24 19:41:47 katarynka volumio[7711]: info: Adding plugin qobuzconnect to MyMusic Plugins Mar 24 19:41:47 katarynka volumio[7711]: info: Adding plugin smart_inputs to MyMusic Plugins Mar 24 19:41:47 katarynka volumio[7711]: info: Adding plugin tidalconnect to MyMusic Plugins Mar 24 19:41:47 katarynka volumio[7711]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Mar 24 19:41:47 katarynka go-librespot[8069]: time="2026-03-24T19:41:47+01:00" level=debug msg="obtained new client token: AABwOczoAXpQ+mNNy7y1Tw6Tev+osWp8M37zTr7Jn9+6Ex2uQChr3jvQ19pG5ylYUI6+UA6Hy3mCVIOzD/poEpVv8duzE+jSei8xv45pfWrBd7UOACxLMEfnnM2xrLg5WLx/c5+bGt6lb6MmD79LBNfV/jZOzpJTdCssxIk4GV+CF7rIIoENwtEilMFPLkKG2yF3Mpo9+rTgQt3DJbwe9EuYEYVgc6i9qKhmtLx51+UH6XVKYaSQEt5R9iA=" Mar 24 19:41:47 katarynka go-librespot[8069]: time="2026-03-24T19:41:47+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 24 19:41:47 katarynka go-librespot[8069]: time="2026-03-24T19:41:47+01:00" level=debug msg="completed keyexchange" Mar 24 19:41:47 katarynka go-librespot[8069]: time="2026-03-24T19:41:47+01:00" level=debug msg="completed challenge" Mar 24 19:41:47 katarynka go-librespot[8069]: time="2026-03-24T19:41:47+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 24 19:41:47 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 24 19:41:47 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 24 19:41:49 katarynka volumio[7711]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Mar 24 19:41:49 katarynka volumio[7711]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Mar 24 19:41:49 katarynka volumio[7711]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 24 19:41:49 katarynka volumio[7711]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 24 19:41:49 katarynka volumio[7711]: info: Starting MyVolumio Remote Streaming Endpoints Mar 24 19:41:49 katarynka volumio[7711]: info: MyVolumio login type: Token Mar 24 19:41:49 katarynka volumio[7711]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Mar 24 19:41:49 katarynka volumio[7711]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Mar 24 19:41:50 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Mar 24 19:41:50 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 24 19:41:50 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 24 19:41:50 katarynka go-librespot[8076]: go-librespot daemon starting... Mar 24 19:41:50 katarynka go-librespot[8077]: time="2026-03-24T19:41:50+01:00" level=info msg="running go-librespot 0.4.0" Mar 24 19:41:50 katarynka go-librespot[8077]: time="2026-03-24T19:41:50+01:00" level=debug msg="app state loaded" Mar 24 19:41:50 katarynka go-librespot[8077]: time="2026-03-24T19:41:50+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 24 19:41:51 katarynka volumio[7711]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Mar 24 19:41:51 katarynka volumio[7711]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Mar 24 19:41:51 katarynka volumio[7711]: info: Streaming services startup Mar 24 19:41:51 katarynka volumio[7711]: info: Starting Streaming Daemon Mar 24 19:41:51 katarynka go-librespot[8077]: time="2026-03-24T19:41:51+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Mar 24 19:41:51 katarynka go-librespot[8077]: time="2026-03-24T19:41:51+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 24 19:41:51 katarynka go-librespot[8077]: time="2026-03-24T19:41:51+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 24 19:41:51 katarynka sudo[8086]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Mar 24 19:41:51 katarynka sudo[8086]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 19:41:51 katarynka volumio[7711]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Mar 24 19:41:51 katarynka go-librespot[8077]: time="2026-03-24T19:41:51+01:00" level=info msg="zeroconf server listening on port 41309" Mar 24 19:41:51 katarynka sudo[8086]: pam_unix(sudo:session): session closed for user root Mar 24 19:41:51 katarynka go-librespot[8077]: time="2026-03-24T19:41:51+01:00" level=debug msg="obtained new client token: AAAKC2LF0enKwRpClzq+6zdBbKT7tzZlWdN6kzj9kR+NFcvinfMufog8I/MQrLhkBrdFMaAFnd57w3nI6TmFI2V5Sxs/Izja/igJ6MZio9QmpTjh+Ah5wPEhZ4ZrFvxj8lFyWvGG4pl/61wJXr4XJl1hmA9diJ6fakSMJp83re2nxsv4CC/hjeTNuyxPO6THFI6icnLVNCxSUeaCewr6dzFjXcmgqlfy/ZBX65V2WvCU9FgFqjf/SMDew9s=" Mar 24 19:41:51 katarynka volumio[7711]: info: Getting Spotify volume Mar 24 19:41:51 katarynka go-librespot[8077]: time="2026-03-24T19:41:51+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 24 19:41:51 katarynka volumio[7711]: info: Connection to go-librespot Websocket closed Mar 24 19:41:51 katarynka volumio[7711]: error: Cannot start Volumio Streaming Daemon Mar 24 19:41:51 katarynka volumio[7711]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Mar 24 19:41:51 katarynka volumio[7711]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Mar 24 19:41:51 katarynka volumio[7711]: 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 24 19:41:51 katarynka go-librespot[8077]: time="2026-03-24T19:41:51+01:00" level=debug msg="completed keyexchange" Mar 24 19:41:51 katarynka go-librespot[8077]: time="2026-03-24T19:41:51+01:00" level=debug msg="completed challenge" Mar 24 19:41:51 katarynka go-librespot[8077]: time="2026-03-24T19:41:51+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 24 19:41:51 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 24 19:41:51 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 24 19:41:51 katarynka volumio[7711]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 24 19:41:51 katarynka volumio[7711]: Error: socket hang up Mar 24 19:41:51 katarynka volumio[7711]: at connResetException (node:internal/errors:720:14) Mar 24 19:41:51 katarynka volumio[7711]: at Socket.socketOnEnd (node:_http_client:519:23) Mar 24 19:41:51 katarynka volumio[7711]: at Socket.emit (node:events:526:35) Mar 24 19:41:51 katarynka volumio[7711]: at endReadableNT (node:internal/streams/readable:1376:12) Mar 24 19:41:51 katarynka volumio[7711]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Mar 24 19:41:51 katarynka volumio[7711]: code: 'ECONNRESET', Mar 24 19:41:51 katarynka volumio[7711]: response: undefined Mar 24 19:41:51 katarynka volumio[7711]: } Mar 24 19:41:51 katarynka volumio[7711]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 24 19:41:53 katarynka sudo[8121]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-03-24 19:40' Mar 24 19:41:53 katarynka sudo[8121]: 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"