Mar 25 08:57:00 katarynka volumio[13765]: info: Plugin mpdemulation is not enabled Mar 25 08:57:00 katarynka volumio[13765]: info: Loading plugin "rest_api"... Mar 25 08:57:00 katarynka volumio[13765]: info: Loading plugin "websocket"... Mar 25 08:57:00 katarynka volumio[13765]: info: Starting Socket.io Server version 1.7.4 Mar 25 08:57:00 katarynka volumio[13765]: info: Loading i18n strings for locale pl Mar 25 08:57:00 katarynka volumio[13765]: Updating browse sources language Mar 25 08:57:00 katarynka volumio[13765]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 25 08:57:00 katarynka volumio[13765]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 25 08:57:00 katarynka volumio[13765]: info: CoreCommandRouter::initPlayerControls Mar 25 08:57:00 katarynka volumio[13765]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 08:57:00 katarynka volumio[13765]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 08:57:00 katarynka volumio[13765]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 08:57:00 katarynka volumio[13765]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 08:57:00 katarynka volumio[13765]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 08:57:00 katarynka volumio[13765]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 08:57:00 katarynka volumio[13765]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 08:57:00 katarynka volumio[13765]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 08:57:00 katarynka volumio[13765]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 25 08:57:00 katarynka volumio[13765]: Express server listening on port 3000 Mar 25 08:57:00 katarynka volumio[13765]: [Metrics] WebUI: 12s 459.12ms Mar 25 08:57:00 katarynka volumio[13765]: info: CoreStateMachine::resetVolumioState Mar 25 08:57:00 katarynka volumio[13765]: info: CoreStateMachine::getcurrentVolume Mar 25 08:57:00 katarynka volumio[13765]: info: CoreCommandRouter::volumioRetrievevolume Mar 25 08:57:00 katarynka volumio[13765]: info: Cannot read play queue from file Mar 25 08:57:00 katarynka volumio[13765]: info: Volumio Network Manager: Network status updated: 2 Mar 25 08:57:00 katarynka volumio[13866]: Forking 3 albumart workers Mar 25 08:57:01 katarynka volumio[13765]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 08:57:01 katarynka volumio[13765]: info: CoreStateMachine::setRepeat null single undefined Mar 25 08:57:01 katarynka volumio[13765]: info: CoreStateMachine::pushState Mar 25 08:57:01 katarynka volumio[13765]: info: CorePlayQueue::getTrack 0 Mar 25 08:57:01 katarynka volumio[13765]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 25 08:57:01 katarynka volumio[13765]: info: CoreCommandRouter::volumioPushState Mar 25 08:57:01 katarynka volumio[13765]: info: CoreStateMachine::setRandom null Mar 25 08:57:01 katarynka volumio[13765]: info: CoreStateMachine::pushState Mar 25 08:57:01 katarynka volumio[13765]: info: CorePlayQueue::getTrack 0 Mar 25 08:57:01 katarynka volumio[13765]: info: CoreCommandRouter::volumioPushState Mar 25 08:57:01 katarynka volumio[13765]: info: Setting Device type: Raspberry PI Mar 25 08:57:01 katarynka volumio[13765]: info: VolumeController:: Volume=96 Mute =false Mar 25 08:57:01 katarynka volumio[13765]: info: CoreStateMachine::pushState Mar 25 08:57:01 katarynka volumio[13765]: info: CorePlayQueue::getTrack 0 Mar 25 08:57:01 katarynka volumio[13765]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 25 08:57:01 katarynka volumio[13765]: info: CoreCommandRouter::volumioPushState Mar 25 08:57:01 katarynka volumio[13765]: info: CoreStateMachine::updateTrackBlock Mar 25 08:57:01 katarynka volumio[13765]: info: CorePlayQueue::getTrackBlock Mar 25 08:57:01 katarynka volumio[13765]: info: CoreCommandRouter::volumioRetrievevolume Mar 25 08:57:01 katarynka volumio[13765]: info: Completed loading Core Plugins Mar 25 08:57:01 katarynka volumio[13765]: info: Preparing to generate the ALSA configuration file Mar 25 08:57:01 katarynka volumio[13765]: info: Asound.conf file unchanged, so no further update is needed Mar 25 08:57:01 katarynka volumio[13765]: info: Output device has changed, restarting MPD Mar 25 08:57:01 katarynka volumio[13765]: info: Output device has changed, restarting Shairport Sync Mar 25 08:57:01 katarynka volumio[13765]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 08:57:01 katarynka volumio[13765]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 08:57:01 katarynka sudo[13920]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 25 08:57:01 katarynka sudo[13920]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 08:57:01 katarynka sudo[13920]: pam_unix(sudo:session): session closed for user root Mar 25 08:57:01 katarynka sudo[13922]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 25 08:57:01 katarynka sudo[13922]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 08:57:01 katarynka volumio[13765]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 25 08:57:01 katarynka volumio[13765]: info: ___________ START PLUGINS ___________ Mar 25 08:57:01 katarynka volumio[13765]: info: ControllerMpd::onStart: Initializing MPD Mar 25 08:57:01 katarynka volumio[13765]: info: Creating MPD Configuration file Mar 25 08:57:01 katarynka systemd[1]: Stopping mpd.service - Music Player Daemon... Mar 25 08:57:01 katarynka volumio[13765]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 25 08:57:01 katarynka volumio[13765]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 25 08:57:01 katarynka sudo[13930]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 25 08:57:01 katarynka volumio[13765]: info: [1774425421791] CoreMusicLibrary::Adding element Serwery Mediów Mar 25 08:57:01 katarynka volumio[13765]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 25 08:57:01 katarynka sudo[13930]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 08:57:01 katarynka sudo[13930]: pam_unix(sudo:session): session closed for user root Mar 25 08:57:01 katarynka systemd[1]: mpd.service: Deactivated successfully. Mar 25 08:57:01 katarynka systemd[1]: Stopped mpd.service - Music Player Daemon. Mar 25 08:57:01 katarynka systemd[1]: mpd.service: Consumed 7.837s CPU time. Mar 25 08:57:01 katarynka systemd[1]: mpd.socket: Deactivated successfully. Mar 25 08:57:01 katarynka systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Mar 25 08:57:01 katarynka systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Mar 25 08:57:01 katarynka sudo[13932]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 25 08:57:01 katarynka sudo[13932]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 08:57:01 katarynka volumio[13765]: info: UPNP Browser: Client initialized successfully Mar 25 08:57:01 katarynka systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Mar 25 08:57:01 katarynka systemd[1]: Starting mpd.service - Music Player Daemon... Mar 25 08:57:01 katarynka volumio[13765]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 08:57:02 katarynka volumio[13765]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 08:57:02 katarynka systemd[1]: mpd.service: Deactivated successfully. Mar 25 08:57:02 katarynka systemd[1]: Stopped mpd.service - Music Player Daemon. Mar 25 08:57:02 katarynka systemd[1]: mpd.socket: Deactivated successfully. Mar 25 08:57:02 katarynka systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Mar 25 08:57:02 katarynka systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Mar 25 08:57:02 katarynka volumio[13765]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 25 08:57:02 katarynka volumio[13765]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 08:57:02 katarynka volumio[13765]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 08:57:02 katarynka systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Mar 25 08:57:02 katarynka systemd[1]: Starting mpd.service - Music Player Daemon... Mar 25 08:57:02 katarynka volumio[13765]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 25 08:57:02 katarynka volumio[13765]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 25 08:57:02 katarynka volumio[13765]: info: [1774425422214] CoreMusicLibrary::Adding element Last_100 Mar 25 08:57:02 katarynka volumio[13765]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 25 08:57:02 katarynka volumio[13765]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 25 08:57:02 katarynka volumio[13765]: info: [1774425422225] CoreMusicLibrary::Adding element Webradio Mar 25 08:57:02 katarynka volumio[13765]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 25 08:57:02 katarynka volumio[13765]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 25 08:57:02 katarynka volumio[13765]: info: Initializing BBC Radios Mar 25 08:57:02 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Mar 25 08:57:02 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 08:57:02 katarynka volumio[13765]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 25 08:57:02 katarynka volumio[13765]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 08:57:02 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 08:57:02 katarynka go-librespot[13960]: go-librespot daemon starting... Mar 25 08:57:02 katarynka volumio[13765]: info: Creating Spotify config file Mar 25 08:57:02 katarynka volumio[13765]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 08:57:02 katarynka go-librespot[13961]: time="2026-03-25T08:57:02+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 08:57:02 katarynka volumio-remote-updater[622]: [2026-03-25 08:57:02] [connect] Successful connection Mar 25 08:57:02 katarynka sudo[13946]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Mar 25 08:57:02 katarynka sudo[13946]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Mar 25 08:57:02 katarynka sudo[13946]: pam_unix(sudo:session): session closed for user root Mar 25 08:57:03 katarynka go-librespot[13961]: time="2026-03-25T08:57:03+01:00" level=info msg="zeroconf server listening on port 33459" Mar 25 08:57:04 katarynka volumio[13765]: info: Volumio Calling Home Mar 25 08:57:04 katarynka volumio[13882]: Starting albumart workers Mar 25 08:57:04 katarynka volumio[13887]: Starting albumart workers Mar 25 08:57:05 katarynka volumio[13885]: Starting albumart workers Mar 25 08:57:05 katarynka sudo[13989]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 25 08:57:05 katarynka sudo[13989]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 08:57:05 katarynka volumio[13765]: info: Discovery: adding 4d616d77-6a8c-4da2-85a4-840d70f98e51 Mar 25 08:57:05 katarynka volumio[13765]: info: Discovery: Found device katarynka Mar 25 08:57:05 katarynka volumio[13765]: info: CoreCommandRouter::volumioGetState Mar 25 08:57:05 katarynka volumio[13765]: info: CorePlayQueue::getTrack 0 Mar 25 08:57:05 katarynka sudo[13989]: pam_unix(sudo:session): session closed for user root Mar 25 08:57:05 katarynka volumio[13765]: info: MPD Permissions set Mar 25 08:57:05 katarynka volumio[13765]: info: MPD Permissions set Mar 25 08:57:05 katarynka volumio[13765]: info: VolumeController:: Volume=96 Mute =false Mar 25 08:57:05 katarynka volumio[13765]: info: CoreStateMachine::pushState Mar 25 08:57:05 katarynka volumio[13765]: info: CorePlayQueue::getTrack 0 Mar 25 08:57:05 katarynka volumio[13765]: info: CoreCommandRouter::volumioPushState Mar 25 08:57:05 katarynka sudo[13991]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 25 08:57:05 katarynka volumio[13765]: info: Discovery: this is already registered, 4d616d77-6a8c-4da2-85a4-840d70f98e51 Mar 25 08:57:05 katarynka sudo[13991]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 08:57:05 katarynka volumio[13765]: info: Discovery: Found device katarynka Mar 25 08:57:05 katarynka volumio[13765]: info: CoreCommandRouter::volumioGetState Mar 25 08:57:05 katarynka volumio[13765]: info: CorePlayQueue::getTrack 0 Mar 25 08:57:05 katarynka sudo[13991]: pam_unix(sudo:session): session closed for user root Mar 25 08:57:05 katarynka volumio-remote-updater[622]: [2026-03-25 08:57:05] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1774425422 101 Mar 25 08:57:05 katarynka volumio[13765]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 1 Mar 25 08:57:05 katarynka volumio[13765]: info: Volumio called home Mar 25 08:57:05 katarynka volumio[13765]: info: Spotify config file written Mar 25 08:57:05 katarynka sudo[13995]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Mar 25 08:57:05 katarynka sudo[13995]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 08:57:05 katarynka volumio[13765]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Mar 25 08:57:05 katarynka volumio[13765]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 08:57:05 katarynka volumio[13765]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 08:57:05 katarynka volumio[13765]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 08:57:05 katarynka volumio[13765]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 08:57:05 katarynka volumio[13765]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 08:57:05 katarynka volumio[13765]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 08:57:05 katarynka volumio[13765]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 08:57:05 katarynka volumio[13765]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 08:57:05 katarynka volumio[13765]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 08:57:05 katarynka volumio[13765]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 08:57:05 katarynka volumio[13765]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 08:57:05 katarynka volumio[13765]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 08:57:05 katarynka volumio[13765]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 08:57:05 katarynka volumio[13765]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 08:57:05 katarynka volumio[13765]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 08:57:05 katarynka volumio[13765]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 08:57:05 katarynka volumio[13765]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 08:57:05 katarynka volumio[13765]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 08:57:05 katarynka systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Mar 25 08:57:05 katarynka systemd[1]: go-librespot-daemon.service: Deactivated successfully. Mar 25 08:57:05 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 08:57:05 katarynka volumio[13765]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 08:57:05 katarynka volumio[13765]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 08:57:05 katarynka volumio[13765]: info: No need to fix Spotify hosts Mar 25 08:57:05 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 08:57:05 katarynka go-librespot[14007]: go-librespot daemon starting... Mar 25 08:57:05 katarynka sudo[13995]: pam_unix(sudo:session): session closed for user root Mar 25 08:57:05 katarynka go-librespot[14008]: time="2026-03-25T08:57:05+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 08:57:05 katarynka go-librespot[14008]: time="2026-03-25T08:57:05+01:00" level=debug msg="app state loaded" Mar 25 08:57:05 katarynka go-librespot[14008]: time="2026-03-25T08:57:05+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 08:57:06 katarynka go-librespot[14008]: time="2026-03-25T08:57:06+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 25 08:57:06 katarynka go-librespot[14008]: time="2026-03-25T08:57:06+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 25 08:57:06 katarynka go-librespot[14008]: time="2026-03-25T08:57:06+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 25 08:57:06 katarynka go-librespot[14008]: time="2026-03-25T08:57:06+01:00" level=info msg="zeroconf server listening on port 38887" Mar 25 08:57:06 katarynka volumio[13765]: info: Starting Shairport Sync Mar 25 08:57:06 katarynka volumio[13765]: info: Starting Shairport Sync Mar 25 08:57:06 katarynka go-librespot[14008]: time="2026-03-25T08:57:06+01:00" level=debug msg="obtained new client token: AACOTak3mhmxxXTq1NtcISmxK0/4tGVjuT3nICJ/M1A1Ghg67G87azXVYfbIPg3ufFyV9nUtC+d8n1DcU5uG6sxA+0vTqMjsRaLR1WUEf7IRZ2GIY7b4G6Jr2wwzh/WQBmWwEm/romEFuAjex+Yc1kpjWEEeHFgeDiqiC7jc19wCkC4g0I8Z1hWJkVGr3/ke/Mk295N0N7Ogto0vAcfmWmdBDpnTIrh40NKdVnCvtXwQMCQc/zh0CQgyRdI=" Mar 25 08:57:06 katarynka volumio[13765]: info: Starting Shairport Sync Mar 25 08:57:06 katarynka sudo[14022]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 25 08:57:06 katarynka go-librespot[14008]: time="2026-03-25T08:57:06+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 08:57:06 katarynka sudo[14022]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 08:57:06 katarynka sudo[14024]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 25 08:57:06 katarynka sudo[14024]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 08:57:06 katarynka go-librespot[14008]: time="2026-03-25T08:57:06+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Mar 25 08:57:06 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 08:57:06 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 08:57:06 katarynka sudo[14030]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Mar 25 08:57:06 katarynka sudo[14026]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 25 08:57:06 katarynka sudo[14030]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 08:57:06 katarynka sudo[14026]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 08:57:07 katarynka systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Mar 25 08:57:07 katarynka systemd[1]: shairport-sync.service: Deactivated successfully. Mar 25 08:57:07 katarynka systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 25 08:57:07 katarynka systemd[1]: shairport-sync.service: Consumed 2.295s CPU time. Mar 25 08:57:07 katarynka systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 25 08:57:07 katarynka sudo[14024]: pam_unix(sudo:session): session closed for user root Mar 25 08:57:07 katarynka sudo[14022]: pam_unix(sudo:session): session closed for user root Mar 25 08:57:07 katarynka sudo[14030]: pam_unix(sudo:session): session closed for user root Mar 25 08:57:07 katarynka systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Mar 25 08:57:07 katarynka systemd[1]: shairport-sync.service: Deactivated successfully. Mar 25 08:57:07 katarynka systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 25 08:57:07 katarynka systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 25 08:57:07 katarynka sudo[14026]: pam_unix(sudo:session): session closed for user root Mar 25 08:57:07 katarynka volumio[13765]: info: An error occurred while refreshing Spotify Token Error: Bad Request Mar 25 08:57:07 katarynka volumio[13765]: info: Shairport-Sync Started Mar 25 08:57:07 katarynka volumio[13765]: Error adding Membership: Error: addMembership EINVAL Mar 25 08:57:07 katarynka volumio[13765]: info: Upmpdcli Daemon Started Mar 25 08:57:07 katarynka volumio[13765]: info: Shairport-Sync Started Mar 25 08:57:07 katarynka volumio[13765]: info: Shairport-Sync Started Mar 25 08:57:07 katarynka volumio[13765]: info: CoreCommandRouter::volumioGetState Mar 25 08:57:07 katarynka volumio[13765]: info: CorePlayQueue::getTrack 0 Mar 25 08:57:09 katarynka volumio[13765]: info: go-librespot daemon successfully initialized Mar 25 08:57:10 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Mar 25 08:57:10 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 08:57:10 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 08:57:10 katarynka go-librespot[14062]: go-librespot daemon starting... Mar 25 08:57:10 katarynka go-librespot[14063]: time="2026-03-25T08:57:10+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 08:57:10 katarynka go-librespot[14063]: time="2026-03-25T08:57:10+01:00" level=debug msg="app state loaded" Mar 25 08:57:10 katarynka go-librespot[14063]: time="2026-03-25T08:57:10+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 08:57:10 katarynka mpd[13968]: 2026-03-25T08:57:10 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Mar 25 08:57:10 katarynka systemd[1]: Started mpd.service - Music Player Daemon. Mar 25 08:57:10 katarynka sudo[13932]: pam_unix(sudo:session): session closed for user root Mar 25 08:57:10 katarynka sudo[13922]: pam_unix(sudo:session): session closed for user root Mar 25 08:57:10 katarynka volumio[13765]: info: Completed starting Core Plugins Mar 25 08:57:10 katarynka volumio[13765]: info: ------------------------------------------- Mar 25 08:57:10 katarynka volumio[13765]: info: ----- MyVolumio plugins startup ---- Mar 25 08:57:10 katarynka volumio[13765]: info: ------------------------------------------- Mar 25 08:57:10 katarynka volumio[13765]: info: [MyVolumio PluginManager] Fetching plans data.... Mar 25 08:57:10 katarynka volumio[13765]: error: MPD error: The expression evaluated to a falsy value: Mar 25 08:57:10 katarynka volumio[13765]: assert.ok(self.idling) Mar 25 08:57:10 katarynka volumio[13765]: error: The expression evaluated to a falsy value: Mar 25 08:57:10 katarynka volumio[13765]: assert.ok(self.idling) Mar 25 08:57:10 katarynka volumio[13765]: error: updateQueue error: null Mar 25 08:57:10 katarynka volumio[13765]: info: MPD running with PID13968 Mar 25 08:57:10 katarynka volumio[13765]: ,establishing connection Mar 25 08:57:10 katarynka volumio[13765]: error: updateQueue error: null Mar 25 08:57:10 katarynka go-librespot[14063]: time="2026-03-25T08:57:10+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Mar 25 08:57:10 katarynka go-librespot[14063]: time="2026-03-25T08:57:10+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Mar 25 08:57:10 katarynka go-librespot[14063]: time="2026-03-25T08:57:10+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Mar 25 08:57:10 katarynka go-librespot[14063]: time="2026-03-25T08:57:10+01:00" level=info msg="zeroconf server listening on port 42691" Mar 25 08:57:10 katarynka go-librespot[14063]: time="2026-03-25T08:57:10+01:00" level=debug msg="obtained new client token: AADqm/43qibZ5yhntxMLbT0muCg+3v9PVCgpz5vn4XUOG1qpd0EA5T2go+BzzJInqShiROQZnorQIe/1ejH2ATGjwWY9JmbyWSKbU9cQ1XaZLL9WtxzGuR6B84CQgPCTDKmAFFqy1BxeHOo3xeNY17cPOMii+IONlmfgmd5rV+/td3WQ1UL9bbyddN3G+rGotb1ljaA/fAyMS2nTS6/0CUlrq7a/F2cSCiyHg/m2dCW1EtzhmxMx3BTsUBM=" Mar 25 08:57:10 katarynka go-librespot[14063]: time="2026-03-25T08:57:10+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 08:57:10 katarynka go-librespot[14063]: time="2026-03-25T08:57:10+01:00" level=debug msg="completed keyexchange" Mar 25 08:57:10 katarynka go-librespot[14063]: time="2026-03-25T08:57:10+01:00" level=debug msg="completed challenge" Mar 25 08:57:11 katarynka go-librespot[14063]: time="2026-03-25T08:57:11+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 25 08:57:11 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 08:57:11 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 08:57:12 katarynka volumio[13765]: info: Initializing connection to go-librespot Websocket Mar 25 08:57:12 katarynka volumio[13765]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 25 08:57:13 katarynka sudo[14082]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Mar 25 08:57:13 katarynka sudo[14082]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 08:57:13 katarynka sudo[14094]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Mar 25 08:57:13 katarynka sudo[14094]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 08:57:13 katarynka systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Mar 25 08:57:13 katarynka systemd[1]: mpd_monitor.service: Deactivated successfully. Mar 25 08:57:13 katarynka systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Mar 25 08:57:13 katarynka systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Mar 25 08:57:13 katarynka sudo[14082]: pam_unix(sudo:session): session closed for user root Mar 25 08:57:13 katarynka sudo[14094]: pam_unix(sudo:session): session closed for user root Mar 25 08:57:13 katarynka mpd_monitor.sh[14098]: MPD Monitor Service: Starting MPD Monitor Service Mar 25 08:57:13 katarynka volumio[13765]: info: Successfully started MPD Monitor Mar 25 08:57:13 katarynka volumio[13765]: info: Successfully started MPD Monitor Mar 25 08:57:14 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Mar 25 08:57:14 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 08:57:14 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 08:57:14 katarynka go-librespot[14102]: go-librespot daemon starting... Mar 25 08:57:14 katarynka go-librespot[14103]: time="2026-03-25T08:57:14+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 08:57:14 katarynka go-librespot[14103]: time="2026-03-25T08:57:14+01:00" level=debug msg="app state loaded" Mar 25 08:57:14 katarynka go-librespot[14103]: time="2026-03-25T08:57:14+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 08:57:14 katarynka go-librespot[14103]: time="2026-03-25T08:57:14+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Mar 25 08:57:14 katarynka go-librespot[14103]: time="2026-03-25T08:57:14+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Mar 25 08:57:14 katarynka go-librespot[14103]: time="2026-03-25T08:57:14+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Mar 25 08:57:14 katarynka go-librespot[14103]: time="2026-03-25T08:57:14+01:00" level=info msg="zeroconf server listening on port 36619" Mar 25 08:57:14 katarynka go-librespot[14103]: time="2026-03-25T08:57:14+01:00" level=debug msg="obtained new client token: AADaCUoUUQmdpFpCZdVl1z1ObveoF+LwzEyla3X/+H0HOsRuKJG20VCf0EER2nZPATtJNHN6va4Y2eZHiuxlBkMfZgkehSpz1c1RfQ1lc4ZEpJLxp4Mh5UIjfNLPRNYHdVkrAKgkrZjtO91fjR+vqnqqIx+FgtGWoPPuPyBwonSNrwnJNaasYEXwjQhcGUryuoOhO+JQpROAIZO9STmLXDzTiageDW9K6hOcWo1jqFvS3bgleKvQiTo6s/E=" Mar 25 08:57:14 katarynka go-librespot[14103]: time="2026-03-25T08:57:14+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 08:57:14 katarynka go-librespot[14103]: time="2026-03-25T08:57:14+01:00" level=debug msg="completed keyexchange" Mar 25 08:57:14 katarynka go-librespot[14103]: time="2026-03-25T08:57:14+01:00" level=debug msg="completed challenge" Mar 25 08:57:15 katarynka go-librespot[14103]: time="2026-03-25T08:57:15+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 25 08:57:15 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 08:57:15 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 08:57:15 katarynka volumio[13765]: info: Initializing connection to go-librespot Websocket Mar 25 08:57:15 katarynka volumio[13765]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 25 08:57:15 katarynka volumio[13765]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Mar 25 08:57:18 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Mar 25 08:57:18 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 08:57:18 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 08:57:18 katarynka go-librespot[14110]: go-librespot daemon starting... Mar 25 08:57:18 katarynka go-librespot[14111]: time="2026-03-25T08:57:18+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 08:57:18 katarynka go-librespot[14111]: time="2026-03-25T08:57:18+01:00" level=debug msg="app state loaded" Mar 25 08:57:18 katarynka go-librespot[14111]: time="2026-03-25T08:57:18+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 08:57:18 katarynka volumio[13765]: info: Initializing connection to go-librespot Websocket Mar 25 08:57:18 katarynka go-librespot[14111]: time="2026-03-25T08:57:18+01:00" level=debug msg="new websocket client" Mar 25 08:57:18 katarynka volumio[13765]: info: Connection to go-librespot Websocket established Mar 25 08:57:18 katarynka go-librespot[14111]: time="2026-03-25T08:57:18+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 25 08:57:18 katarynka go-librespot[14111]: time="2026-03-25T08:57:18+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 25 08:57:18 katarynka go-librespot[14111]: time="2026-03-25T08:57:18+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 25 08:57:18 katarynka go-librespot[14111]: time="2026-03-25T08:57:18+01:00" level=info msg="zeroconf server listening on port 45267" Mar 25 08:57:18 katarynka go-librespot[14111]: time="2026-03-25T08:57:18+01:00" level=debug msg="obtained new client token: AADU9TnDUsYS7KlUrS0/EzuDkF3uEJNyc/v80dNLLSVtd5+AKMDkAr3k7O16TlZaXAUs4pd0VwGAKp4kaFhBbajF/8UjJlcsI9vfq2pd7CgbWNoa5fNzmOQiR4TCh1HteYs7ibAaCs5Jt73emkG/7FObcKs7y6dX//kfbalxsoGq96InEd6L65qpHWzWdOxg5C5NDhNMmKr0mors7AaVTQW8eYZlyRLq8vlPwQ0J5RtcYLSNAzIj/CwKegY=" Mar 25 08:57:18 katarynka volumio[13765]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Mar 25 08:57:18 katarynka volumio[13765]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Mar 25 08:57:18 katarynka volumio[13765]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Mar 25 08:57:18 katarynka volumio[13765]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Mar 25 08:57:18 katarynka volumio[13765]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Mar 25 08:57:18 katarynka volumio[13765]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Mar 25 08:57:18 katarynka volumio[13765]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Mar 25 08:57:18 katarynka volumio[13765]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Mar 25 08:57:18 katarynka volumio[13765]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Mar 25 08:57:18 katarynka volumio[13765]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Mar 25 08:57:18 katarynka volumio[13765]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Mar 25 08:57:18 katarynka volumio[13765]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Mar 25 08:57:18 katarynka volumio[13765]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Mar 25 08:57:18 katarynka volumio[13765]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Mar 25 08:57:18 katarynka volumio[13765]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Mar 25 08:57:18 katarynka volumio[13765]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Mar 25 08:57:18 katarynka volumio[13765]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Mar 25 08:57:18 katarynka volumio[13765]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Mar 25 08:57:18 katarynka volumio[13765]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Mar 25 08:57:18 katarynka volumio[13765]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Mar 25 08:57:18 katarynka volumio[13765]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Mar 25 08:57:18 katarynka volumio[13765]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Mar 25 08:57:18 katarynka volumio[13765]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Mar 25 08:57:18 katarynka volumio[13765]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Mar 25 08:57:18 katarynka volumio[13765]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Mar 25 08:57:18 katarynka volumio[13765]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Mar 25 08:57:18 katarynka volumio[13765]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Mar 25 08:57:18 katarynka volumio[13765]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Mar 25 08:57:18 katarynka volumio[13765]: info: Adding plugin bluetooth to MyMusic Plugins Mar 25 08:57:18 katarynka volumio[13765]: info: Adding plugin multiroom to MyMusic Plugins Mar 25 08:57:18 katarynka go-librespot[14111]: time="2026-03-25T08:57:18+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 08:57:18 katarynka volumio[13765]: info: Adding plugin metavolumio to MyMusic Plugins Mar 25 08:57:18 katarynka volumio[13765]: info: Adding plugin cd_controller to MyMusic Plugins Mar 25 08:57:18 katarynka volumio[13765]: info: Adding plugin qobuzconnect to MyMusic Plugins Mar 25 08:57:18 katarynka volumio[13765]: info: Adding plugin smart_inputs to MyMusic Plugins Mar 25 08:57:18 katarynka volumio[13765]: info: Adding plugin tidalconnect to MyMusic Plugins Mar 25 08:57:18 katarynka volumio[13765]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Mar 25 08:57:18 katarynka go-librespot[14111]: time="2026-03-25T08:57:18+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Mar 25 08:57:18 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 08:57:18 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 08:57:20 katarynka volumio[13765]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Mar 25 08:57:20 katarynka volumio[13765]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Mar 25 08:57:20 katarynka volumio[13765]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 08:57:20 katarynka volumio[13765]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 08:57:20 katarynka volumio[13765]: info: Starting MyVolumio Remote Streaming Endpoints Mar 25 08:57:20 katarynka volumio[13765]: info: MyVolumio login type: Token Mar 25 08:57:21 katarynka volumio[13765]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Mar 25 08:57:21 katarynka volumio[13765]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Mar 25 08:57:22 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Mar 25 08:57:22 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 08:57:22 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 08:57:22 katarynka go-librespot[14118]: go-librespot daemon starting... Mar 25 08:57:22 katarynka go-librespot[14119]: time="2026-03-25T08:57:22+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 08:57:22 katarynka go-librespot[14119]: time="2026-03-25T08:57:22+01:00" level=debug msg="app state loaded" Mar 25 08:57:22 katarynka go-librespot[14119]: time="2026-03-25T08:57:22+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 08:57:22 katarynka go-librespot[14119]: time="2026-03-25T08:57:22+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 25 08:57:22 katarynka go-librespot[14119]: time="2026-03-25T08:57:22+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 25 08:57:22 katarynka go-librespot[14119]: time="2026-03-25T08:57:22+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 25 08:57:22 katarynka go-librespot[14119]: time="2026-03-25T08:57:22+01:00" level=info msg="zeroconf server listening on port 43777" Mar 25 08:57:22 katarynka volumio[13765]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Mar 25 08:57:22 katarynka volumio[13765]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Mar 25 08:57:22 katarynka volumio[13765]: info: Streaming services startup Mar 25 08:57:22 katarynka volumio[13765]: info: Starting Streaming Daemon Mar 25 08:57:22 katarynka sudo[14127]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Mar 25 08:57:22 katarynka sudo[14127]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 08:57:22 katarynka go-librespot[14119]: time="2026-03-25T08:57:22+01:00" level=debug msg="obtained new client token: AACEBiOwpgo/didl4O+KmsHXASl9fpNBU4aLxEG7JHrcAeB2rja3pu6xkUkWmWWenqviR4967nBfNGV9F/xT0LeCT9SbdcTxSDoUvbngr0t3zna0piGV/pD1dYuV0LFVGMrBYrtf2XEnxCPzBuqRxmNzJOeDJCx2cZeaDqmiMb5OM0YOZuyR/pQgy0piBwroF2wvVqtjcYK/A1arKu124fm1+V6XxYLW/x6KI423HJj8PVEh8qa1AJ7jt0M=" Mar 25 08:57:22 katarynka volumio[13765]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Mar 25 08:57:22 katarynka go-librespot[14119]: time="2026-03-25T08:57:22+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 08:57:22 katarynka sudo[14127]: pam_unix(sudo:session): session closed for user root Mar 25 08:57:23 katarynka go-librespot[14119]: time="2026-03-25T08:57:23+01:00" level=debug msg="completed keyexchange" Mar 25 08:57:23 katarynka go-librespot[14119]: time="2026-03-25T08:57:23+01:00" level=debug msg="completed challenge" Mar 25 08:57:23 katarynka volumio[13765]: info: Getting Spotify volume Mar 25 08:57:23 katarynka go-librespot[14119]: time="2026-03-25T08:57:23+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 25 08:57:23 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 08:57:23 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 08:57:23 katarynka volumio[13765]: info: Connection to go-librespot Websocket closed Mar 25 08:57:23 katarynka volumio[13765]: error: Cannot start Volumio Streaming Daemon Mar 25 08:57:23 katarynka volumio[13765]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Mar 25 08:57:23 katarynka volumio[13765]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Mar 25 08:57:23 katarynka volumio[13765]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 25 08:57:23 katarynka volumio[13765]: Error: socket hang up Mar 25 08:57:23 katarynka volumio[13765]: at connResetException (node:internal/errors:720:14) Mar 25 08:57:23 katarynka volumio[13765]: at Socket.socketOnEnd (node:_http_client:519:23) Mar 25 08:57:23 katarynka volumio[13765]: at Socket.emit (node:events:526:35) Mar 25 08:57:23 katarynka volumio[13765]: at endReadableNT (node:internal/streams/readable:1376:12) Mar 25 08:57:23 katarynka volumio[13765]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Mar 25 08:57:23 katarynka volumio[13765]: code: 'ECONNRESET', Mar 25 08:57:23 katarynka volumio[13765]: response: undefined Mar 25 08:57:23 katarynka volumio[13765]: } Mar 25 08:57:23 katarynka volumio[13765]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 25 08:57:24 katarynka sudo[14161]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-03-25 08:56' Mar 25 08:57:24 katarynka sudo[14161]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 08:57:24 katarynka sudo[14161]: pam_unix(sudo:session): session closed for user root Mar 25 08:57:25 katarynka volumio-remote-updater[622]: [2026-03-25 08:57:25] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Mar 25 08:57:25 katarynka volumio-remote-updater[622]: [2026-03-25 08:57:25] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Mar 25 08:57:25 katarynka systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Mar 25 08:57:25 katarynka systemd[1]: volumio.service: Failed with result 'exit-code'. Mar 25 08:57:25 katarynka systemd[1]: volumio.service: Consumed 48.941s CPU time. Mar 25 08:57:25 katarynka systemd[1]: Started dynamicswap.service - dynamicswap service. Mar 25 08:57:25 katarynka systemd[1]: dynamicswap.service: Deactivated successfully. Mar 25 08:57:25 katarynka systemd[1]: volumio.service: Scheduled restart job, restart counter is at 26176. Mar 25 08:57:25 katarynka systemd[1]: Started dynamicswap.service - dynamicswap service. Mar 25 08:57:25 katarynka systemd[1]: Stopped volumio.service - Volumio Backend Module. Mar 25 08:57:25 katarynka systemd[1]: volumio.service: Consumed 48.941s CPU time. Mar 25 08:57:25 katarynka systemd[1]: Started volumio.service - Volumio Backend Module. Mar 25 08:57:25 katarynka systemd[1]: dynamicswap.service: Deactivated successfully. Mar 25 08:57:26 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Mar 25 08:57:26 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 08:57:26 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 08:57:26 katarynka go-librespot[14192]: go-librespot daemon starting... Mar 25 08:57:26 katarynka go-librespot[14193]: time="2026-03-25T08:57:26+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 08:57:26 katarynka go-librespot[14193]: time="2026-03-25T08:57:26+01:00" level=debug msg="app state loaded" Mar 25 08:57:26 katarynka go-librespot[14193]: time="2026-03-25T08:57:26+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 08:57:26 katarynka go-librespot[14193]: time="2026-03-25T08:57:26+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 25 08:57:26 katarynka go-librespot[14193]: time="2026-03-25T08:57:26+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 25 08:57:26 katarynka go-librespot[14193]: time="2026-03-25T08:57:26+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 25 08:57:26 katarynka go-librespot[14193]: time="2026-03-25T08:57:26+01:00" level=info msg="zeroconf server listening on port 35675" Mar 25 08:57:26 katarynka go-librespot[14193]: time="2026-03-25T08:57:26+01:00" level=debug msg="obtained new client token: AADsW3++Pj00PLDv6kLjqlVEr9deT7QwxZhq3LWyTdV0/QR7V9iZ7Cs5E2kpeqWPt57b2NnAczn0UQnY4MWwgN3J9MI51uYwBPq86orQPJ3AdyOZAIbQGoKRd/eMhD8wIumgZI8Ic43XhyWVu4Tha7jCmJx8ledVLEZCrG1+qYj/Sobe2g4sPKKu2KqGxQ2jWuEvzZPHtyRHSMZCc4QuuCuYTpSg7hGn2t+L9C1lK9ndiURSGoWvgdOXrRo=" Mar 25 08:57:26 katarynka go-librespot[14193]: time="2026-03-25T08:57:26+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 08:57:26 katarynka go-librespot[14193]: time="2026-03-25T08:57:26+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Mar 25 08:57:27 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 08:57:27 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 08:57:29 katarynka volumio[14177]: info: ------------------------------------------- Mar 25 08:57:29 katarynka volumio[14177]: info: ----- Volumio3 ---- Mar 25 08:57:29 katarynka volumio[14177]: info: ------------------------------------------- Mar 25 08:57:29 katarynka volumio[14177]: info: ----- System startup ---- Mar 25 08:57:29 katarynka volumio[14177]: info: ------------------------------------------- Mar 25 08:57:30 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Mar 25 08:57:30 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 08:57:30 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 08:57:30 katarynka go-librespot[14206]: go-librespot daemon starting... Mar 25 08:57:30 katarynka go-librespot[14207]: time="2026-03-25T08:57:30+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 08:57:30 katarynka go-librespot[14207]: time="2026-03-25T08:57:30+01:00" level=debug msg="app state loaded" Mar 25 08:57:30 katarynka go-librespot[14207]: time="2026-03-25T08:57:30+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 08:57:30 katarynka volumio-remote-updater[622]: [2026-03-25 08:57:30] [connect] Successful connection Mar 25 08:57:30 katarynka go-librespot[14207]: time="2026-03-25T08:57:30+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 25 08:57:30 katarynka go-librespot[14207]: time="2026-03-25T08:57:30+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 25 08:57:30 katarynka go-librespot[14207]: time="2026-03-25T08:57:30+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 25 08:57:30 katarynka go-librespot[14207]: time="2026-03-25T08:57:30+01:00" level=info msg="zeroconf server listening on port 39205" Mar 25 08:57:30 katarynka go-librespot[14207]: time="2026-03-25T08:57:30+01:00" level=debug msg="obtained new client token: AAC3cazI10fkPokiGigUq/DGwdtTGs2WWLobJ5jkqqGrixJtRtZaJXfFvmwiakrV3em+OEfzojAoV0Bhb2oyxd5FNN9RQwb+BzPg0tSHxEINEAe/PXqYG4bTBsohS54U8uWZs9nTPKTikzq7bcYvALdx5hWSkrW55f1RUqA1EaaETfCSft/y7+bziNPMgSdQmTbpDTrP3XGfgBi4FuCDpchKirzcXmzTMlu4UDgVYah5ADN4ia77Mj5D2YQ=" Mar 25 08:57:30 katarynka go-librespot[14207]: time="2026-03-25T08:57:30+01:00" level=warning msg="failed to connect to AP ap-gew4.spotify.com:4070, retrying with a different AP" error="dial tcp 34.158.1.133:4070: connect: connection refused" Mar 25 08:57:31 katarynka volumio[14177]: info: MYVOLUMIO Environment detected Mar 25 08:57:31 katarynka volumio[14177]: info: Plugin folders cleanup Mar 25 08:57:31 katarynka volumio[14177]: info: Scanning into folder /volumio/app/plugins/ Mar 25 08:57:31 katarynka volumio[14177]: info: Scanning category audio_interface Mar 25 08:57:31 katarynka volumio[14177]: info: Scanning category miscellanea Mar 25 08:57:31 katarynka volumio[14177]: info: Scanning category music_service Mar 25 08:57:31 katarynka volumio[14177]: info: Scanning category plugins.json Mar 25 08:57:31 katarynka volumio[14177]: info: Scanning category system_controller Mar 25 08:57:31 katarynka volumio[14177]: info: Scanning category user_interface Mar 25 08:57:31 katarynka volumio[14177]: info: Scanning into folder /data/plugins/ Mar 25 08:57:31 katarynka volumio[14177]: info: Scanning category music_service Mar 25 08:57:31 katarynka volumio[14177]: info: Plugin folders cleanup completed Mar 25 08:57:31 katarynka volumio[14177]: info: ------------------------------------------- Mar 25 08:57:31 katarynka volumio[14177]: info: ----- Core plugins startup ---- Mar 25 08:57:31 katarynka volumio[14177]: info: ------------------------------------------- Mar 25 08:57:31 katarynka volumio[14177]: info: Loading plugins from folder /volumio/app/plugins/ Mar 25 08:57:31 katarynka volumio[14177]: info: Adding plugin upnp to MyMusic Plugins Mar 25 08:57:31 katarynka volumio[14177]: info: Adding plugin airplay_emulation to MyMusic Plugins Mar 25 08:57:31 katarynka volumio[14177]: info: Adding plugin upnp_browser to MyMusic Plugins Mar 25 08:57:31 katarynka volumio[14177]: info: Loading plugins from folder /data/plugins/ Mar 25 08:57:31 katarynka volumio[14177]: info: Loading plugin "system"... Mar 25 08:57:31 katarynka volumio[14177]: info: Loading plugin "appearance"... Mar 25 08:57:32 katarynka go-librespot[14207]: time="2026-03-25T08:57:32+01:00" level=debug msg="connected to ap-gew4.spotify.com:443" Mar 25 08:57:32 katarynka go-librespot[14207]: time="2026-03-25T08:57:32+01:00" level=debug msg="completed keyexchange" Mar 25 08:57:32 katarynka go-librespot[14207]: time="2026-03-25T08:57:32+01:00" level=debug msg="completed challenge" Mar 25 08:57:32 katarynka go-librespot[14207]: time="2026-03-25T08:57:32+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 25 08:57:32 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 08:57:32 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 08:57:33 katarynka volumio[14177]: info: Loading plugin "network"... Mar 25 08:57:33 katarynka volumio[14177]: info: Refreshing Cached IP Addresses Mar 25 08:57:33 katarynka sudo[14223]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 25 08:57:33 katarynka sudo[14223]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 08:57:33 katarynka sudo[14225]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 25 08:57:33 katarynka volumio[14177]: info: Loading plugin "services"... Mar 25 08:57:33 katarynka sudo[14225]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 08:57:33 katarynka sudo[14223]: pam_unix(sudo:session): session closed for user root Mar 25 08:57:33 katarynka sudo[14225]: pam_unix(sudo:session): session closed for user root Mar 25 08:57:33 katarynka volumio[14177]: info: Loading plugin "alsa_controller"... Mar 25 08:57:33 katarynka sudo[14233]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Mar 25 08:57:33 katarynka sudo[14233]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 08:57:33 katarynka volumio[14177]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 25 08:57:33 katarynka volumio[14177]: info: Loading plugin "wizard"... Mar 25 08:57:33 katarynka volumio[14177]: info: Loading plugin "networkfs"... Mar 25 08:57:33 katarynka volumio[14177]: info: Starting Udev Watcher for removable devices Mar 25 08:57:33 katarynka volumio[14177]: info: Ignoring mount for partition: boot Mar 25 08:57:33 katarynka volumio[14177]: info: Ignoring mount for partition: volumio Mar 25 08:57:33 katarynka volumio[14177]: info: Ignoring mount for partition: volumio_data Mar 25 08:57:33 katarynka volumio[14177]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 25 08:57:33 katarynka volumio[14177]: info: Loading plugin "volumio_command_line_client"... Mar 25 08:57:33 katarynka volumio[14177]: info: Loading plugin "upnp"... Mar 25 08:57:33 katarynka volumio[14177]: info: [1774425453904] Starting Upmpd Daemon Mar 25 08:57:33 katarynka volumio[14177]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 25 08:57:33 katarynka volumio[14177]: info: Loading plugin "my_music"... Mar 25 08:57:33 katarynka volumio[14177]: info: Loading plugin "mpd"... Mar 25 08:57:34 katarynka sudo[14233]: pam_unix(sudo:session): session closed for user root Mar 25 08:57:34 katarynka volumio[14177]: info: Loading plugin "upnp_browser"... Mar 25 08:57:35 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Mar 25 08:57:35 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 08:57:35 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 08:57:35 katarynka go-librespot[14259]: go-librespot daemon starting... Mar 25 08:57:35 katarynka go-librespot[14260]: time="2026-03-25T08:57:35+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 08:57:35 katarynka go-librespot[14260]: time="2026-03-25T08:57:35+01:00" level=debug msg="app state loaded" Mar 25 08:57:35 katarynka go-librespot[14260]: time="2026-03-25T08:57:35+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 08:57:35 katarynka go-librespot[14260]: time="2026-03-25T08:57: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 25 08:57:35 katarynka go-librespot[14260]: time="2026-03-25T08:57: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 25 08:57:35 katarynka go-librespot[14260]: time="2026-03-25T08:57: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 25 08:57:36 katarynka go-librespot[14260]: time="2026-03-25T08:57:36+01:00" level=info msg="zeroconf server listening on port 34513" Mar 25 08:57:36 katarynka go-librespot[14260]: time="2026-03-25T08:57:36+01:00" level=debug msg="obtained new client token: AADeDMeoh8jm9CCx/nY8k0opr+yq49p43gMLZtzjGXN6z31xvkUEamMhYXc+VyXXei7s5SJ5NF2GJV7oh/iPPbTi6EFrY+QJZiWQLOtoZgitGs46SqFl5ZzJTQesH+s5cs72SrVsgTBOnY1Ki9QsfPx/clfmuGNzqO/Rw8ojzqALN4d4oitWOoNk7999WNSorkjMtkRNbxkSwGMDAe+7muqUj5wqTplc/pYLNo+Vwjn8OtAjgbQ3I1Tn" Mar 25 08:57:36 katarynka go-librespot[14260]: time="2026-03-25T08:57:36+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 08:57:36 katarynka go-librespot[14260]: time="2026-03-25T08:57:36+01:00" level=debug msg="completed keyexchange" Mar 25 08:57:36 katarynka go-librespot[14260]: time="2026-03-25T08:57:36+01:00" level=debug msg="completed challenge" Mar 25 08:57:36 katarynka go-librespot[14260]: time="2026-03-25T08:57:36+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 25 08:57:36 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 08:57:36 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 08:57:37 katarynka volumio[14177]: info: Starting UPNP Browser Mar 25 08:57:37 katarynka volumio[14177]: info: Loading plugin "alarm-clock"... Mar 25 08:57:38 katarynka volumio[14177]: info: Loading plugin "airplay_emulation"... Mar 25 08:57:38 katarynka volumio[14177]: info: Starting Shairport Sync Mar 25 08:57:38 katarynka volumio[14177]: info: Loading plugin "last_100"... Mar 25 08:57:38 katarynka volumio[14177]: info: Loading plugin "webradio"... Mar 25 08:57:38 katarynka volumio[14177]: info: Loading plugin "i2s_dacs"... Mar 25 08:57:38 katarynka volumio[14177]: info: Loading plugin "volumiodiscovery"... Mar 25 08:57:38 katarynka volumio[14177]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Mar 25 08:57:38 katarynka volumio[14177]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 25 08:57:38 katarynka volumio[14177]: *** WARNING *** For more information see Mar 25 08:57:38 katarynka volumio[14177]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Mar 25 08:57:38 katarynka volumio[14177]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 25 08:57:38 katarynka volumio[14177]: *** WARNING *** For more information see Mar 25 08:57:38 katarynka node[14177]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Mar 25 08:57:38 katarynka node[14177]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 25 08:57:38 katarynka node[14177]: *** WARNING *** For more information see Mar 25 08:57:38 katarynka node[14177]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Mar 25 08:57:38 katarynka node[14177]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 25 08:57:38 katarynka node[14177]: *** WARNING *** For more information see Mar 25 08:57:38 katarynka volumio[14177]: info: Applying required configuration parameters for plugin volumiodiscovery Mar 25 08:57:38 katarynka volumio[14177]: info: Discovery: Started advertising with name: katarynka Mar 25 08:57:38 katarynka volumio[14177]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 25 08:57:38 katarynka volumio[14177]: info: Loading plugin "spop"... Mar 25 08:57:39 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Mar 25 08:57:39 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 08:57:39 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 08:57:39 katarynka go-librespot[14270]: go-librespot daemon starting... Mar 25 08:57:39 katarynka go-librespot[14271]: time="2026-03-25T08:57:39+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 08:57:39 katarynka go-librespot[14271]: time="2026-03-25T08:57:39+01:00" level=debug msg="app state loaded" Mar 25 08:57:39 katarynka go-librespot[14271]: time="2026-03-25T08:57:39+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 08:57:39 katarynka go-librespot[14271]: time="2026-03-25T08:57:39+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 25 08:57:39 katarynka go-librespot[14271]: time="2026-03-25T08:57:39+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 25 08:57:39 katarynka go-librespot[14271]: time="2026-03-25T08:57:39+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 25 08:57:40 katarynka go-librespot[14271]: time="2026-03-25T08:57:40+01:00" level=info msg="zeroconf server listening on port 42817" Mar 25 08:57:40 katarynka go-librespot[14271]: time="2026-03-25T08:57:40+01:00" level=debug msg="obtained new client token: AAA9OvrEydjkiMWU0KuiUz/NDJHZ5xAVTsrUtMg8yQu1buSpD8ZDhKcWxGAmy1qusov748xtjS4mM2t0md4SxTv4cCGoOq04QWn/Q6ED489nWyOQasdHLnWvRP88eOfqbiaxCFNGHFpItusmeazwrYisENNSGFUvgoXkCAbRBoIM7+K1JEtruFhDCTuGKLNWUCu69CXzK3hXrsiQ8sAerGhCL8HWRyRNPVoYUJfQoD5i6uX9zaOnR2y9" Mar 25 08:57:40 katarynka go-librespot[14271]: time="2026-03-25T08:57:40+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 08:57:40 katarynka go-librespot[14271]: time="2026-03-25T08:57:40+01:00" level=debug msg="completed keyexchange" Mar 25 08:57:40 katarynka go-librespot[14271]: time="2026-03-25T08:57:40+01:00" level=debug msg="completed challenge" Mar 25 08:57:40 katarynka go-librespot[14271]: time="2026-03-25T08:57:40+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 25 08:57:40 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 08:57:40 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 08:57:40 katarynka volumio[14177]: info: Loading plugin "outputs"... Mar 25 08:57:40 katarynka volumio[14177]: info: Loading plugin "albumart"... Mar 25 08:57:40 katarynka volumio[14177]: info: Plugin example_plugin is not enabled Mar 25 08:57:40 katarynka volumio[14177]: info: Loading plugin "inputs"... Mar 25 08:57:40 katarynka volumio[14177]: info: Loading plugin "updater_comm"... Mar 25 08:57:40 katarynka volumio[14177]: info: Plugin mpdemulation is not enabled Mar 25 08:57:40 katarynka volumio[14177]: info: Loading plugin "rest_api"... Mar 25 08:57:40 katarynka volumio[14177]: info: Loading plugin "websocket"... Mar 25 08:57:40 katarynka volumio[14177]: info: Starting Socket.io Server version 1.7.4 Mar 25 08:57:40 katarynka volumio[14177]: info: Loading i18n strings for locale pl Mar 25 08:57:40 katarynka volumio[14177]: Updating browse sources language Mar 25 08:57:40 katarynka volumio[14177]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 25 08:57:41 katarynka volumio[14177]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 25 08:57:41 katarynka volumio[14177]: info: CoreCommandRouter::initPlayerControls Mar 25 08:57:41 katarynka volumio[14177]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 08:57:41 katarynka volumio[14177]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 08:57:41 katarynka volumio[14177]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 08:57:41 katarynka volumio[14177]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 08:57:41 katarynka volumio[14177]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 08:57:41 katarynka volumio[14177]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 08:57:41 katarynka volumio[14177]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 08:57:41 katarynka volumio[14177]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 08:57:41 katarynka volumio[14177]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 25 08:57:41 katarynka volumio[14177]: Express server listening on port 3000 Mar 25 08:57:41 katarynka volumio[14177]: [Metrics] WebUI: 12s 729.95ms Mar 25 08:57:41 katarynka volumio[14177]: info: CoreStateMachine::resetVolumioState Mar 25 08:57:41 katarynka volumio[14177]: info: CoreStateMachine::getcurrentVolume Mar 25 08:57:41 katarynka volumio[14177]: info: CoreCommandRouter::volumioRetrievevolume Mar 25 08:57:41 katarynka volumio[14177]: info: Cannot read play queue from file Mar 25 08:57:41 katarynka volumio[14177]: info: Volumio Network Manager: Network status updated: 2 Mar 25 08:57:41 katarynka volumio[14278]: Forking 3 albumart workers Mar 25 08:57:41 katarynka volumio[14177]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 08:57:41 katarynka volumio[14177]: info: VolumeController:: Volume=96 Mute =false Mar 25 08:57:41 katarynka volumio[14177]: info: CoreStateMachine::pushState Mar 25 08:57:41 katarynka volumio[14177]: info: CorePlayQueue::getTrack 0 Mar 25 08:57:41 katarynka volumio[14177]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 25 08:57:41 katarynka volumio[14177]: info: CoreCommandRouter::volumioPushState Mar 25 08:57:41 katarynka volumio[14177]: info: CoreStateMachine::updateTrackBlock Mar 25 08:57:41 katarynka volumio[14177]: info: CorePlayQueue::getTrackBlock Mar 25 08:57:41 katarynka volumio[14177]: info: CoreCommandRouter::volumioRetrievevolume Mar 25 08:57:41 katarynka volumio[14177]: info: CoreStateMachine::setRepeat null single undefined Mar 25 08:57:41 katarynka volumio[14177]: info: CoreStateMachine::pushState Mar 25 08:57:41 katarynka volumio[14177]: info: CorePlayQueue::getTrack 0 Mar 25 08:57:41 katarynka volumio[14177]: info: CoreCommandRouter::volumioPushState Mar 25 08:57:41 katarynka volumio[14177]: info: CoreStateMachine::setRandom null Mar 25 08:57:41 katarynka volumio[14177]: info: CoreStateMachine::pushState Mar 25 08:57:41 katarynka volumio[14177]: info: CorePlayQueue::getTrack 0 Mar 25 08:57:41 katarynka volumio[14177]: info: CoreCommandRouter::volumioPushState Mar 25 08:57:41 katarynka volumio[14177]: info: Setting Device type: Raspberry PI Mar 25 08:57:41 katarynka volumio[14177]: info: Completed loading Core Plugins Mar 25 08:57:41 katarynka volumio[14177]: info: Preparing to generate the ALSA configuration file Mar 25 08:57:42 katarynka volumio[14177]: info: Asound.conf file unchanged, so no further update is needed Mar 25 08:57:42 katarynka volumio[14177]: info: Output device has changed, restarting MPD Mar 25 08:57:42 katarynka volumio[14177]: info: Output device has changed, restarting Shairport Sync Mar 25 08:57:42 katarynka volumio[14177]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 08:57:42 katarynka volumio[14177]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 08:57:42 katarynka volumio[14177]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 25 08:57:42 katarynka volumio[14177]: info: ___________ START PLUGINS ___________ Mar 25 08:57:42 katarynka sudo[14333]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 25 08:57:42 katarynka sudo[14333]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 08:57:42 katarynka sudo[14335]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 25 08:57:42 katarynka volumio[14177]: info: ControllerMpd::onStart: Initializing MPD Mar 25 08:57:42 katarynka volumio[14177]: info: Creating MPD Configuration file Mar 25 08:57:42 katarynka sudo[14333]: pam_unix(sudo:session): session closed for user root Mar 25 08:57:42 katarynka sudo[14335]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 08:57:42 katarynka volumio[14177]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 25 08:57:42 katarynka volumio[14177]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 25 08:57:42 katarynka volumio[14177]: info: [1774425462334] CoreMusicLibrary::Adding element Serwery Mediów Mar 25 08:57:42 katarynka volumio[14177]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 25 08:57:42 katarynka volumio[14177]: info: UPNP Browser: Client initialized successfully Mar 25 08:57:42 katarynka systemd[1]: Stopping mpd.service - Music Player Daemon... Mar 25 08:57:42 katarynka sudo[14343]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 25 08:57:42 katarynka sudo[14343]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 08:57:42 katarynka sudo[14343]: pam_unix(sudo:session): session closed for user root Mar 25 08:57:42 katarynka volumio[14177]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 08:57:42 katarynka volumio[14177]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 08:57:42 katarynka sudo[14345]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 25 08:57:42 katarynka sudo[14345]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 08:57:42 katarynka systemd[1]: mpd.service: Deactivated successfully. Mar 25 08:57:42 katarynka systemd[1]: Stopped mpd.service - Music Player Daemon. Mar 25 08:57:42 katarynka systemd[1]: mpd.service: Consumed 7.646s CPU time. Mar 25 08:57:42 katarynka systemd[1]: mpd.socket: Deactivated successfully. Mar 25 08:57:42 katarynka systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Mar 25 08:57:42 katarynka systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Mar 25 08:57:42 katarynka volumio[14177]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 25 08:57:42 katarynka volumio[14177]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 08:57:42 katarynka volumio[14177]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 08:57:42 katarynka systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Mar 25 08:57:42 katarynka systemd[1]: Starting mpd.service - Music Player Daemon... Mar 25 08:57:42 katarynka volumio[14177]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 25 08:57:42 katarynka volumio[14177]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 25 08:57:42 katarynka volumio[14177]: info: [1774425462605] CoreMusicLibrary::Adding element Last_100 Mar 25 08:57:42 katarynka volumio[14177]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 25 08:57:42 katarynka volumio[14177]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 25 08:57:42 katarynka volumio[14177]: info: [1774425462614] CoreMusicLibrary::Adding element Webradio Mar 25 08:57:42 katarynka volumio[14177]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 25 08:57:42 katarynka volumio[14177]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 25 08:57:42 katarynka volumio[14177]: info: Initializing BBC Radios Mar 25 08:57:42 katarynka systemd[1]: mpd.service: Deactivated successfully. Mar 25 08:57:42 katarynka systemd[1]: Stopped mpd.service - Music Player Daemon. Mar 25 08:57:42 katarynka systemd[1]: mpd.socket: Deactivated successfully. Mar 25 08:57:42 katarynka systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Mar 25 08:57:42 katarynka systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Mar 25 08:57:42 katarynka systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Mar 25 08:57:42 katarynka systemd[1]: Starting mpd.service - Music Player Daemon... Mar 25 08:57:42 katarynka volumio[14177]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 25 08:57:42 katarynka volumio[14177]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 08:57:42 katarynka volumio[14177]: info: Creating Spotify config file Mar 25 08:57:42 katarynka volumio[14177]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 08:57:43 katarynka volumio-remote-updater[622]: [2026-03-25 08:57:43] [connect] Successful connection Mar 25 08:57:43 katarynka sudo[14373]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Mar 25 08:57:43 katarynka sudo[14373]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Mar 25 08:57:43 katarynka sudo[14373]: pam_unix(sudo:session): session closed for user root Mar 25 08:57:43 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Mar 25 08:57:43 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 08:57:43 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 08:57:43 katarynka go-librespot[14376]: go-librespot daemon starting... Mar 25 08:57:43 katarynka go-librespot[14377]: time="2026-03-25T08:57:43+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 08:57:44 katarynka volumio[14177]: info: Volumio Calling Home Mar 25 08:57:44 katarynka go-librespot[14377]: time="2026-03-25T08:57:44+01:00" level=info msg="zeroconf server listening on port 43637" Mar 25 08:57:45 katarynka volumio[14177]: info: Discovery: adding 4d616d77-6a8c-4da2-85a4-840d70f98e51 Mar 25 08:57:45 katarynka volumio[14177]: info: Discovery: Found device katarynka Mar 25 08:57:45 katarynka volumio[14177]: info: CoreCommandRouter::volumioGetState Mar 25 08:57:45 katarynka volumio[14177]: info: CorePlayQueue::getTrack 0 Mar 25 08:57:45 katarynka sudo[14403]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 25 08:57:45 katarynka sudo[14403]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 08:57:45 katarynka sudo[14403]: pam_unix(sudo:session): session closed for user root Mar 25 08:57:45 katarynka volumio[14177]: info: Discovery: this is already registered, 4d616d77-6a8c-4da2-85a4-840d70f98e51 Mar 25 08:57:45 katarynka volumio[14300]: Starting albumart workers Mar 25 08:57:45 katarynka volumio[14177]: info: Discovery: Found device katarynka Mar 25 08:57:45 katarynka volumio[14177]: info: CoreCommandRouter::volumioGetState Mar 25 08:57:45 katarynka sudo[14405]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 25 08:57:45 katarynka volumio[14177]: info: CorePlayQueue::getTrack 0 Mar 25 08:57:45 katarynka sudo[14405]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 08:57:45 katarynka sudo[14405]: pam_unix(sudo:session): session closed for user root Mar 25 08:57:45 katarynka volumio[14177]: info: MPD Permissions set Mar 25 08:57:45 katarynka volumio[14177]: info: MPD Permissions set Mar 25 08:57:45 katarynka volumio[14177]: info: VolumeController:: Volume=96 Mute =false Mar 25 08:57:45 katarynka volumio[14177]: info: CoreStateMachine::pushState Mar 25 08:57:45 katarynka volumio[14177]: info: CorePlayQueue::getTrack 0 Mar 25 08:57:45 katarynka volumio[14177]: info: CoreCommandRouter::volumioPushState Mar 25 08:57:45 katarynka volumio-remote-updater[622]: [2026-03-25 08:57:45] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1774425463 101 Mar 25 08:57:45 katarynka volumio[14177]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 1 Mar 25 08:57:45 katarynka volumio[14177]: info: Volumio called home Mar 25 08:57:45 katarynka volumio[14177]: info: Spotify config file written Mar 25 08:57:45 katarynka sudo[14409]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Mar 25 08:57:45 katarynka sudo[14409]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 08:57:46 katarynka systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Mar 25 08:57:46 katarynka systemd[1]: go-librespot-daemon.service: Deactivated successfully. Mar 25 08:57:46 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 08:57:46 katarynka volumio[14299]: Starting albumart workers Mar 25 08:57:46 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 08:57:46 katarynka sudo[14409]: pam_unix(sudo:session): session closed for user root Mar 25 08:57:46 katarynka go-librespot[14411]: go-librespot daemon starting... Mar 25 08:57:46 katarynka volumio[14298]: Starting albumart workers Mar 25 08:57:46 katarynka go-librespot[14412]: time="2026-03-25T08:57:46+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 08:57:46 katarynka go-librespot[14412]: time="2026-03-25T08:57:46+01:00" level=debug msg="app state loaded" Mar 25 08:57:46 katarynka volumio[14177]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Mar 25 08:57:46 katarynka go-librespot[14412]: time="2026-03-25T08:57:46+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 08:57:46 katarynka volumio[14177]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 08:57:46 katarynka volumio[14177]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 08:57:46 katarynka volumio[14177]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 08:57:46 katarynka volumio[14177]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 08:57:46 katarynka volumio[14177]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 08:57:46 katarynka volumio[14177]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 08:57:46 katarynka volumio[14177]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 08:57:46 katarynka volumio[14177]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 08:57:46 katarynka volumio[14177]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 08:57:46 katarynka volumio[14177]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 08:57:46 katarynka volumio[14177]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 08:57:46 katarynka volumio[14177]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 08:57:46 katarynka volumio[14177]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 08:57:46 katarynka volumio[14177]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 08:57:46 katarynka volumio[14177]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 08:57:46 katarynka volumio[14177]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 08:57:46 katarynka volumio[14177]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 08:57:46 katarynka volumio[14177]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 08:57:46 katarynka volumio[14177]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 08:57:46 katarynka volumio[14177]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 08:57:46 katarynka volumio[14177]: info: No need to fix Spotify hosts Mar 25 08:57:46 katarynka go-librespot[14412]: time="2026-03-25T08:57:46+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 25 08:57:46 katarynka go-librespot[14412]: time="2026-03-25T08:57:46+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 25 08:57:46 katarynka go-librespot[14412]: time="2026-03-25T08:57:46+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 25 08:57:46 katarynka go-librespot[14412]: time="2026-03-25T08:57:46+01:00" level=info msg="zeroconf server listening on port 41479" Mar 25 08:57:46 katarynka go-librespot[14412]: time="2026-03-25T08:57:46+01:00" level=debug msg="obtained new client token: AADykdH93fSUX5VimRFc/5HW/5WPCFwVU7xOOdmD6Alfb1aCVOpCYQW5i2Ge9bU/qFL7TgfbVpuM0Abj5T2rj+Abj+GwiKgzcVq/+/FodwlujQBYQuhvhAZN8bM73V4EHKCNr6sQndfP+gZSe5yDrOKt/YYGjiPBjR727unbqGD9GcWhbhy9s2zeF6Swi2JMYvsE8pQkka1iOV/2zPsaOvQ9FSIzPCVHbOPm0PJM+EeIHSyPn+mMoziGSvw=" Mar 25 08:57:47 katarynka go-librespot[14412]: time="2026-03-25T08:57:47+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 08:57:47 katarynka go-librespot[14412]: time="2026-03-25T08:57:47+01:00" level=debug msg="completed keyexchange" Mar 25 08:57:47 katarynka go-librespot[14412]: time="2026-03-25T08:57:47+01:00" level=debug msg="completed challenge" Mar 25 08:57:47 katarynka go-librespot[14412]: time="2026-03-25T08:57: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 25 08:57:47 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 08:57:47 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 08:57:47 katarynka volumio[14177]: info: Starting Shairport Sync Mar 25 08:57:47 katarynka volumio[14177]: info: Starting Shairport Sync Mar 25 08:57:47 katarynka volumio[14177]: info: Starting Shairport Sync Mar 25 08:57:47 katarynka sudo[14440]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 25 08:57:47 katarynka sudo[14440]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 08:57:47 katarynka sudo[14436]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 25 08:57:47 katarynka sudo[14436]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 08:57:47 katarynka systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Mar 25 08:57:47 katarynka systemd[1]: shairport-sync.service: Deactivated successfully. Mar 25 08:57:47 katarynka systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 25 08:57:47 katarynka systemd[1]: shairport-sync.service: Consumed 2.354s CPU time. Mar 25 08:57:47 katarynka sudo[14438]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 25 08:57:47 katarynka sudo[14442]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Mar 25 08:57:47 katarynka sudo[14442]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 08:57:47 katarynka sudo[14438]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 08:57:47 katarynka systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 25 08:57:47 katarynka sudo[14440]: pam_unix(sudo:session): session closed for user root Mar 25 08:57:48 katarynka systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Mar 25 08:57:48 katarynka systemd[1]: shairport-sync.service: Deactivated successfully. Mar 25 08:57:48 katarynka systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 25 08:57:48 katarynka sudo[14442]: pam_unix(sudo:session): session closed for user root Mar 25 08:57:48 katarynka volumio[14177]: info: An error occurred while refreshing Spotify Token Error: Bad Request Mar 25 08:57:48 katarynka volumio[14177]: info: Shairport-Sync Started Mar 25 08:57:48 katarynka volumio[14177]: Error adding Membership: Error: addMembership EINVAL Mar 25 08:57:48 katarynka systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 25 08:57:48 katarynka sudo[14438]: pam_unix(sudo:session): session closed for user root Mar 25 08:57:48 katarynka sudo[14436]: pam_unix(sudo:session): session closed for user root Mar 25 08:57:48 katarynka volumio[14177]: info: Upmpdcli Daemon Started Mar 25 08:57:48 katarynka volumio[14177]: info: CoreCommandRouter::volumioGetState Mar 25 08:57:48 katarynka volumio[14177]: info: CorePlayQueue::getTrack 0 Mar 25 08:57:48 katarynka volumio[14177]: info: Shairport-Sync Started Mar 25 08:57:48 katarynka volumio[14177]: info: Shairport-Sync Started Mar 25 08:57:50 katarynka volumio[14177]: info: go-librespot daemon successfully initialized Mar 25 08:57:50 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Mar 25 08:57:50 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 08:57:50 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 08:57:50 katarynka go-librespot[14488]: go-librespot daemon starting... Mar 25 08:57:50 katarynka go-librespot[14489]: time="2026-03-25T08:57:50+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 08:57:50 katarynka go-librespot[14489]: time="2026-03-25T08:57:50+01:00" level=debug msg="app state loaded" Mar 25 08:57:50 katarynka go-librespot[14489]: time="2026-03-25T08:57:50+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 08:57:50 katarynka go-librespot[14489]: time="2026-03-25T08:57:50+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 25 08:57:50 katarynka go-librespot[14489]: time="2026-03-25T08:57:50+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 25 08:57:50 katarynka go-librespot[14489]: time="2026-03-25T08:57:50+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 25 08:57:50 katarynka go-librespot[14489]: time="2026-03-25T08:57:50+01:00" level=info msg="zeroconf server listening on port 33171" Mar 25 08:57:51 katarynka mpd[14375]: 2026-03-25T08:57:51 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Mar 25 08:57:51 katarynka systemd[1]: Started mpd.service - Music Player Daemon. Mar 25 08:57:51 katarynka sudo[14335]: pam_unix(sudo:session): session closed for user root Mar 25 08:57:51 katarynka sudo[14345]: pam_unix(sudo:session): session closed for user root Mar 25 08:57:51 katarynka volumio[14177]: info: Completed starting Core Plugins Mar 25 08:57:51 katarynka volumio[14177]: info: ------------------------------------------- Mar 25 08:57:51 katarynka volumio[14177]: info: ----- MyVolumio plugins startup ---- Mar 25 08:57:51 katarynka volumio[14177]: info: ------------------------------------------- Mar 25 08:57:51 katarynka volumio[14177]: info: [MyVolumio PluginManager] Fetching plans data.... Mar 25 08:57:51 katarynka go-librespot[14489]: time="2026-03-25T08:57:51+01:00" level=debug msg="obtained new client token: AABR+jNSaBQtIM4y+gxQq7yXTFmLc5gP5+wV9s0XOmjy0kBuP+Vr5+xN4ykvo1V1eVjLaf0/y1Zyw1CU/Ze2KwQOyH1SQ0OIDLCVvxiraB6b4FDq8yH/Pc1apg5I9fO2r5i57jJRch2vjJSBmLque70PhWkOm+eW4lbFzhUOcboBTwabeDvdJyQqhY8qPd4722QJAcR6OKgv1h1ZaIfknAQonMlA97hNuf71LxpJzQkT4aBtTfi4o8I+" Mar 25 08:57:51 katarynka go-librespot[14489]: time="2026-03-25T08:57:51+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 08:57:51 katarynka go-librespot[14489]: time="2026-03-25T08:57:51+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Mar 25 08:57:51 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 08:57:51 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 08:57:51 katarynka volumio[14177]: error: MPD error: The expression evaluated to a falsy value: Mar 25 08:57:51 katarynka volumio[14177]: assert.ok(self.idling) Mar 25 08:57:51 katarynka volumio[14177]: error: The expression evaluated to a falsy value: Mar 25 08:57:51 katarynka volumio[14177]: assert.ok(self.idling) Mar 25 08:57:51 katarynka volumio[14177]: error: updateQueue error: null Mar 25 08:57:51 katarynka volumio[14177]: info: MPD running with PID14375 Mar 25 08:57:51 katarynka volumio[14177]: ,establishing connection Mar 25 08:57:51 katarynka volumio[14177]: error: updateQueue error: null Mar 25 08:57:53 katarynka volumio[14177]: info: Initializing connection to go-librespot Websocket Mar 25 08:57:53 katarynka volumio[14177]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 25 08:57:54 katarynka sudo[14519]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Mar 25 08:57:54 katarynka sudo[14519]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 08:57:54 katarynka sudo[14521]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Mar 25 08:57:54 katarynka sudo[14521]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 08:57:54 katarynka systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Mar 25 08:57:54 katarynka systemd[1]: mpd_monitor.service: Deactivated successfully. Mar 25 08:57:54 katarynka systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Mar 25 08:57:54 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Mar 25 08:57:54 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 08:57:54 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 08:57:54 katarynka go-librespot[14524]: go-librespot daemon starting... Mar 25 08:57:54 katarynka systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Mar 25 08:57:54 katarynka mpd_monitor.sh[14526]: MPD Monitor Service: Starting MPD Monitor Service Mar 25 08:57:54 katarynka sudo[14521]: pam_unix(sudo:session): session closed for user root Mar 25 08:57:54 katarynka sudo[14519]: pam_unix(sudo:session): session closed for user root Mar 25 08:57:54 katarynka volumio[14177]: info: Successfully started MPD Monitor Mar 25 08:57:54 katarynka volumio[14177]: info: Successfully started MPD Monitor Mar 25 08:57:54 katarynka go-librespot[14525]: time="2026-03-25T08:57:54+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 08:57:54 katarynka go-librespot[14525]: time="2026-03-25T08:57:54+01:00" level=debug msg="app state loaded" Mar 25 08:57:54 katarynka go-librespot[14525]: time="2026-03-25T08:57:54+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 08:57:54 katarynka go-librespot[14525]: time="2026-03-25T08:57:54+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 25 08:57:54 katarynka go-librespot[14525]: time="2026-03-25T08:57:54+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 25 08:57:54 katarynka go-librespot[14525]: time="2026-03-25T08:57:54+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 25 08:57:54 katarynka go-librespot[14525]: time="2026-03-25T08:57:54+01:00" level=info msg="zeroconf server listening on port 45725" Mar 25 08:57:54 katarynka go-librespot[14525]: time="2026-03-25T08:57:54+01:00" level=debug msg="obtained new client token: AABX8/b2/lMpU4yBWBQqCROxIg6ipYlF103lA/YXwK2BtOxqhtftogz1QseFCkWfIghimcX1xgMpv04aS8blLQMz+q7uL0336vU3fvgfGgb1RgayaXMOLrm6TykYXMAF58m63356P2eMjY8IO4HEfIV6l7oNauclRbzA/mAuM8OO/iG2ozNnzNt4p8oTe79ZBR0MjN+x/NNxfG8wICSqDFMkSyu6bj2FGRDVZ8ZWUPao8RkQ7JqDBHxQBeY=" Mar 25 08:57:55 katarynka go-librespot[14525]: time="2026-03-25T08:57:55+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 08:57:55 katarynka go-librespot[14525]: time="2026-03-25T08:57:55+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Mar 25 08:57:55 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 08:57:55 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 08:57:56 katarynka volumio[14177]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Mar 25 08:57:56 katarynka volumio[14177]: info: Initializing connection to go-librespot Websocket Mar 25 08:57:56 katarynka volumio[14177]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 25 08:57:58 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Mar 25 08:57:58 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 08:57:58 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 08:57:58 katarynka go-librespot[14536]: go-librespot daemon starting... Mar 25 08:57:58 katarynka go-librespot[14537]: time="2026-03-25T08:57:58+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 08:57:58 katarynka go-librespot[14537]: time="2026-03-25T08:57:58+01:00" level=debug msg="app state loaded" Mar 25 08:57:58 katarynka go-librespot[14537]: time="2026-03-25T08:57:58+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 08:57:58 katarynka go-librespot[14537]: time="2026-03-25T08:57:58+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 25 08:57:58 katarynka go-librespot[14537]: time="2026-03-25T08:57:58+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 25 08:57:58 katarynka go-librespot[14537]: time="2026-03-25T08:57:58+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 25 08:57:58 katarynka go-librespot[14537]: time="2026-03-25T08:57:58+01:00" level=info msg="zeroconf server listening on port 38105" Mar 25 08:57:58 katarynka go-librespot[14537]: time="2026-03-25T08:57:58+01:00" level=debug msg="obtained new client token: AABCgLNuBC1FU4nLDQPHR3Z00tnMWmBvJtw7S0327b0v6yCSlcNpy/fuyTXTfQVkGb+HyycDb++bBCGtSPohmo3F88/c5YxIJF4maf1otrvUpoVxJRclW139Gp2z34/2o7sYrr9izzbAHdlgToZweQ2tmoyF+4Hjur4w4EJHPfxkCkjMIbVkbUdPy0IHp9g1epeyuYXnuI0FrIbikEhBeWIa3MZmCkp9tTHMDbHFUYkqdcgRCUkKu63/h6s=" Mar 25 08:57:58 katarynka go-librespot[14537]: time="2026-03-25T08:57:58+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 08:57:58 katarynka go-librespot[14537]: time="2026-03-25T08:57:58+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Mar 25 08:57:58 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 08:57:58 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 08:57:59 katarynka volumio[14177]: info: Initializing connection to go-librespot Websocket Mar 25 08:57:59 katarynka volumio[14177]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 25 08:57:59 katarynka volumio[14177]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Mar 25 08:57:59 katarynka volumio[14177]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Mar 25 08:57:59 katarynka volumio[14177]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Mar 25 08:57:59 katarynka volumio[14177]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Mar 25 08:57:59 katarynka volumio[14177]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Mar 25 08:57:59 katarynka volumio[14177]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Mar 25 08:57:59 katarynka volumio[14177]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Mar 25 08:57:59 katarynka volumio[14177]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Mar 25 08:57:59 katarynka volumio[14177]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Mar 25 08:57:59 katarynka volumio[14177]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Mar 25 08:57:59 katarynka volumio[14177]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Mar 25 08:57:59 katarynka volumio[14177]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Mar 25 08:57:59 katarynka volumio[14177]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Mar 25 08:57:59 katarynka volumio[14177]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Mar 25 08:57:59 katarynka volumio[14177]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Mar 25 08:57:59 katarynka volumio[14177]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Mar 25 08:57:59 katarynka volumio[14177]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Mar 25 08:57:59 katarynka volumio[14177]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Mar 25 08:57:59 katarynka volumio[14177]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Mar 25 08:57:59 katarynka volumio[14177]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Mar 25 08:57:59 katarynka volumio[14177]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Mar 25 08:57:59 katarynka volumio[14177]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Mar 25 08:57:59 katarynka volumio[14177]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Mar 25 08:57:59 katarynka volumio[14177]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Mar 25 08:57:59 katarynka volumio[14177]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Mar 25 08:57:59 katarynka volumio[14177]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Mar 25 08:57:59 katarynka volumio[14177]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Mar 25 08:57:59 katarynka volumio[14177]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Mar 25 08:57:59 katarynka volumio[14177]: info: Adding plugin bluetooth to MyMusic Plugins Mar 25 08:57:59 katarynka volumio[14177]: info: Adding plugin multiroom to MyMusic Plugins Mar 25 08:57:59 katarynka volumio[14177]: info: Adding plugin metavolumio to MyMusic Plugins Mar 25 08:57:59 katarynka volumio[14177]: info: Adding plugin cd_controller to MyMusic Plugins Mar 25 08:57:59 katarynka volumio[14177]: info: Adding plugin qobuzconnect to MyMusic Plugins Mar 25 08:57:59 katarynka volumio[14177]: info: Adding plugin smart_inputs to MyMusic Plugins Mar 25 08:57:59 katarynka volumio[14177]: info: Adding plugin tidalconnect to MyMusic Plugins Mar 25 08:57:59 katarynka volumio[14177]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Mar 25 08:58:01 katarynka volumio[14177]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Mar 25 08:58:01 katarynka volumio[14177]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Mar 25 08:58:01 katarynka volumio[14177]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 08:58:01 katarynka volumio[14177]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 08:58:01 katarynka volumio[14177]: info: Starting MyVolumio Remote Streaming Endpoints Mar 25 08:58:01 katarynka volumio[14177]: info: MyVolumio login type: Token Mar 25 08:58:01 katarynka volumio[14177]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Mar 25 08:58:01 katarynka volumio[14177]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Mar 25 08:58:02 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Mar 25 08:58:02 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 08:58:02 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 08:58:02 katarynka go-librespot[14544]: go-librespot daemon starting... Mar 25 08:58:02 katarynka go-librespot[14545]: time="2026-03-25T08:58:02+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 08:58:02 katarynka go-librespot[14545]: time="2026-03-25T08:58:02+01:00" level=debug msg="app state loaded" Mar 25 08:58:02 katarynka go-librespot[14545]: time="2026-03-25T08:58:02+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 08:58:02 katarynka go-librespot[14545]: time="2026-03-25T08:58:02+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 25 08:58:02 katarynka go-librespot[14545]: time="2026-03-25T08:58:02+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 25 08:58:02 katarynka go-librespot[14545]: time="2026-03-25T08:58:02+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 25 08:58:02 katarynka go-librespot[14545]: time="2026-03-25T08:58:02+01:00" level=info msg="zeroconf server listening on port 45653" Mar 25 08:58:02 katarynka go-librespot[14545]: time="2026-03-25T08:58:02+01:00" level=debug msg="obtained new client token: AABvEbSTic/pYsV3+s8bGnvlr3919GzAOwzg91KWxbBszy95CkWcuLNVQ0hzQxKjKYmKhg5azs7kH8XnHXYOltbFm6F5K6ip6sNLi3p9+TyOUdWfD8Sz4KwVvLGePQO8hR19wQ6QHgWd2N9HbtXwGGR5xD//PGc3ABOk/Cob77gRBPTinbR5okZuXUfQdBh/7iaEU4a3OojpkF71fLnHsjM505hg7LvqHwjDUXH29PKFTGp6ViG63d3Wpow=" Mar 25 08:58:02 katarynka go-librespot[14545]: time="2026-03-25T08:58:02+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 08:58:03 katarynka go-librespot[14545]: time="2026-03-25T08:58:03+01:00" level=debug msg="completed keyexchange" Mar 25 08:58:03 katarynka go-librespot[14545]: time="2026-03-25T08:58:03+01:00" level=debug msg="completed challenge" Mar 25 08:58:03 katarynka go-librespot[14545]: time="2026-03-25T08:58:03+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 25 08:58:03 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 08:58:03 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 08:58:03 katarynka volumio[14177]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Mar 25 08:58:03 katarynka volumio[14177]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Mar 25 08:58:03 katarynka volumio[14177]: info: Streaming services startup Mar 25 08:58:03 katarynka volumio[14177]: info: Starting Streaming Daemon Mar 25 08:58:03 katarynka sudo[14553]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Mar 25 08:58:03 katarynka sudo[14553]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 08:58:03 katarynka volumio[14177]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Mar 25 08:58:03 katarynka sudo[14553]: pam_unix(sudo:session): session closed for user root Mar 25 08:58:03 katarynka volumio[14177]: info: Initializing connection to go-librespot Websocket Mar 25 08:58:03 katarynka volumio[14177]: error: Cannot start Volumio Streaming Daemon Mar 25 08:58:03 katarynka volumio[14177]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Mar 25 08:58:03 katarynka volumio[14177]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Mar 25 08:58:03 katarynka volumio[14177]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 25 08:58:04 katarynka volumio[14177]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Mar 25 08:58:05 katarynka volumio[14177]: info: MyVolumio token set successfully Mar 25 08:58:05 katarynka volumio[14177]: info: MYVOLUMIO: Adding device Mar 25 08:58:05 katarynka volumio[14177]: info: MYVOLUMIO: Evaluating Server Mar 25 08:58:05 katarynka volumio[14177]: info: MyVolumio status changed Mar 25 08:58:05 katarynka volumio[14177]: info: Streaming services startup Mar 25 08:58:05 katarynka volumio[14177]: info: Starting Streaming Daemon Mar 25 08:58:05 katarynka volumio[14177]: info: Removing browser output: myVolumio user plan is not superstar Mar 25 08:58:05 katarynka volumio[14177]: info: Removing audio output: Mar 25 08:58:05 katarynka volumio[14177]: info: Stoppping Tunnel 1 Mar 25 08:58:05 katarynka sudo[14596]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Mar 25 08:58:05 katarynka sudo[14596]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 08:58:05 katarynka sudo[14598]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Mar 25 08:58:05 katarynka sudo[14598]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 08:58:05 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 25 08:58:05 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 25 08:58:05 katarynka sudo[14596]: pam_unix(sudo:session): session closed for user root Mar 25 08:58:05 katarynka volumio[14177]: error: Cannot start Volumio Streaming Daemon Mar 25 08:58:05 katarynka volumio[14177]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Mar 25 08:58:05 katarynka volumio[14177]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Mar 25 08:58:05 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 25 08:58:05 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 25 08:58:05 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 25 08:58:05 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 25 08:58:05 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 25 08:58:05 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 25 08:58:05 katarynka sudo[14598]: pam_unix(sudo:session): session closed for user root Mar 25 08:58:05 katarynka volumio[14177]: info: Remote SSH Stopped Mar 25 08:58:05 katarynka volumio[14177]: info: Setting Geolocation for MyVolumio to eu4 Mar 25 08:58:05 katarynka volumio[14177]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 08:58:05 katarynka volumio[14177]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 08:58:05 katarynka volumio[14177]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 08:58:06 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Mar 25 08:58:06 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 08:58:06 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 08:58:06 katarynka go-librespot[14602]: go-librespot daemon starting... Mar 25 08:58:06 katarynka volumio[14177]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Mar 25 08:58:06 katarynka go-librespot[14603]: time="2026-03-25T08:58:06+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 08:58:06 katarynka go-librespot[14603]: time="2026-03-25T08:58:06+01:00" level=debug msg="app state loaded" Mar 25 08:58:06 katarynka go-librespot[14603]: time="2026-03-25T08:58:06+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 08:58:06 katarynka go-librespot[14603]: time="2026-03-25T08:58:06+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 25 08:58:06 katarynka go-librespot[14603]: time="2026-03-25T08:58:06+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 25 08:58:06 katarynka go-librespot[14603]: time="2026-03-25T08:58:06+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 25 08:58:06 katarynka go-librespot[14603]: time="2026-03-25T08:58:06+01:00" level=info msg="zeroconf server listening on port 46607" Mar 25 08:58:06 katarynka volumio[14177]: info: Initializing connection to go-librespot Websocket Mar 25 08:58:06 katarynka go-librespot[14603]: time="2026-03-25T08:58:06+01:00" level=debug msg="new websocket client" Mar 25 08:58:06 katarynka volumio[14177]: info: Connection to go-librespot Websocket established Mar 25 08:58:06 katarynka go-librespot[14603]: time="2026-03-25T08:58:06+01:00" level=debug msg="obtained new client token: AADocswLThGvHz9CaysfVRUobPuXw3c1s7cU1pGbvqFZk2hQOMAEzcoSn1qFZVSJQlBscmNo34SiMCsLX2f7ThM7itG49jnGEI4kvod37SH/a6MNAndCJ7mz6nqmWTDEzz/I9EtbpToSZTHx9bKDE+qSZ6Pe/20V+WUIiFB03HOZahan1d6WgfZWVQZwYqEeC3RD5AgqYoLtiPkLpezt13y4CmPe4XyjTA0k5UQAgIU9zvVHiGB5potpBCo=" Mar 25 08:58:06 katarynka go-librespot[14603]: time="2026-03-25T08:58:06+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 08:58:06 katarynka volumio[14177]: info: Updating MyVolumio device info Mar 25 08:58:06 katarynka volumio[14177]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 08:58:06 katarynka volumio[14177]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 08:58:06 katarynka volumio[14177]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 08:58:06 katarynka go-librespot[14603]: time="2026-03-25T08:58:06+01:00" level=debug msg="completed keyexchange" Mar 25 08:58:06 katarynka go-librespot[14603]: time="2026-03-25T08:58:06+01:00" level=debug msg="completed challenge" Mar 25 08:58:06 katarynka go-librespot[14603]: time="2026-03-25T08:58:06+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 25 08:58:07 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 08:58:07 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 08:58:07 katarynka volumio[14177]: info: Connection to go-librespot Websocket closed Mar 25 08:58:07 katarynka volumio[14177]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Mar 25 08:58:09 katarynka volumio[14177]: info: Getting Spotify volume Mar 25 08:58:09 katarynka volumio[14177]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 25 08:58:09 katarynka volumio[14177]: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 25 08:58:09 katarynka volumio[14177]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Mar 25 08:58:09 katarynka volumio[14177]: errno: -111, Mar 25 08:58:09 katarynka volumio[14177]: code: 'ECONNREFUSED', Mar 25 08:58:09 katarynka volumio[14177]: syscall: 'connect', Mar 25 08:58:09 katarynka volumio[14177]: address: '127.0.0.1', Mar 25 08:58:09 katarynka volumio[14177]: port: 9879, Mar 25 08:58:09 katarynka volumio[14177]: response: undefined Mar 25 08:58:09 katarynka volumio[14177]: } Mar 25 08:58:09 katarynka volumio[14177]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 25 08:58:10 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Mar 25 08:58:10 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 08:58:10 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 08:58:10 katarynka go-librespot[14622]: go-librespot daemon starting... Mar 25 08:58:10 katarynka go-librespot[14623]: time="2026-03-25T08:58:10+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 08:58:10 katarynka go-librespot[14623]: time="2026-03-25T08:58:10+01:00" level=debug msg="app state loaded" Mar 25 08:58:10 katarynka go-librespot[14623]: time="2026-03-25T08:58:10+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 08:58:10 katarynka go-librespot[14623]: time="2026-03-25T08:58:10+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 25 08:58:10 katarynka go-librespot[14623]: time="2026-03-25T08:58:10+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 25 08:58:10 katarynka go-librespot[14623]: time="2026-03-25T08:58:10+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 25 08:58:10 katarynka go-librespot[14623]: time="2026-03-25T08:58:10+01:00" level=info msg="zeroconf server listening on port 44427" Mar 25 08:58:10 katarynka go-librespot[14623]: time="2026-03-25T08:58:10+01:00" level=debug msg="obtained new client token: AAAjNpDsmYzx04do6zTnAhzL9Rbu4agEJZLFJEl2pZI4YP5e1eq6nfgaRBEY1MqKtMQu2KUiAmk51/a+hwRF2kftAobT2d4reVahxbxHk80cjejIBrme5Ufsp1k/9M5gzAFD3mEpqGf+/vyx6RLvSSPksveJk/mi/69k+i4BpE3/WZIkdsIxb8X+P1DguLL6Vak5LA854RQArwGn+sxtYEhUcxCHmi5a7ZKa0uankdBii12nEhY+8tYV+xY=" Mar 25 08:58:10 katarynka go-librespot[14623]: time="2026-03-25T08:58:10+01:00" level=warning msg="failed to connect to AP ap-gew4.spotify.com:4070, retrying with a different AP" error="dial tcp 34.158.1.133:4070: connect: connection refused" Mar 25 08:58:11 katarynka go-librespot[14623]: time="2026-03-25T08:58:11+01:00" level=debug msg="connected to ap-gew4.spotify.com:443" Mar 25 08:58:11 katarynka sudo[14632]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-03-25 08:57' Mar 25 08:58:11 katarynka sudo[14632]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 08:58:11 katarynka go-librespot[14623]: time="2026-03-25T08:58:11+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Mar 25 08:58:11 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 08:58:11 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 08:58:11 katarynka sudo[14632]: pam_unix(sudo:session): session closed for user root Mar 25 08:58:12 katarynka volumio-remote-updater[622]: [2026-03-25 08:58:12] [error] handle_read_frame error: asio.system:104 (Connection reset by peer) Mar 25 08:58:12 katarynka volumio-remote-updater[622]: [2026-03-25 08:58:12] [disconnect] Disconnect close local:[1006,Connection reset by peer] remote:[1006] Mar 25 08:58:12 katarynka systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Mar 25 08:58:12 katarynka systemd[1]: volumio.service: Failed with result 'exit-code'. Mar 25 08:58:12 katarynka systemd[1]: volumio.service: Consumed 50.796s CPU time. Mar 25 08:58:12 katarynka systemd[1]: Started dynamicswap.service - dynamicswap service. Mar 25 08:58:12 katarynka systemd[1]: dynamicswap.service: Deactivated successfully. Mar 25 08:58:12 katarynka systemd[1]: volumio.service: Scheduled restart job, restart counter is at 26177. Mar 25 08:58:12 katarynka systemd[1]: Started dynamicswap.service - dynamicswap service. Mar 25 08:58:12 katarynka systemd[1]: Stopped volumio.service - Volumio Backend Module. Mar 25 08:58:12 katarynka systemd[1]: volumio.service: Consumed 50.796s CPU time. Mar 25 08:58:12 katarynka systemd[1]: Started volumio.service - Volumio Backend Module. Mar 25 08:58:12 katarynka systemd[1]: dynamicswap.service: Deactivated successfully. Mar 25 08:58:14 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Mar 25 08:58:14 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 08:58:14 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 08:58:14 katarynka go-librespot[14668]: go-librespot daemon starting... Mar 25 08:58:14 katarynka go-librespot[14669]: time="2026-03-25T08:58:14+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 08:58:14 katarynka go-librespot[14669]: time="2026-03-25T08:58:14+01:00" level=debug msg="app state loaded" Mar 25 08:58:14 katarynka go-librespot[14669]: time="2026-03-25T08:58:14+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 08:58:15 katarynka go-librespot[14669]: time="2026-03-25T08:58: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 25 08:58:15 katarynka go-librespot[14669]: time="2026-03-25T08:58:15+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 25 08:58:15 katarynka go-librespot[14669]: time="2026-03-25T08:58:15+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 25 08:58:15 katarynka go-librespot[14669]: time="2026-03-25T08:58:15+01:00" level=info msg="zeroconf server listening on port 37519" Mar 25 08:58:15 katarynka go-librespot[14669]: time="2026-03-25T08:58:15+01:00" level=debug msg="obtained new client token: AADPOQjrD1bkcfdNRIaI0nN95DyEw9ym3YWSwOaVwt5a+vA1zPRKhS11VTXKujuJNtUsnVqgIVC5YLm+dlc9SHIO7+B0naPl8zNTVicsk2wPdnplIjxdWRyOsxOTOQZLJ0OaVit8YE+chECh+e968VB0c6v5aIxIZJK3Qk2Im9g50FnrhBV7Rt/tAkF7yngw+1Kii5PKBgu9jLMRKKX96kF9EcvQ2gAe2zMLWjaCIcvNMRzjGPDzvJiEkqQ=" Mar 25 08:58:15 katarynka go-librespot[14669]: time="2026-03-25T08:58:15+01:00" level=warning msg="failed to connect to AP ap-gew4.spotify.com:4070, retrying with a different AP" error="dial tcp 34.158.1.133:4070: connect: connection refused" Mar 25 08:58:15 katarynka go-librespot[14669]: time="2026-03-25T08:58:15+01:00" level=debug msg="connected to ap-gew4.spotify.com:443" Mar 25 08:58:15 katarynka go-librespot[14669]: time="2026-03-25T08:58:15+01:00" level=debug msg="completed keyexchange" Mar 25 08:58:15 katarynka go-librespot[14669]: time="2026-03-25T08:58:15+01:00" level=debug msg="completed challenge" Mar 25 08:58:15 katarynka go-librespot[14669]: time="2026-03-25T08:58:15+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 25 08:58:15 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 08:58:15 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 08:58:16 katarynka volumio[14649]: info: ------------------------------------------- Mar 25 08:58:16 katarynka volumio[14649]: info: ----- Volumio3 ---- Mar 25 08:58:16 katarynka volumio[14649]: info: ------------------------------------------- Mar 25 08:58:16 katarynka volumio[14649]: info: ----- System startup ---- Mar 25 08:58:16 katarynka volumio[14649]: info: ------------------------------------------- Mar 25 08:58:17 katarynka volumio-remote-updater[622]: [2026-03-25 08:58:17] [connect] Successful connection Mar 25 08:58:17 katarynka volumio[14649]: info: MYVOLUMIO Environment detected Mar 25 08:58:17 katarynka volumio[14649]: info: Plugin folders cleanup Mar 25 08:58:17 katarynka volumio[14649]: info: Scanning into folder /volumio/app/plugins/ Mar 25 08:58:17 katarynka volumio[14649]: info: Scanning category audio_interface Mar 25 08:58:17 katarynka volumio[14649]: info: Scanning category miscellanea Mar 25 08:58:17 katarynka volumio[14649]: info: Scanning category music_service Mar 25 08:58:17 katarynka volumio[14649]: info: Scanning category plugins.json Mar 25 08:58:18 katarynka volumio[14649]: info: Scanning category system_controller Mar 25 08:58:18 katarynka volumio[14649]: info: Scanning category user_interface Mar 25 08:58:18 katarynka volumio[14649]: info: Scanning into folder /data/plugins/ Mar 25 08:58:18 katarynka volumio[14649]: info: Scanning category music_service Mar 25 08:58:18 katarynka volumio[14649]: info: Plugin folders cleanup completed Mar 25 08:58:18 katarynka volumio[14649]: info: ------------------------------------------- Mar 25 08:58:18 katarynka volumio[14649]: info: ----- Core plugins startup ---- Mar 25 08:58:18 katarynka volumio[14649]: info: ------------------------------------------- Mar 25 08:58:18 katarynka volumio[14649]: info: Loading plugins from folder /volumio/app/plugins/ Mar 25 08:58:18 katarynka volumio[14649]: info: Adding plugin upnp to MyMusic Plugins Mar 25 08:58:18 katarynka volumio[14649]: info: Adding plugin airplay_emulation to MyMusic Plugins Mar 25 08:58:18 katarynka volumio[14649]: info: Adding plugin upnp_browser to MyMusic Plugins Mar 25 08:58:18 katarynka volumio[14649]: info: Loading plugins from folder /data/plugins/ Mar 25 08:58:18 katarynka volumio[14649]: info: Loading plugin "system"... Mar 25 08:58:18 katarynka volumio[14649]: info: Loading plugin "appearance"... Mar 25 08:58:18 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Mar 25 08:58:18 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 08:58:18 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 08:58:18 katarynka go-librespot[14688]: go-librespot daemon starting... Mar 25 08:58:18 katarynka go-librespot[14689]: time="2026-03-25T08:58:18+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 08:58:18 katarynka go-librespot[14689]: time="2026-03-25T08:58:18+01:00" level=debug msg="app state loaded" Mar 25 08:58:18 katarynka go-librespot[14689]: time="2026-03-25T08:58:18+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 08:58:19 katarynka go-librespot[14689]: time="2026-03-25T08:58: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-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 25 08:58:19 katarynka go-librespot[14689]: time="2026-03-25T08:58:19+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 25 08:58:19 katarynka go-librespot[14689]: time="2026-03-25T08:58:19+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 25 08:58:19 katarynka go-librespot[14689]: time="2026-03-25T08:58:19+01:00" level=info msg="zeroconf server listening on port 40639" Mar 25 08:58:19 katarynka go-librespot[14689]: time="2026-03-25T08:58:19+01:00" level=debug msg="obtained new client token: AAADmyBR8/BZYBsntMgEgm2WICyQ5feJ+6kajDT+kNA9YffqrHPgItYqRVzTCix9du8JoSwotZGhPE2OTHdXitJ06cq5DJr0t05UuGejsmAhbe2+wm306vjanKbure4gtpMzy0sygLGV2A9hXopS9fZULa6JgebrUAxkaqflGQPp33P+RFfBfSU2ZGRshtXVexpAdd9PyjdPO3dG4WVcpCe5NavtePW0moXkLPPFpHpjYKkJk4EalBeFRo8=" Mar 25 08:58:19 katarynka go-librespot[14689]: time="2026-03-25T08:58:19+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 08:58:19 katarynka go-librespot[14689]: time="2026-03-25T08:58:19+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Mar 25 08:58:19 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 08:58:19 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 08:58:20 katarynka volumio[14649]: info: Loading plugin "network"... Mar 25 08:58:20 katarynka volumio[14649]: info: Refreshing Cached IP Addresses Mar 25 08:58:20 katarynka sudo[14697]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 25 08:58:20 katarynka sudo[14697]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 08:58:20 katarynka sudo[14697]: pam_unix(sudo:session): session closed for user root Mar 25 08:58:20 katarynka volumio[14649]: info: Loading plugin "services"... Mar 25 08:58:20 katarynka volumio[14649]: info: Loading plugin "alsa_controller"... Mar 25 08:58:20 katarynka sudo[14699]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 25 08:58:20 katarynka sudo[14699]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 08:58:20 katarynka sudo[14699]: pam_unix(sudo:session): session closed for user root Mar 25 08:58:20 katarynka sudo[14707]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Mar 25 08:58:20 katarynka sudo[14707]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 08:58:20 katarynka volumio[14649]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 25 08:58:20 katarynka volumio[14649]: info: Loading plugin "wizard"... Mar 25 08:58:20 katarynka volumio[14649]: info: Loading plugin "networkfs"... Mar 25 08:58:20 katarynka volumio[14649]: info: Starting Udev Watcher for removable devices Mar 25 08:58:20 katarynka volumio[14649]: info: Ignoring mount for partition: boot Mar 25 08:58:20 katarynka volumio[14649]: info: Ignoring mount for partition: volumio Mar 25 08:58:20 katarynka volumio[14649]: info: Ignoring mount for partition: volumio_data Mar 25 08:58:20 katarynka volumio[14649]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 25 08:58:20 katarynka volumio[14649]: info: Loading plugin "volumio_command_line_client"... Mar 25 08:58:20 katarynka volumio[14649]: info: Loading plugin "upnp"... Mar 25 08:58:20 katarynka volumio[14649]: info: [1774425500659] Starting Upmpd Daemon Mar 25 08:58:20 katarynka volumio[14649]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 25 08:58:20 katarynka volumio[14649]: info: Loading plugin "my_music"... Mar 25 08:58:20 katarynka volumio[14649]: info: Loading plugin "mpd"... Mar 25 08:58:21 katarynka sudo[14707]: pam_unix(sudo:session): session closed for user root Mar 25 08:58:21 katarynka volumio[14649]: info: Loading plugin "upnp_browser"... Mar 25 08:58:22 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Mar 25 08:58:22 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 08:58:22 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 08:58:22 katarynka go-librespot[14730]: go-librespot daemon starting... Mar 25 08:58:22 katarynka go-librespot[14731]: time="2026-03-25T08:58:22+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 08:58:22 katarynka go-librespot[14731]: time="2026-03-25T08:58:22+01:00" level=debug msg="app state loaded" Mar 25 08:58:22 katarynka go-librespot[14731]: time="2026-03-25T08:58:22+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 08:58:23 katarynka go-librespot[14731]: time="2026-03-25T08:58:23+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 25 08:58:23 katarynka go-librespot[14731]: time="2026-03-25T08:58:23+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 25 08:58:23 katarynka go-librespot[14731]: time="2026-03-25T08:58:23+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 25 08:58:23 katarynka go-librespot[14731]: time="2026-03-25T08:58:23+01:00" level=info msg="zeroconf server listening on port 34247" Mar 25 08:58:23 katarynka go-librespot[14731]: time="2026-03-25T08:58:23+01:00" level=debug msg="obtained new client token: AACLu9R9OtuBaPpXpeve6A+n8+gbp5W9g2OTpAtqNUNki+NmGIai0YVyW9uV/OFzxsynBaUsg9vVqIxHsGSVBu0LeBpo7BS+fL9I5grtaj7G4tQ+M/3wm5mqefibdnpVbxhE/Eb9qKssMV2J18IJgTP8kOVwNLLpdR45X7/ulCh5r20Uq+L5WYG4je1H0Dm1OYOerlSHkRcfbYIjf4jCJQe35qYq8KMqfoFEKBSyL1/c7izOJjM1LuHmOrM=" Mar 25 08:58:23 katarynka go-librespot[14731]: time="2026-03-25T08:58:23+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 08:58:23 katarynka go-librespot[14731]: time="2026-03-25T08:58:23+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Mar 25 08:58:23 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 08:58:23 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 08:58:24 katarynka volumio[14649]: info: Starting UPNP Browser Mar 25 08:58:24 katarynka volumio[14649]: info: Loading plugin "alarm-clock"... Mar 25 08:58:24 katarynka volumio[14649]: info: Loading plugin "airplay_emulation"... Mar 25 08:58:24 katarynka volumio[14649]: info: Starting Shairport Sync Mar 25 08:58:24 katarynka volumio[14649]: info: Loading plugin "last_100"... Mar 25 08:58:24 katarynka volumio[14649]: info: Loading plugin "webradio"... Mar 25 08:58:24 katarynka volumio[14649]: info: Loading plugin "i2s_dacs"... Mar 25 08:58:25 katarynka volumio[14649]: info: Loading plugin "volumiodiscovery"... Mar 25 08:58:25 katarynka volumio[14649]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Mar 25 08:58:25 katarynka volumio[14649]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 25 08:58:25 katarynka volumio[14649]: *** WARNING *** For more information see Mar 25 08:58:25 katarynka volumio[14649]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Mar 25 08:58:25 katarynka volumio[14649]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 25 08:58:25 katarynka volumio[14649]: *** WARNING *** For more information see Mar 25 08:58:25 katarynka node[14649]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Mar 25 08:58:25 katarynka node[14649]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 25 08:58:25 katarynka node[14649]: *** WARNING *** For more information see Mar 25 08:58:25 katarynka node[14649]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Mar 25 08:58:25 katarynka node[14649]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 25 08:58:25 katarynka node[14649]: *** WARNING *** For more information see Mar 25 08:58:25 katarynka volumio[14649]: info: Applying required configuration parameters for plugin volumiodiscovery Mar 25 08:58:25 katarynka volumio[14649]: info: Discovery: Started advertising with name: katarynka Mar 25 08:58:25 katarynka volumio[14649]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 25 08:58:25 katarynka volumio[14649]: info: Loading plugin "spop"... Mar 25 08:58:26 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Mar 25 08:58:26 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 08:58:26 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 08:58:26 katarynka go-librespot[14741]: go-librespot daemon starting... Mar 25 08:58:26 katarynka go-librespot[14742]: time="2026-03-25T08:58:26+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 08:58:26 katarynka go-librespot[14742]: time="2026-03-25T08:58:26+01:00" level=debug msg="app state loaded" Mar 25 08:58:26 katarynka go-librespot[14742]: time="2026-03-25T08:58:26+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 08:58:27 katarynka volumio[14649]: info: Loading plugin "outputs"... Mar 25 08:58:27 katarynka volumio[14649]: info: Loading plugin "albumart"... Mar 25 08:58:27 katarynka go-librespot[14742]: time="2026-03-25T08:58: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 25 08:58:27 katarynka go-librespot[14742]: time="2026-03-25T08:58: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 25 08:58:27 katarynka go-librespot[14742]: time="2026-03-25T08:58: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 25 08:58:27 katarynka volumio[14649]: info: Plugin example_plugin is not enabled Mar 25 08:58:27 katarynka volumio[14649]: info: Loading plugin "inputs"... Mar 25 08:58:27 katarynka volumio[14649]: info: Loading plugin "updater_comm"... Mar 25 08:58:27 katarynka go-librespot[14742]: time="2026-03-25T08:58:27+01:00" level=info msg="zeroconf server listening on port 32967" Mar 25 08:58:27 katarynka go-librespot[14742]: time="2026-03-25T08:58:27+01:00" level=debug msg="obtained new client token: AADWaFjgbtVrgwF1RXMEZmr5GMTYi5nNLIaortTOWpthdfASBWLVfAkLSY4VsH6ykXK1JiFbapV+YKjgVwdqKFEt6SlCwUFedyUyT+Rc05zLv1vqR1d0V0cxL/q5ToV1n2wzePn2CZa4MVKFDvU86Ha0PaNTj+m9mTw+qCWDEHdf5IGqOcSUQvYa/QhKU3qgaYIbO4yVOC+It9eBzj+/U6j1rndtnhRyrdc29B4iF15yJHl6FQQ31umOd+w=" Mar 25 08:58:27 katarynka go-librespot[14742]: time="2026-03-25T08:58:27+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 08:58:27 katarynka volumio[14649]: info: Plugin mpdemulation is not enabled Mar 25 08:58:27 katarynka volumio[14649]: info: Loading plugin "rest_api"... Mar 25 08:58:27 katarynka go-librespot[14742]: time="2026-03-25T08:58:27+01:00" level=debug msg="completed keyexchange" Mar 25 08:58:27 katarynka go-librespot[14742]: time="2026-03-25T08:58:27+01:00" level=debug msg="completed challenge" Mar 25 08:58:27 katarynka volumio[14649]: info: Loading plugin "websocket"... Mar 25 08:58:27 katarynka volumio[14649]: info: Starting Socket.io Server version 1.7.4 Mar 25 08:58:27 katarynka go-librespot[14742]: time="2026-03-25T08:58:27+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 25 08:58:27 katarynka volumio[14649]: info: Loading i18n strings for locale pl Mar 25 08:58:27 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 08:58:27 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 08:58:27 katarynka volumio[14649]: Updating browse sources language Mar 25 08:58:27 katarynka volumio[14649]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 25 08:58:27 katarynka volumio[14649]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 25 08:58:27 katarynka volumio[14649]: info: CoreCommandRouter::initPlayerControls Mar 25 08:58:27 katarynka volumio[14649]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 08:58:27 katarynka volumio[14649]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 08:58:27 katarynka volumio[14649]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 08:58:27 katarynka volumio[14649]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 08:58:27 katarynka volumio[14649]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 08:58:27 katarynka volumio[14649]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 08:58:27 katarynka volumio[14649]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 08:58:27 katarynka volumio[14649]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 08:58:27 katarynka volumio[14649]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 25 08:58:28 katarynka volumio[14649]: Express server listening on port 3000 Mar 25 08:58:28 katarynka volumio[14649]: [Metrics] WebUI: 12s 660.27ms Mar 25 08:58:28 katarynka volumio[14649]: info: CoreStateMachine::resetVolumioState Mar 25 08:58:28 katarynka volumio[14649]: info: CoreStateMachine::getcurrentVolume Mar 25 08:58:28 katarynka volumio[14649]: info: CoreCommandRouter::volumioRetrievevolume Mar 25 08:58:28 katarynka volumio[14649]: info: Cannot read play queue from file Mar 25 08:58:28 katarynka volumio[14649]: info: Volumio Network Manager: Network status updated: 2 Mar 25 08:58:28 katarynka volumio[14749]: Forking 3 albumart workers Mar 25 08:58:28 katarynka volumio[14649]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 08:58:28 katarynka volumio[14649]: info: VolumeController:: Volume=96 Mute =false Mar 25 08:58:28 katarynka volumio[14649]: info: CoreStateMachine::pushState Mar 25 08:58:28 katarynka volumio[14649]: info: CorePlayQueue::getTrack 0 Mar 25 08:58:28 katarynka volumio[14649]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 25 08:58:28 katarynka volumio[14649]: info: CoreCommandRouter::volumioPushState Mar 25 08:58:28 katarynka volumio[14649]: info: CoreStateMachine::updateTrackBlock Mar 25 08:58:28 katarynka volumio[14649]: info: CorePlayQueue::getTrackBlock Mar 25 08:58:28 katarynka volumio[14649]: info: CoreCommandRouter::volumioRetrievevolume Mar 25 08:58:28 katarynka volumio[14649]: info: CoreStateMachine::setRepeat null single undefined Mar 25 08:58:28 katarynka volumio[14649]: info: CoreStateMachine::pushState Mar 25 08:58:28 katarynka volumio[14649]: info: CorePlayQueue::getTrack 0 Mar 25 08:58:28 katarynka volumio[14649]: info: CoreCommandRouter::volumioPushState Mar 25 08:58:28 katarynka volumio[14649]: info: CoreStateMachine::setRandom null Mar 25 08:58:28 katarynka volumio[14649]: info: CoreStateMachine::pushState Mar 25 08:58:28 katarynka volumio[14649]: info: CorePlayQueue::getTrack 0 Mar 25 08:58:28 katarynka volumio[14649]: info: CoreCommandRouter::volumioPushState Mar 25 08:58:28 katarynka volumio[14649]: info: Setting Device type: Raspberry PI Mar 25 08:58:28 katarynka volumio[14649]: info: Completed loading Core Plugins Mar 25 08:58:28 katarynka volumio[14649]: info: Preparing to generate the ALSA configuration file Mar 25 08:58:28 katarynka volumio[14649]: info: Asound.conf file unchanged, so no further update is needed Mar 25 08:58:28 katarynka volumio[14649]: info: Output device has changed, restarting MPD Mar 25 08:58:28 katarynka volumio[14649]: info: Output device has changed, restarting Shairport Sync Mar 25 08:58:28 katarynka volumio[14649]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 08:58:28 katarynka volumio[14649]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 08:58:28 katarynka sudo[14806]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 25 08:58:28 katarynka sudo[14806]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 08:58:28 katarynka sudo[14804]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 25 08:58:28 katarynka sudo[14804]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 08:58:28 katarynka sudo[14804]: pam_unix(sudo:session): session closed for user root Mar 25 08:58:28 katarynka volumio[14649]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 25 08:58:28 katarynka volumio[14649]: info: ___________ START PLUGINS ___________ Mar 25 08:58:28 katarynka systemd[1]: Stopping mpd.service - Music Player Daemon... Mar 25 08:58:28 katarynka volumio[14649]: info: ControllerMpd::onStart: Initializing MPD Mar 25 08:58:28 katarynka volumio[14649]: info: Creating MPD Configuration file Mar 25 08:58:29 katarynka volumio[14649]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 25 08:58:29 katarynka volumio[14649]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 25 08:58:29 katarynka volumio[14649]: info: [1774425509089] CoreMusicLibrary::Adding element Serwery Mediów Mar 25 08:58:29 katarynka volumio[14649]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 25 08:58:29 katarynka systemd[1]: mpd.service: Deactivated successfully. Mar 25 08:58:29 katarynka systemd[1]: Stopped mpd.service - Music Player Daemon. Mar 25 08:58:29 katarynka systemd[1]: mpd.service: Consumed 7.779s CPU time. Mar 25 08:58:29 katarynka volumio[14649]: info: UPNP Browser: Client initialized successfully Mar 25 08:58:29 katarynka sudo[14814]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 25 08:58:29 katarynka systemd[1]: mpd.socket: Deactivated successfully. Mar 25 08:58:29 katarynka sudo[14814]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 08:58:29 katarynka systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Mar 25 08:58:29 katarynka systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Mar 25 08:58:29 katarynka sudo[14814]: pam_unix(sudo:session): session closed for user root Mar 25 08:58:29 katarynka volumio[14649]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 08:58:29 katarynka volumio[14649]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 08:58:29 katarynka sudo[14816]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 25 08:58:29 katarynka sudo[14816]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 08:58:29 katarynka systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Mar 25 08:58:29 katarynka volumio[14649]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 25 08:58:29 katarynka volumio[14649]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 08:58:29 katarynka volumio[14649]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 08:58:29 katarynka systemd[1]: Starting mpd.service - Music Player Daemon... Mar 25 08:58:29 katarynka volumio[14649]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 25 08:58:29 katarynka systemd[1]: mpd.service: Deactivated successfully. Mar 25 08:58:29 katarynka systemd[1]: Stopped mpd.service - Music Player Daemon. Mar 25 08:58:29 katarynka systemd[1]: mpd.socket: Deactivated successfully. Mar 25 08:58:29 katarynka volumio[14649]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 25 08:58:29 katarynka volumio[14649]: info: [1774425509370] CoreMusicLibrary::Adding element Last_100 Mar 25 08:58:29 katarynka systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Mar 25 08:58:29 katarynka systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Mar 25 08:58:29 katarynka volumio[14649]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 25 08:58:29 katarynka volumio[14649]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 25 08:58:29 katarynka volumio[14649]: info: [1774425509393] CoreMusicLibrary::Adding element Webradio Mar 25 08:58:29 katarynka volumio[14649]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 25 08:58:29 katarynka volumio[14649]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 25 08:58:29 katarynka volumio[14649]: info: Initializing BBC Radios Mar 25 08:58:29 katarynka systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Mar 25 08:58:29 katarynka systemd[1]: Starting mpd.service - Music Player Daemon... Mar 25 08:58:29 katarynka volumio-remote-updater[622]: [2026-03-25 08:58:29] [connect] Successful connection Mar 25 08:58:29 katarynka volumio[14649]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 25 08:58:29 katarynka volumio[14649]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 08:58:29 katarynka volumio[14649]: info: Creating Spotify config file Mar 25 08:58:29 katarynka volumio[14649]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 08:58:30 katarynka sudo[14831]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Mar 25 08:58:30 katarynka sudo[14831]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Mar 25 08:58:30 katarynka sudo[14831]: pam_unix(sudo:session): session closed for user root Mar 25 08:58:30 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 11. Mar 25 08:58:30 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 08:58:31 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 08:58:31 katarynka go-librespot[14860]: go-librespot daemon starting... Mar 25 08:58:31 katarynka go-librespot[14861]: time="2026-03-25T08:58:31+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 08:58:31 katarynka volumio[14649]: info: Volumio Calling Home Mar 25 08:58:31 katarynka go-librespot[14861]: time="2026-03-25T08:58:31+01:00" level=info msg="zeroconf server listening on port 43783" Mar 25 08:58:32 katarynka volumio[14770]: Starting albumart workers Mar 25 08:58:32 katarynka volumio[14771]: Starting albumart workers Mar 25 08:58:32 katarynka volumio[14767]: Starting albumart workers Mar 25 08:58:32 katarynka volumio[14649]: info: Discovery: adding 4d616d77-6a8c-4da2-85a4-840d70f98e51 Mar 25 08:58:32 katarynka volumio[14649]: info: Discovery: Found device katarynka Mar 25 08:58:32 katarynka volumio[14649]: info: CoreCommandRouter::volumioGetState Mar 25 08:58:32 katarynka volumio[14649]: info: CorePlayQueue::getTrack 0 Mar 25 08:58:32 katarynka volumio[14649]: info: Discovery: this is already registered, 4d616d77-6a8c-4da2-85a4-840d70f98e51 Mar 25 08:58:32 katarynka volumio[14649]: info: Discovery: Found device katarynka Mar 25 08:58:32 katarynka volumio[14649]: info: CoreCommandRouter::volumioGetState Mar 25 08:58:32 katarynka volumio[14649]: info: CorePlayQueue::getTrack 0 Mar 25 08:58:32 katarynka sudo[14873]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 25 08:58:32 katarynka sudo[14873]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 08:58:32 katarynka sudo[14875]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 25 08:58:32 katarynka sudo[14875]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 08:58:32 katarynka volumio[14649]: info: MPD Permissions set Mar 25 08:58:32 katarynka volumio[14649]: info: MPD Permissions set Mar 25 08:58:32 katarynka sudo[14875]: pam_unix(sudo:session): session closed for user root Mar 25 08:58:32 katarynka volumio[14649]: info: VolumeController:: Volume=96 Mute =false Mar 25 08:58:32 katarynka volumio[14649]: info: CoreStateMachine::pushState Mar 25 08:58:32 katarynka volumio[14649]: info: CorePlayQueue::getTrack 0 Mar 25 08:58:32 katarynka volumio[14649]: info: CoreCommandRouter::volumioPushState Mar 25 08:58:32 katarynka sudo[14873]: pam_unix(sudo:session): session closed for user root Mar 25 08:58:32 katarynka volumio-remote-updater[622]: [2026-03-25 08:58:32] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1774425509 101 Mar 25 08:58:32 katarynka volumio[14649]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 1 Mar 25 08:58:32 katarynka volumio[14649]: info: Volumio called home Mar 25 08:58:32 katarynka volumio[14649]: info: Spotify config file written Mar 25 08:58:32 katarynka sudo[14879]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Mar 25 08:58:32 katarynka sudo[14879]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 08:58:32 katarynka systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Mar 25 08:58:32 katarynka systemd[1]: go-librespot-daemon.service: Deactivated successfully. Mar 25 08:58:32 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 08:58:33 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 08:58:33 katarynka go-librespot[14881]: go-librespot daemon starting... Mar 25 08:58:33 katarynka sudo[14879]: pam_unix(sudo:session): session closed for user root Mar 25 08:58:33 katarynka go-librespot[14882]: time="2026-03-25T08:58:33+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 08:58:33 katarynka go-librespot[14882]: time="2026-03-25T08:58:33+01:00" level=debug msg="app state loaded" Mar 25 08:58:33 katarynka go-librespot[14882]: time="2026-03-25T08:58:33+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 08:58:33 katarynka volumio[14649]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Mar 25 08:58:33 katarynka volumio[14649]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 08:58:33 katarynka volumio[14649]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 08:58:33 katarynka volumio[14649]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 08:58:33 katarynka volumio[14649]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 08:58:33 katarynka volumio[14649]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 08:58:33 katarynka volumio[14649]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 08:58:33 katarynka volumio[14649]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 08:58:33 katarynka volumio[14649]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 08:58:33 katarynka volumio[14649]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 08:58:33 katarynka volumio[14649]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 08:58:33 katarynka volumio[14649]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 08:58:33 katarynka volumio[14649]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 08:58:33 katarynka volumio[14649]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 08:58:33 katarynka volumio[14649]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 08:58:33 katarynka volumio[14649]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 08:58:33 katarynka volumio[14649]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 08:58:33 katarynka volumio[14649]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 08:58:33 katarynka volumio[14649]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 08:58:33 katarynka volumio[14649]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 08:58:33 katarynka volumio[14649]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 08:58:33 katarynka volumio[14649]: info: No need to fix Spotify hosts Mar 25 08:58:33 katarynka go-librespot[14882]: time="2026-03-25T08:58:33+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Mar 25 08:58:33 katarynka go-librespot[14882]: time="2026-03-25T08:58:33+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Mar 25 08:58:33 katarynka go-librespot[14882]: time="2026-03-25T08:58:33+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Mar 25 08:58:33 katarynka go-librespot[14882]: time="2026-03-25T08:58:33+01:00" level=info msg="zeroconf server listening on port 35569" Mar 25 08:58:33 katarynka go-librespot[14882]: time="2026-03-25T08:58:33+01:00" level=debug msg="obtained new client token: AACtXya95OwlWhVbmIiotzgjWix+CxOZxltVhyIzCxvfokLkRI40bEtopouAboYHsf3pvoNTaa9RuWYCGfpUPmE7GzSdEw3tq62We6DyZzhuK3bBBN6sdAC5EWmB3fByjThEC+os+1ART27sDNj5ey6bg1KEDaVK6+0wa8T+hKeXqRreOHLvUWtEeexsuGJtXvID3vuPExFAMGWe5BszeUtfa1Gf/DoyN15+i/VIT5OR8InpYXun4RBqKKQ=" Mar 25 08:58:34 katarynka go-librespot[14882]: time="2026-03-25T08:58:34+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 08:58:34 katarynka volumio[14649]: info: Starting Shairport Sync Mar 25 08:58:34 katarynka go-librespot[14882]: time="2026-03-25T08:58:34+01:00" level=debug msg="completed keyexchange" Mar 25 08:58:34 katarynka go-librespot[14882]: time="2026-03-25T08:58:34+01:00" level=debug msg="completed challenge" Mar 25 08:58:34 katarynka volumio[14649]: info: Starting Shairport Sync Mar 25 08:58:34 katarynka go-librespot[14882]: time="2026-03-25T08:58:34+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 25 08:58:34 katarynka volumio[14649]: info: Starting Shairport Sync Mar 25 08:58:34 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 08:58:34 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 08:58:34 katarynka sudo[14904]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 25 08:58:34 katarynka sudo[14904]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 08:58:34 katarynka sudo[14902]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 25 08:58:34 katarynka sudo[14902]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 08:58:34 katarynka sudo[14908]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Mar 25 08:58:34 katarynka sudo[14908]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 08:58:34 katarynka sudo[14906]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 25 08:58:34 katarynka sudo[14906]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 08:58:34 katarynka systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Mar 25 08:58:34 katarynka systemd[1]: shairport-sync.service: Deactivated successfully. Mar 25 08:58:34 katarynka systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 25 08:58:34 katarynka systemd[1]: shairport-sync.service: Consumed 2.449s CPU time. Mar 25 08:58:34 katarynka systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 25 08:58:34 katarynka sudo[14902]: pam_unix(sudo:session): session closed for user root Mar 25 08:58:34 katarynka sudo[14908]: pam_unix(sudo:session): session closed for user root Mar 25 08:58:34 katarynka systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Mar 25 08:58:34 katarynka systemd[1]: shairport-sync.service: Deactivated successfully. Mar 25 08:58:34 katarynka systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 25 08:58:34 katarynka systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 25 08:58:34 katarynka sudo[14904]: pam_unix(sudo:session): session closed for user root Mar 25 08:58:34 katarynka sudo[14906]: pam_unix(sudo:session): session closed for user root Mar 25 08:58:34 katarynka volumio[14649]: info: Upmpdcli Daemon Started Mar 25 08:58:34 katarynka volumio[14649]: info: Shairport-Sync Started Mar 25 08:58:34 katarynka volumio[14649]: Error adding Membership: Error: addMembership EINVAL Mar 25 08:58:35 katarynka volumio[14649]: info: An error occurred while refreshing Spotify Token Error: Bad Request Mar 25 08:58:35 katarynka volumio[14649]: info: Shairport-Sync Started Mar 25 08:58:35 katarynka volumio[14649]: info: Shairport-Sync Started Mar 25 08:58:35 katarynka volumio[14649]: info: CoreCommandRouter::volumioGetState Mar 25 08:58:35 katarynka volumio[14649]: info: CorePlayQueue::getTrack 0 Mar 25 08:58:36 katarynka volumio[14649]: info: go-librespot daemon successfully initialized Mar 25 08:58:37 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Mar 25 08:58:37 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 08:58:37 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 08:58:37 katarynka go-librespot[14950]: go-librespot daemon starting... Mar 25 08:58:37 katarynka go-librespot[14951]: time="2026-03-25T08:58:37+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 08:58:37 katarynka go-librespot[14951]: time="2026-03-25T08:58:37+01:00" level=debug msg="app state loaded" Mar 25 08:58:37 katarynka go-librespot[14951]: time="2026-03-25T08:58:37+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 08:58:37 katarynka mpd[14845]: 2026-03-25T08:58:37 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Mar 25 08:58:37 katarynka systemd[1]: Started mpd.service - Music Player Daemon. Mar 25 08:58:37 katarynka sudo[14816]: pam_unix(sudo:session): session closed for user root Mar 25 08:58:37 katarynka sudo[14806]: pam_unix(sudo:session): session closed for user root Mar 25 08:58:37 katarynka volumio[14649]: info: Completed starting Core Plugins Mar 25 08:58:37 katarynka volumio[14649]: info: ------------------------------------------- Mar 25 08:58:37 katarynka volumio[14649]: info: ----- MyVolumio plugins startup ---- Mar 25 08:58:37 katarynka volumio[14649]: info: ------------------------------------------- Mar 25 08:58:37 katarynka volumio[14649]: info: [MyVolumio PluginManager] Fetching plans data.... Mar 25 08:58:37 katarynka go-librespot[14951]: time="2026-03-25T08:58:37+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 25 08:58:37 katarynka go-librespot[14951]: time="2026-03-25T08:58:37+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 25 08:58:37 katarynka go-librespot[14951]: time="2026-03-25T08:58:37+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 25 08:58:37 katarynka go-librespot[14951]: time="2026-03-25T08:58:37+01:00" level=info msg="zeroconf server listening on port 42833" Mar 25 08:58:38 katarynka volumio[14649]: error: MPD error: The expression evaluated to a falsy value: Mar 25 08:58:38 katarynka volumio[14649]: assert.ok(self.idling) Mar 25 08:58:38 katarynka volumio[14649]: error: The expression evaluated to a falsy value: Mar 25 08:58:38 katarynka volumio[14649]: assert.ok(self.idling) Mar 25 08:58:38 katarynka volumio[14649]: info: MPD running with PID14845 Mar 25 08:58:38 katarynka volumio[14649]: ,establishing connection Mar 25 08:58:38 katarynka volumio[14649]: error: updateQueue error: null Mar 25 08:58:38 katarynka volumio[14649]: error: updateQueue error: null Mar 25 08:58:38 katarynka go-librespot[14951]: time="2026-03-25T08:58:38+01:00" level=debug msg="obtained new client token: AACK7tEiWRSAZmyrB0Y2fnHpagajNznrSYzMWc78vblvH88TX1aDyj5nyRVLTje44pqlHBzRaeJGtHO7FNcV/PZQUnoQ+BlNZGPMyIi0SFuPBzwTSCpzO9ITlIxnAbZ8a8kvKOQZoZnmNuyFQvPJmcY45Ca3YGKL8y1k1hjimG08BdzYluETbhftk+F15Y8FZwxJn4dlvlvpHMKXKze+KuKOIeKMMLLO68lNhQ7E/soqVYmSAkLiOLHl" Mar 25 08:58:38 katarynka go-librespot[14951]: time="2026-03-25T08:58:38+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 08:58:38 katarynka go-librespot[14951]: time="2026-03-25T08:58:38+01:00" level=debug msg="completed keyexchange" Mar 25 08:58:38 katarynka go-librespot[14951]: time="2026-03-25T08:58:38+01:00" level=debug msg="completed challenge" Mar 25 08:58:38 katarynka go-librespot[14951]: time="2026-03-25T08:58:38+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 25 08:58:38 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 08:58:38 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 08:58:39 katarynka volumio[14649]: info: Initializing connection to go-librespot Websocket Mar 25 08:58:39 katarynka volumio[14649]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 25 08:58:40 katarynka sudo[14978]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Mar 25 08:58:40 katarynka sudo[14978]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 08:58:40 katarynka sudo[14981]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Mar 25 08:58:40 katarynka sudo[14981]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 08:58:40 katarynka systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Mar 25 08:58:40 katarynka systemd[1]: mpd_monitor.service: Deactivated successfully. Mar 25 08:58:40 katarynka systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Mar 25 08:58:41 katarynka systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Mar 25 08:58:41 katarynka sudo[14978]: pam_unix(sudo:session): session closed for user root Mar 25 08:58:41 katarynka mpd_monitor.sh[14983]: MPD Monitor Service: Starting MPD Monitor Service Mar 25 08:58:41 katarynka volumio[14649]: info: Successfully started MPD Monitor Mar 25 08:58:41 katarynka sudo[14981]: pam_unix(sudo:session): session closed for user root Mar 25 08:58:41 katarynka volumio[14649]: info: Successfully started MPD Monitor Mar 25 08:58:41 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Mar 25 08:58:41 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 08:58:41 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 08:58:41 katarynka go-librespot[14987]: go-librespot daemon starting... Mar 25 08:58:41 katarynka go-librespot[14988]: time="2026-03-25T08:58:41+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 08:58:41 katarynka go-librespot[14988]: time="2026-03-25T08:58:41+01:00" level=debug msg="app state loaded" Mar 25 08:58:41 katarynka go-librespot[14988]: time="2026-03-25T08:58:41+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 08:58:41 katarynka go-librespot[14988]: time="2026-03-25T08:58:41+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Mar 25 08:58:41 katarynka go-librespot[14988]: time="2026-03-25T08:58:41+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Mar 25 08:58:41 katarynka go-librespot[14988]: time="2026-03-25T08:58:41+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Mar 25 08:58:41 katarynka go-librespot[14988]: time="2026-03-25T08:58:41+01:00" level=info msg="zeroconf server listening on port 43753" Mar 25 08:58:42 katarynka go-librespot[14988]: time="2026-03-25T08:58:42+01:00" level=debug msg="obtained new client token: AAAz1hh00lsP7vHy6037eW2CEOH5DjW3ZQ9JsVqSAdqn1GKIZlLuJIJ6mxro4tpfnnP1zeKxyUQhruMT8UpTbZqgCLBaQ2P9wUADp8Rnkn3FcK/6JR73+t9c4nTcoElOtyotY60EsKSLVz6Q5P6ezq6akbl3WPeK4TFcwoVTfIG9yOSHKGwlChiZ3DfG+v8wC1AJVgEUIvvEqrfU5MOZMneexlk5+8ABJy6nBI3xlK+nVUQxtTND9zww" Mar 25 08:58:42 katarynka go-librespot[14988]: time="2026-03-25T08:58:42+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 08:58:42 katarynka go-librespot[14988]: time="2026-03-25T08:58:42+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Mar 25 08:58:42 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 08:58:42 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 08:58:42 katarynka volumio[14649]: info: Initializing connection to go-librespot Websocket Mar 25 08:58:42 katarynka volumio[14649]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 25 08:58:42 katarynka volumio[14649]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Mar 25 08:58:45 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Mar 25 08:58:45 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 08:58:45 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 08:58:45 katarynka go-librespot[14995]: go-librespot daemon starting... Mar 25 08:58:45 katarynka go-librespot[14996]: time="2026-03-25T08:58:45+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 08:58:45 katarynka go-librespot[14996]: time="2026-03-25T08:58:45+01:00" level=debug msg="app state loaded" Mar 25 08:58:45 katarynka go-librespot[14996]: time="2026-03-25T08:58:45+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 08:58:45 katarynka volumio[14649]: info: Initializing connection to go-librespot Websocket Mar 25 08:58:45 katarynka go-librespot[14996]: time="2026-03-25T08:58:45+01:00" level=debug msg="new websocket client" Mar 25 08:58:45 katarynka volumio[14649]: info: Connection to go-librespot Websocket established Mar 25 08:58:46 katarynka go-librespot[14996]: time="2026-03-25T08:58:46+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 25 08:58:46 katarynka go-librespot[14996]: time="2026-03-25T08:58:46+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 25 08:58:46 katarynka go-librespot[14996]: time="2026-03-25T08:58:46+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 25 08:58:46 katarynka go-librespot[14996]: time="2026-03-25T08:58:46+01:00" level=info msg="zeroconf server listening on port 34025" Mar 25 08:58:46 katarynka volumio[14649]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Mar 25 08:58:46 katarynka volumio[14649]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Mar 25 08:58:46 katarynka volumio[14649]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Mar 25 08:58:46 katarynka volumio[14649]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Mar 25 08:58:46 katarynka volumio[14649]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Mar 25 08:58:46 katarynka volumio[14649]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Mar 25 08:58:46 katarynka volumio[14649]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Mar 25 08:58:46 katarynka volumio[14649]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Mar 25 08:58:46 katarynka volumio[14649]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Mar 25 08:58:46 katarynka volumio[14649]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Mar 25 08:58:46 katarynka volumio[14649]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Mar 25 08:58:46 katarynka volumio[14649]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Mar 25 08:58:46 katarynka volumio[14649]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Mar 25 08:58:46 katarynka volumio[14649]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Mar 25 08:58:46 katarynka volumio[14649]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Mar 25 08:58:46 katarynka volumio[14649]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Mar 25 08:58:46 katarynka volumio[14649]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Mar 25 08:58:46 katarynka volumio[14649]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Mar 25 08:58:46 katarynka volumio[14649]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Mar 25 08:58:46 katarynka volumio[14649]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Mar 25 08:58:46 katarynka volumio[14649]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Mar 25 08:58:46 katarynka volumio[14649]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Mar 25 08:58:46 katarynka volumio[14649]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Mar 25 08:58:46 katarynka volumio[14649]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Mar 25 08:58:46 katarynka volumio[14649]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Mar 25 08:58:46 katarynka volumio[14649]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Mar 25 08:58:46 katarynka volumio[14649]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Mar 25 08:58:46 katarynka volumio[14649]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Mar 25 08:58:46 katarynka volumio[14649]: info: Adding plugin bluetooth to MyMusic Plugins Mar 25 08:58:46 katarynka volumio[14649]: info: Adding plugin multiroom to MyMusic Plugins Mar 25 08:58:46 katarynka volumio[14649]: info: Adding plugin metavolumio to MyMusic Plugins Mar 25 08:58:46 katarynka volumio[14649]: info: Adding plugin cd_controller to MyMusic Plugins Mar 25 08:58:46 katarynka volumio[14649]: info: Adding plugin qobuzconnect to MyMusic Plugins Mar 25 08:58:46 katarynka volumio[14649]: info: Adding plugin smart_inputs to MyMusic Plugins Mar 25 08:58:46 katarynka volumio[14649]: info: Adding plugin tidalconnect to MyMusic Plugins Mar 25 08:58:46 katarynka go-librespot[14996]: time="2026-03-25T08:58:46+01:00" level=debug msg="obtained new client token: AACJmLQjmhrFkbiaYzYwig/ahDPaW//8/Mu0p+nfoLdbNMOLZa+AcXx6kAd1NVUxNFcf+Kf0PQ3KwaXLKe6B0FiI0gL4s8vGPafx1qozMfo/DBFv/SSJV8+heamPPEIyaNfp6pUDAincUE5k5Um8TxPq4LfnZWIJlBXccgRzbZXOBVqJbnthx9Mo776Xd6PgQhxc0qRWGiN+KRNYCtrBwsnDbeg8TO9AKCauqCxKM4KFNg7P2yAgZPhb9F0=" Mar 25 08:58:46 katarynka volumio[14649]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Mar 25 08:58:46 katarynka go-librespot[14996]: time="2026-03-25T08:58:46+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 08:58:46 katarynka go-librespot[14996]: time="2026-03-25T08:58:46+01:00" level=debug msg="completed keyexchange" Mar 25 08:58:46 katarynka go-librespot[14996]: time="2026-03-25T08:58:46+01:00" level=debug msg="completed challenge" Mar 25 08:58:46 katarynka go-librespot[14996]: time="2026-03-25T08:58:46+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 25 08:58:46 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 08:58:46 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 08:58:48 katarynka volumio[14649]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Mar 25 08:58:48 katarynka volumio[14649]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Mar 25 08:58:48 katarynka volumio[14649]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 08:58:48 katarynka volumio[14649]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 08:58:48 katarynka volumio[14649]: info: Starting MyVolumio Remote Streaming Endpoints Mar 25 08:58:48 katarynka volumio[14649]: info: MyVolumio login type: Token Mar 25 08:58:48 katarynka volumio[14649]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Mar 25 08:58:48 katarynka volumio[14649]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Mar 25 08:58:49 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Mar 25 08:58:49 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 08:58:49 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 08:58:49 katarynka go-librespot[15003]: go-librespot daemon starting... Mar 25 08:58:49 katarynka go-librespot[15004]: time="2026-03-25T08:58:49+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 08:58:49 katarynka go-librespot[15004]: time="2026-03-25T08:58:49+01:00" level=debug msg="app state loaded" Mar 25 08:58:49 katarynka go-librespot[15004]: time="2026-03-25T08:58:49+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 08:58:50 katarynka go-librespot[15004]: time="2026-03-25T08:58:50+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Mar 25 08:58:50 katarynka go-librespot[15004]: time="2026-03-25T08:58:50+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Mar 25 08:58:50 katarynka go-librespot[15004]: time="2026-03-25T08:58:50+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Mar 25 08:58:50 katarynka go-librespot[15004]: time="2026-03-25T08:58:50+01:00" level=info msg="zeroconf server listening on port 46739" Mar 25 08:58:50 katarynka volumio[14649]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Mar 25 08:58:50 katarynka volumio[14649]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Mar 25 08:58:50 katarynka volumio[14649]: info: Streaming services startup Mar 25 08:58:50 katarynka volumio[14649]: info: Starting Streaming Daemon Mar 25 08:58:50 katarynka sudo[15013]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Mar 25 08:58:50 katarynka sudo[15013]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 08:58:50 katarynka volumio[14649]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Mar 25 08:58:50 katarynka go-librespot[15004]: time="2026-03-25T08:58:50+01:00" level=debug msg="obtained new client token: AADlLZCkVTR9WfP8a2YWMZCH/F11NjUfvAvovCJpbGns4MqCB2QW2oit7k8sh0Be7WCcSI9FvCdDZMAf7/8pttRqqOoaf8RBS6/S4iRRD0shB+Y7+1nQFmql9/lTuMPLQGw0UYk56qU9dtqAf5MLO6BP57of4pYKIDAhPm2EaHHdfwULgrwzUdg1GehmnCA0Zq1iDLI6oGV+Dvm1qy2PXmFWTqSNzCwUIec5Rcee9vzdsersuHIUx4TS17E=" Mar 25 08:58:50 katarynka sudo[15013]: pam_unix(sudo:session): session closed for user root Mar 25 08:58:50 katarynka go-librespot[15004]: time="2026-03-25T08:58:50+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 08:58:50 katarynka volumio[14649]: info: Getting Spotify volume Mar 25 08:58:50 katarynka go-librespot[15004]: time="2026-03-25T08:58:50+01:00" level=debug msg="completed keyexchange" Mar 25 08:58:50 katarynka go-librespot[15004]: time="2026-03-25T08:58:50+01:00" level=debug msg="completed challenge" Mar 25 08:58:50 katarynka volumio[14649]: info: Connection to go-librespot Websocket closed Mar 25 08:58:50 katarynka volumio[14649]: error: Cannot start Volumio Streaming Daemon Mar 25 08:58:50 katarynka volumio[14649]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Mar 25 08:58:50 katarynka volumio[14649]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Mar 25 08:58:50 katarynka go-librespot[15004]: time="2026-03-25T08:58:50+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 25 08:58:50 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 08:58:50 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 08:58:50 katarynka volumio[14649]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 25 08:58:50 katarynka volumio[14649]: Error: socket hang up Mar 25 08:58:50 katarynka volumio[14649]: at connResetException (node:internal/errors:720:14) Mar 25 08:58:50 katarynka volumio[14649]: at Socket.socketOnEnd (node:_http_client:519:23) Mar 25 08:58:50 katarynka volumio[14649]: at Socket.emit (node:events:526:35) Mar 25 08:58:50 katarynka volumio[14649]: at endReadableNT (node:internal/streams/readable:1376:12) Mar 25 08:58:50 katarynka volumio[14649]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Mar 25 08:58:50 katarynka volumio[14649]: code: 'ECONNRESET', Mar 25 08:58:50 katarynka volumio[14649]: response: undefined Mar 25 08:58:50 katarynka volumio[14649]: } Mar 25 08:58:50 katarynka volumio[14649]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 25 08:58:52 katarynka sudo[15047]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-03-25 08:57' Mar 25 08:58:52 katarynka sudo[15047]: 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"