Mar 25 08:43:00 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Mar 25 08:43:00 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 08:43:00 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 08:43:00 katarynka go-librespot[10228]: go-librespot daemon starting... Mar 25 08:43:00 katarynka go-librespot[10229]: time="2026-03-25T08:43:00+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 08:43:00 katarynka go-librespot[10229]: time="2026-03-25T08:43:00+01:00" level=debug msg="app state loaded" Mar 25 08:43:00 katarynka go-librespot[10229]: time="2026-03-25T08:43:00+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 08:43:00 katarynka go-librespot[10229]: time="2026-03-25T08:43:00+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 25 08:43:00 katarynka go-librespot[10229]: time="2026-03-25T08:43:00+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:43:00 katarynka go-librespot[10229]: time="2026-03-25T08:43:00+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:43:00 katarynka go-librespot[10229]: time="2026-03-25T08:43:00+01:00" level=info msg="zeroconf server listening on port 45775" Mar 25 08:43:00 katarynka go-librespot[10229]: time="2026-03-25T08:43:00+01:00" level=debug msg="obtained new client token: AADEFrJ8iVUJiEvSbR4oEg4libn93SNs952xlaHrk48z1NrCvJAmJiAWJS5TJpeBcWQErRQyHg55Ac/kQ0MJg5br0HmE1mK6D9w8mHZ3d/YszVBgbJB2gneG0O69iTRTzGPw7RmDlScXq8LDsmLyp4fq2j6KB13VshxId/bFGYUJnh+XnLUIJoL+pYsLmrTgBLyrbB9XNMUDn+ix2ieKGb0CmFtjGhZ2m9iw6KA3yGxWslCvMNG1oKGhA9A=" Mar 25 08:43:00 katarynka go-librespot[10229]: time="2026-03-25T08:43:00+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 08:43:01 katarynka go-librespot[10229]: time="2026-03-25T08:43:01+01:00" level=debug msg="completed keyexchange" Mar 25 08:43:01 katarynka go-librespot[10229]: time="2026-03-25T08:43:01+01:00" level=debug msg="completed challenge" Mar 25 08:43:01 katarynka go-librespot[10229]: time="2026-03-25T08:43:01+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 25 08:43:01 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 08:43:01 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 08:43:01 katarynka volumio[10189]: info: Loading plugin "network"... Mar 25 08:43:01 katarynka volumio[10189]: info: Refreshing Cached IP Addresses Mar 25 08:43:01 katarynka sudo[10237]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 25 08:43:01 katarynka sudo[10237]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 08:43:01 katarynka sudo[10239]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 25 08:43:01 katarynka sudo[10237]: pam_unix(sudo:session): session closed for user root Mar 25 08:43:01 katarynka sudo[10239]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 08:43:01 katarynka volumio[10189]: info: Loading plugin "services"... Mar 25 08:43:01 katarynka volumio[10189]: info: Loading plugin "alsa_controller"... Mar 25 08:43:01 katarynka sudo[10239]: pam_unix(sudo:session): session closed for user root Mar 25 08:43:01 katarynka sudo[10247]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Mar 25 08:43:02 katarynka sudo[10247]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 08:43:02 katarynka volumio[10189]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 25 08:43:02 katarynka volumio[10189]: info: Loading plugin "wizard"... Mar 25 08:43:02 katarynka volumio[10189]: info: Loading plugin "networkfs"... Mar 25 08:43:02 katarynka volumio[10189]: info: Starting Udev Watcher for removable devices Mar 25 08:43:02 katarynka volumio[10189]: info: Ignoring mount for partition: boot Mar 25 08:43:02 katarynka volumio[10189]: info: Ignoring mount for partition: volumio Mar 25 08:43:02 katarynka volumio[10189]: info: Ignoring mount for partition: volumio_data Mar 25 08:43:02 katarynka volumio[10189]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 25 08:43:02 katarynka volumio[10189]: info: Loading plugin "volumio_command_line_client"... Mar 25 08:43:02 katarynka volumio[10189]: info: Loading plugin "upnp"... Mar 25 08:43:02 katarynka volumio[10189]: info: [1774424582275] Starting Upmpd Daemon Mar 25 08:43:02 katarynka volumio[10189]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 25 08:43:02 katarynka volumio[10189]: info: Loading plugin "my_music"... Mar 25 08:43:02 katarynka volumio[10189]: info: Loading plugin "mpd"... Mar 25 08:43:02 katarynka sudo[10247]: pam_unix(sudo:session): session closed for user root Mar 25 08:43:02 katarynka volumio[10189]: info: Loading plugin "upnp_browser"... Mar 25 08:43:04 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Mar 25 08:43:04 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 08:43:04 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 08:43:04 katarynka go-librespot[10270]: go-librespot daemon starting... Mar 25 08:43:04 katarynka go-librespot[10271]: time="2026-03-25T08:43:04+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 08:43:04 katarynka go-librespot[10271]: time="2026-03-25T08:43:04+01:00" level=debug msg="app state loaded" Mar 25 08:43:04 katarynka go-librespot[10271]: time="2026-03-25T08:43:04+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 08:43:04 katarynka go-librespot[10271]: time="2026-03-25T08:43:04+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 25 08:43:04 katarynka go-librespot[10271]: time="2026-03-25T08:43:04+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:43:04 katarynka go-librespot[10271]: time="2026-03-25T08:43:04+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:43:04 katarynka go-librespot[10271]: time="2026-03-25T08:43:04+01:00" level=info msg="zeroconf server listening on port 46603" Mar 25 08:43:04 katarynka go-librespot[10271]: time="2026-03-25T08:43:04+01:00" level=debug msg="obtained new client token: AAAv5w8C03a2PngaP+xZdyUveeoY/lAyUoRPgyfZ8qbkCza/XBdsiV5fj8J5/TsjyE15fox5kNIsgTi7XhE+6n6WbnOutF81OwPpKrVc3fzufeJvTnD+hLOFvAPRXSh6+Yt1JUlUaW9XLENi5cZe2BDE9ibBqrA/IyoBZfwQv+H1PlioWz08DMx3yXpdVfYJBNpxr/0LpiGiIO4xe26ypjFwDR8UETRmmCyWv67OIuqOx4B1Obwsjo60uvQ=" Mar 25 08:43:04 katarynka go-librespot[10271]: time="2026-03-25T08:43:04+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 08:43:05 katarynka go-librespot[10271]: time="2026-03-25T08:43:05+01:00" level=debug msg="completed keyexchange" Mar 25 08:43:05 katarynka go-librespot[10271]: time="2026-03-25T08:43:05+01:00" level=debug msg="completed challenge" Mar 25 08:43:05 katarynka go-librespot[10271]: time="2026-03-25T08:43:05+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 25 08:43:05 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 08:43:05 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 08:43:05 katarynka volumio[10189]: info: Starting UPNP Browser Mar 25 08:43:05 katarynka volumio[10189]: info: Loading plugin "alarm-clock"... Mar 25 08:43:06 katarynka volumio[10189]: info: Loading plugin "airplay_emulation"... Mar 25 08:43:06 katarynka volumio[10189]: info: Starting Shairport Sync Mar 25 08:43:06 katarynka volumio[10189]: info: Loading plugin "last_100"... Mar 25 08:43:06 katarynka volumio[10189]: info: Loading plugin "webradio"... Mar 25 08:43:06 katarynka volumio[10189]: info: Loading plugin "i2s_dacs"... Mar 25 08:43:06 katarynka volumio[10189]: info: Loading plugin "volumiodiscovery"... Mar 25 08:43:06 katarynka volumio[10189]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Mar 25 08:43:06 katarynka volumio[10189]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 25 08:43:06 katarynka volumio[10189]: *** WARNING *** For more information see Mar 25 08:43:06 katarynka volumio[10189]: *** 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:43:06 katarynka volumio[10189]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 25 08:43:06 katarynka volumio[10189]: *** WARNING *** For more information see Mar 25 08:43:06 katarynka node[10189]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Mar 25 08:43:06 katarynka node[10189]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 25 08:43:06 katarynka node[10189]: *** WARNING *** For more information see Mar 25 08:43:06 katarynka volumio[10189]: info: Applying required configuration parameters for plugin volumiodiscovery Mar 25 08:43:06 katarynka node[10189]: *** 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:43:06 katarynka node[10189]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 25 08:43:06 katarynka node[10189]: *** WARNING *** For more information see Mar 25 08:43:06 katarynka volumio[10189]: info: Discovery: Started advertising with name: katarynka Mar 25 08:43:06 katarynka volumio[10189]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 25 08:43:06 katarynka volumio[10189]: info: Loading plugin "spop"... Mar 25 08:43:08 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Mar 25 08:43:08 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 08:43:08 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 08:43:08 katarynka go-librespot[10281]: go-librespot daemon starting... Mar 25 08:43:08 katarynka go-librespot[10282]: time="2026-03-25T08:43:08+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 08:43:08 katarynka go-librespot[10282]: time="2026-03-25T08:43:08+01:00" level=debug msg="app state loaded" Mar 25 08:43:08 katarynka go-librespot[10282]: time="2026-03-25T08:43:08+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 08:43:08 katarynka go-librespot[10282]: time="2026-03-25T08:43:08+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 25 08:43:08 katarynka go-librespot[10282]: time="2026-03-25T08:43:08+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 25 08:43:08 katarynka go-librespot[10282]: time="2026-03-25T08:43:08+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 25 08:43:08 katarynka go-librespot[10282]: time="2026-03-25T08:43:08+01:00" level=info msg="zeroconf server listening on port 33493" Mar 25 08:43:08 katarynka volumio[10189]: info: Loading plugin "outputs"... Mar 25 08:43:08 katarynka volumio[10189]: info: Loading plugin "albumart"... Mar 25 08:43:08 katarynka volumio[10189]: info: Plugin example_plugin is not enabled Mar 25 08:43:08 katarynka volumio[10189]: info: Loading plugin "inputs"... Mar 25 08:43:08 katarynka go-librespot[10282]: time="2026-03-25T08:43:08+01:00" level=debug msg="obtained new client token: AADjXA+aPwtwxCVeR0sWPmZcE4sec1JOWLke4RG+k6qf8tHAsJ+gSNgKYlFqooaN6Qn27a/4duoOCe+ALbH2ugHgdyJXC6AIQLZa9KbTVTwC6mfdccsLZgWrZkTobuqjCuZ9W1oMiE0nRsn6Q2O/Yebog9l28QAFdQHAW7hN2YXs0ExUCvcKU4JuSGoCKkEzk+Z5AzyjEQ25jcYVu3VnG5fL85IdslRTX0mLWTa4GRgD0sOxN+rHfN0ci60=" Mar 25 08:43:08 katarynka volumio[10189]: info: Loading plugin "updater_comm"... Mar 25 08:43:08 katarynka go-librespot[10282]: time="2026-03-25T08:43:08+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 08:43:09 katarynka go-librespot[10282]: time="2026-03-25T08:43:09+01:00" level=debug msg="completed keyexchange" Mar 25 08:43:09 katarynka go-librespot[10282]: time="2026-03-25T08:43:09+01:00" level=debug msg="completed challenge" Mar 25 08:43:09 katarynka go-librespot[10282]: time="2026-03-25T08:43:09+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:43:09 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 08:43:09 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 08:43:09 katarynka volumio[10189]: info: Plugin mpdemulation is not enabled Mar 25 08:43:09 katarynka volumio[10189]: info: Loading plugin "rest_api"... Mar 25 08:43:09 katarynka volumio[10189]: info: Loading plugin "websocket"... Mar 25 08:43:09 katarynka volumio[10189]: info: Starting Socket.io Server version 1.7.4 Mar 25 08:43:09 katarynka volumio[10189]: info: Loading i18n strings for locale pl Mar 25 08:43:09 katarynka volumio[10189]: Updating browse sources language Mar 25 08:43:09 katarynka volumio[10189]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 25 08:43:09 katarynka volumio[10189]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 25 08:43:09 katarynka volumio[10189]: info: CoreCommandRouter::initPlayerControls Mar 25 08:43:09 katarynka volumio[10189]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 08:43:09 katarynka volumio[10189]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 08:43:09 katarynka volumio[10189]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 08:43:09 katarynka volumio[10189]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 08:43:09 katarynka volumio[10189]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 08:43:09 katarynka volumio[10189]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 08:43:09 katarynka volumio[10189]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 08:43:09 katarynka volumio[10189]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 08:43:09 katarynka volumio[10189]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 25 08:43:09 katarynka volumio[10189]: Express server listening on port 3000 Mar 25 08:43:09 katarynka volumio[10189]: [Metrics] WebUI: 12s 526.27ms Mar 25 08:43:09 katarynka volumio[10189]: info: CoreStateMachine::resetVolumioState Mar 25 08:43:09 katarynka volumio[10189]: info: CoreStateMachine::getcurrentVolume Mar 25 08:43:09 katarynka volumio[10189]: info: CoreCommandRouter::volumioRetrievevolume Mar 25 08:43:09 katarynka volumio[10189]: info: Cannot read play queue from file Mar 25 08:43:09 katarynka volumio[10189]: info: Volumio Network Manager: Network status updated: 2 Mar 25 08:43:09 katarynka volumio[10289]: Forking 3 albumart workers Mar 25 08:43:10 katarynka volumio[10189]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 08:43:10 katarynka volumio[10189]: info: CoreStateMachine::setRepeat null single undefined Mar 25 08:43:10 katarynka volumio[10189]: info: CoreStateMachine::pushState Mar 25 08:43:10 katarynka volumio[10189]: info: CorePlayQueue::getTrack 0 Mar 25 08:43:10 katarynka volumio[10189]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 25 08:43:10 katarynka volumio[10189]: info: CoreCommandRouter::volumioPushState Mar 25 08:43:10 katarynka volumio[10189]: info: CoreStateMachine::setRandom null Mar 25 08:43:10 katarynka volumio[10189]: info: CoreStateMachine::pushState Mar 25 08:43:10 katarynka volumio[10189]: info: CorePlayQueue::getTrack 0 Mar 25 08:43:10 katarynka volumio[10189]: info: CoreCommandRouter::volumioPushState Mar 25 08:43:10 katarynka volumio[10189]: info: Setting Device type: Raspberry PI Mar 25 08:43:10 katarynka volumio[10189]: info: Completed loading Core Plugins Mar 25 08:43:10 katarynka volumio[10189]: info: Preparing to generate the ALSA configuration file Mar 25 08:43:10 katarynka volumio[10189]: info: VolumeController:: Volume=96 Mute =false Mar 25 08:43:10 katarynka volumio[10189]: info: CoreStateMachine::pushState Mar 25 08:43:10 katarynka volumio[10189]: info: CorePlayQueue::getTrack 0 Mar 25 08:43:10 katarynka volumio[10189]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 25 08:43:10 katarynka volumio[10189]: info: CoreCommandRouter::volumioPushState Mar 25 08:43:10 katarynka volumio[10189]: info: CoreStateMachine::updateTrackBlock Mar 25 08:43:10 katarynka volumio[10189]: info: CorePlayQueue::getTrackBlock Mar 25 08:43:10 katarynka volumio[10189]: info: CoreCommandRouter::volumioRetrievevolume Mar 25 08:43:10 katarynka volumio[10189]: info: Asound.conf file unchanged, so no further update is needed Mar 25 08:43:10 katarynka volumio[10189]: info: Output device has changed, restarting MPD Mar 25 08:43:10 katarynka volumio[10189]: info: Output device has changed, restarting Shairport Sync Mar 25 08:43:10 katarynka volumio[10189]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 08:43:10 katarynka volumio[10189]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 08:43:10 katarynka volumio[10189]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 25 08:43:10 katarynka sudo[10346]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 25 08:43:10 katarynka sudo[10346]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 08:43:10 katarynka volumio[10189]: info: ___________ START PLUGINS ___________ Mar 25 08:43:10 katarynka sudo[10348]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 25 08:43:10 katarynka sudo[10348]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 08:43:10 katarynka sudo[10346]: pam_unix(sudo:session): session closed for user root Mar 25 08:43:10 katarynka volumio[10189]: info: ControllerMpd::onStart: Initializing MPD Mar 25 08:43:10 katarynka volumio[10189]: info: Creating MPD Configuration file Mar 25 08:43:10 katarynka volumio[10189]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 25 08:43:10 katarynka volumio[10189]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 25 08:43:10 katarynka volumio[10189]: info: [1774424590754] CoreMusicLibrary::Adding element Serwery Mediów Mar 25 08:43:10 katarynka volumio[10189]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 25 08:43:10 katarynka systemd[1]: Stopping mpd.service - Music Player Daemon... Mar 25 08:43:10 katarynka sudo[10358]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 25 08:43:10 katarynka sudo[10358]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 08:43:10 katarynka sudo[10356]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 25 08:43:10 katarynka sudo[10356]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 08:43:10 katarynka volumio[10189]: info: UPNP Browser: Client initialized successfully Mar 25 08:43:10 katarynka sudo[10356]: pam_unix(sudo:session): session closed for user root Mar 25 08:43:10 katarynka systemd[1]: mpd.service: Deactivated successfully. Mar 25 08:43:10 katarynka systemd[1]: Stopped mpd.service - Music Player Daemon. Mar 25 08:43:10 katarynka systemd[1]: mpd.service: Consumed 7.705s CPU time. Mar 25 08:43:10 katarynka systemd[1]: mpd.socket: Deactivated successfully. Mar 25 08:43:10 katarynka systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Mar 25 08:43:10 katarynka systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Mar 25 08:43:10 katarynka volumio[10189]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 08:43:10 katarynka volumio[10189]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 08:43:11 katarynka volumio[10189]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 25 08:43:11 katarynka systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Mar 25 08:43:11 katarynka volumio[10189]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 08:43:11 katarynka volumio[10189]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 08:43:11 katarynka systemd[1]: Starting mpd.service - Music Player Daemon... Mar 25 08:43:11 katarynka systemd[1]: mpd.service: Deactivated successfully. Mar 25 08:43:11 katarynka systemd[1]: Stopped mpd.service - Music Player Daemon. Mar 25 08:43:11 katarynka volumio[10189]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 25 08:43:11 katarynka systemd[1]: mpd.socket: Deactivated successfully. Mar 25 08:43:11 katarynka systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Mar 25 08:43:11 katarynka systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Mar 25 08:43:11 katarynka volumio[10189]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 25 08:43:11 katarynka volumio[10189]: info: [1774424591167] CoreMusicLibrary::Adding element Last_100 Mar 25 08:43:11 katarynka volumio[10189]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 25 08:43:11 katarynka volumio[10189]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 25 08:43:11 katarynka volumio[10189]: info: [1774424591176] CoreMusicLibrary::Adding element Webradio Mar 25 08:43:11 katarynka volumio[10189]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 25 08:43:11 katarynka volumio[10189]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 25 08:43:11 katarynka volumio[10189]: info: Initializing BBC Radios Mar 25 08:43:11 katarynka systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Mar 25 08:43:11 katarynka systemd[1]: Starting mpd.service - Music Player Daemon... Mar 25 08:43:11 katarynka volumio-remote-updater[622]: [2026-03-25 08:43:11] [connect] Successful connection Mar 25 08:43:11 katarynka volumio[10189]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 25 08:43:11 katarynka volumio[10189]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 08:43:11 katarynka volumio[10189]: info: Creating Spotify config file Mar 25 08:43:11 katarynka volumio[10189]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 08:43:11 katarynka sudo[10374]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Mar 25 08:43:11 katarynka sudo[10374]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Mar 25 08:43:11 katarynka sudo[10374]: pam_unix(sudo:session): session closed for user root Mar 25 08:43:12 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 11. Mar 25 08:43:12 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 08:43:12 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 08:43:12 katarynka go-librespot[10398]: go-librespot daemon starting... Mar 25 08:43:12 katarynka go-librespot[10403]: time="2026-03-25T08:43:12+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 08:43:12 katarynka volumio[10189]: info: Volumio Calling Home Mar 25 08:43:12 katarynka go-librespot[10403]: time="2026-03-25T08:43:12+01:00" level=info msg="zeroconf server listening on port 43083" Mar 25 08:43:13 katarynka volumio[10189]: info: Discovery: adding 4d616d77-6a8c-4da2-85a4-840d70f98e51 Mar 25 08:43:13 katarynka volumio[10189]: info: Discovery: Found device katarynka Mar 25 08:43:13 katarynka volumio[10189]: info: CoreCommandRouter::volumioGetState Mar 25 08:43:13 katarynka volumio[10189]: info: CorePlayQueue::getTrack 0 Mar 25 08:43:13 katarynka sudo[10414]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 25 08:43:13 katarynka sudo[10414]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 08:43:13 katarynka sudo[10414]: pam_unix(sudo:session): session closed for user root Mar 25 08:43:13 katarynka volumio[10189]: info: MPD Permissions set Mar 25 08:43:13 katarynka volumio[10189]: info: MPD Permissions set Mar 25 08:43:13 katarynka volumio[10189]: info: VolumeController:: Volume=96 Mute =false Mar 25 08:43:13 katarynka volumio[10189]: info: CoreStateMachine::pushState Mar 25 08:43:13 katarynka volumio[10189]: info: CorePlayQueue::getTrack 0 Mar 25 08:43:13 katarynka volumio[10189]: info: CoreCommandRouter::volumioPushState Mar 25 08:43:13 katarynka sudo[10416]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 25 08:43:13 katarynka sudo[10416]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 08:43:13 katarynka volumio[10189]: info: Discovery: this is already registered, 4d616d77-6a8c-4da2-85a4-840d70f98e51 Mar 25 08:43:13 katarynka volumio[10189]: info: Discovery: Found device katarynka Mar 25 08:43:13 katarynka volumio[10189]: info: CoreCommandRouter::volumioGetState Mar 25 08:43:13 katarynka volumio[10189]: info: CorePlayQueue::getTrack 0 Mar 25 08:43:13 katarynka sudo[10416]: pam_unix(sudo:session): session closed for user root Mar 25 08:43:13 katarynka volumio-remote-updater[622]: [2026-03-25 08:43:13] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1774424591 101 Mar 25 08:43:13 katarynka volumio[10189]: 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:43:13 katarynka volumio[10312]: Starting albumart workers Mar 25 08:43:13 katarynka volumio[10189]: info: Spotify config file written Mar 25 08:43:14 katarynka sudo[10420]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Mar 25 08:43:14 katarynka sudo[10420]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 08:43:14 katarynka systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Mar 25 08:43:14 katarynka systemd[1]: go-librespot-daemon.service: Deactivated successfully. Mar 25 08:43:14 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 08:43:14 katarynka volumio[10310]: Starting albumart workers Mar 25 08:43:14 katarynka volumio[10189]: 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:43:14 katarynka volumio[10189]: info: Volumio called home Mar 25 08:43:14 katarynka volumio[10308]: Starting albumart workers Mar 25 08:43:14 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 08:43:14 katarynka go-librespot[10422]: go-librespot daemon starting... Mar 25 08:43:14 katarynka sudo[10420]: pam_unix(sudo:session): session closed for user root Mar 25 08:43:14 katarynka volumio[10189]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 08:43:14 katarynka volumio[10189]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 08:43:14 katarynka volumio[10189]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 08:43:14 katarynka volumio[10189]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 08:43:14 katarynka volumio[10189]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 08:43:14 katarynka volumio[10189]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 08:43:14 katarynka volumio[10189]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 08:43:14 katarynka volumio[10189]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 08:43:14 katarynka go-librespot[10423]: time="2026-03-25T08:43:14+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 08:43:14 katarynka volumio[10189]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 08:43:14 katarynka go-librespot[10423]: time="2026-03-25T08:43:14+01:00" level=debug msg="app state loaded" Mar 25 08:43:14 katarynka go-librespot[10423]: time="2026-03-25T08:43:14+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 08:43:14 katarynka volumio[10189]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 08:43:14 katarynka volumio[10189]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 08:43:14 katarynka volumio[10189]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 08:43:14 katarynka volumio[10189]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 08:43:14 katarynka volumio[10189]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 08:43:14 katarynka volumio[10189]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 08:43:14 katarynka volumio[10189]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 08:43:14 katarynka volumio[10189]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 08:43:14 katarynka volumio[10189]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 08:43:14 katarynka volumio[10189]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 08:43:14 katarynka volumio[10189]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 08:43:14 katarynka volumio[10189]: info: No need to fix Spotify hosts Mar 25 08:43:15 katarynka go-librespot[10423]: time="2026-03-25T08:43:15+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Mar 25 08:43:15 katarynka go-librespot[10423]: time="2026-03-25T08:43:15+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:43:15 katarynka go-librespot[10423]: time="2026-03-25T08:43:15+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:43:15 katarynka go-librespot[10423]: time="2026-03-25T08:43:15+01:00" level=info msg="zeroconf server listening on port 44459" Mar 25 08:43:15 katarynka go-librespot[10423]: time="2026-03-25T08:43:15+01:00" level=debug msg="obtained new client token: AADUGUdY09paY4HGuESFiGsyya6i6FJFMkjlTLz3oY8ESYvfxFCeM+My9H1qb9NeP/ipE/1VCqdl27ndXBscvc6pqzgVczdlDl1P/+SeTj9utdtd+BQiBoABUZPiLzb/IUfuHtKxa0GdGNNQTrJlTbD5eLqXkWBbpNYfgo8g0tp1mr4dH8qdNyu+5wQAb1wwS6HiDcKuBoElcdP0ziv0oZfPH/Sv+bBbnuRENBB0O6T3LlgJeOuj9+9+" Mar 25 08:43:15 katarynka go-librespot[10423]: time="2026-03-25T08:43:15+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 08:43:15 katarynka go-librespot[10423]: time="2026-03-25T08:43:15+01:00" level=debug msg="completed keyexchange" Mar 25 08:43:15 katarynka go-librespot[10423]: time="2026-03-25T08:43:15+01:00" level=debug msg="completed challenge" Mar 25 08:43:15 katarynka go-librespot[10423]: time="2026-03-25T08:43: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:43:15 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 08:43:15 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 08:43:15 katarynka volumio[10189]: info: Starting Shairport Sync Mar 25 08:43:15 katarynka volumio[10189]: info: Starting Shairport Sync Mar 25 08:43:15 katarynka sudo[10441]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 25 08:43:15 katarynka sudo[10441]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 08:43:15 katarynka volumio[10189]: info: Starting Shairport Sync Mar 25 08:43:15 katarynka sudo[10444]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 25 08:43:15 katarynka sudo[10444]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 08:43:15 katarynka systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Mar 25 08:43:15 katarynka systemd[1]: shairport-sync.service: Deactivated successfully. Mar 25 08:43:15 katarynka systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 25 08:43:15 katarynka systemd[1]: shairport-sync.service: Consumed 2.318s CPU time. Mar 25 08:43:15 katarynka systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 25 08:43:15 katarynka sudo[10447]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 25 08:43:15 katarynka sudo[10441]: pam_unix(sudo:session): session closed for user root Mar 25 08:43:15 katarynka sudo[10447]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 08:43:15 katarynka sudo[10450]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Mar 25 08:43:15 katarynka sudo[10450]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 08:43:15 katarynka systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Mar 25 08:43:15 katarynka systemd[1]: shairport-sync.service: Deactivated successfully. Mar 25 08:43:15 katarynka systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 25 08:43:16 katarynka systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 25 08:43:16 katarynka sudo[10444]: pam_unix(sudo:session): session closed for user root Mar 25 08:43:16 katarynka systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Mar 25 08:43:16 katarynka systemd[1]: shairport-sync.service: Deactivated successfully. Mar 25 08:43:16 katarynka systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 25 08:43:16 katarynka sudo[10450]: pam_unix(sudo:session): session closed for user root Mar 25 08:43:16 katarynka systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 25 08:43:16 katarynka sudo[10447]: pam_unix(sudo:session): session closed for user root Mar 25 08:43:16 katarynka volumio[10189]: info: Shairport-Sync Started Mar 25 08:43:16 katarynka volumio[10189]: Error adding Membership: Error: addMembership EINVAL Mar 25 08:43:16 katarynka volumio[10189]: info: Shairport-Sync Started Mar 25 08:43:16 katarynka volumio[10189]: info: Shairport-Sync Started Mar 25 08:43:16 katarynka volumio[10189]: info: Upmpdcli Daemon Started Mar 25 08:43:16 katarynka volumio[10189]: info: An error occurred while refreshing Spotify Token Error: Bad Request Mar 25 08:43:16 katarynka volumio[10189]: info: CoreCommandRouter::volumioGetState Mar 25 08:43:16 katarynka volumio[10189]: info: CorePlayQueue::getTrack 0 Mar 25 08:43:18 katarynka volumio[10189]: info: go-librespot daemon successfully initialized Mar 25 08:43:18 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Mar 25 08:43:18 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 08:43:18 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 08:43:18 katarynka go-librespot[10499]: go-librespot daemon starting... Mar 25 08:43:18 katarynka go-librespot[10500]: time="2026-03-25T08:43:18+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 08:43:18 katarynka go-librespot[10500]: time="2026-03-25T08:43:18+01:00" level=debug msg="app state loaded" Mar 25 08:43:18 katarynka go-librespot[10500]: time="2026-03-25T08:43:18+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 08:43:19 katarynka go-librespot[10500]: time="2026-03-25T08:43:19+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 25 08:43:19 katarynka go-librespot[10500]: time="2026-03-25T08:43:19+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 25 08:43:19 katarynka go-librespot[10500]: time="2026-03-25T08:43:19+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 25 08:43:19 katarynka go-librespot[10500]: time="2026-03-25T08:43:19+01:00" level=info msg="zeroconf server listening on port 43365" Mar 25 08:43:19 katarynka go-librespot[10500]: time="2026-03-25T08:43:19+01:00" level=debug msg="obtained new client token: AABA1GwDDm1GRpvDMWUQuTL1ZS+2VjcIuMNpycQFNyo6LjKD5T2Q0B95jQFQ+Ls2CH/B/4GN6np/zkaLgBXEFI4j29nQ7C6Zz/f+qo7DiZ/7rEOvFQE+VKpzNN3AgoKjsz6bdUSMbVyW5J0kpBQP27knHn3aviRmLxIVHLfTvVq5b+hJKqGzLwRimmqY+mw3R6GJdUFIZSdhD4u4/o0u7cQD+hn7NecvF0RCOimzL6nhO1CV/U1VYodEbRM=" Mar 25 08:43:19 katarynka go-librespot[10500]: time="2026-03-25T08:43:19+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 08:43:19 katarynka go-librespot[10500]: time="2026-03-25T08:43:19+01:00" level=debug msg="completed keyexchange" Mar 25 08:43:19 katarynka go-librespot[10500]: time="2026-03-25T08:43:19+01:00" level=debug msg="completed challenge" Mar 25 08:43:19 katarynka go-librespot[10500]: time="2026-03-25T08:43:19+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 25 08:43:19 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 08:43:19 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 08:43:19 katarynka mpd[10387]: 2026-03-25T08:43:19 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Mar 25 08:43:19 katarynka systemd[1]: Started mpd.service - Music Player Daemon. Mar 25 08:43:19 katarynka sudo[10358]: pam_unix(sudo:session): session closed for user root Mar 25 08:43:19 katarynka sudo[10348]: pam_unix(sudo:session): session closed for user root Mar 25 08:43:19 katarynka volumio[10189]: info: Completed starting Core Plugins Mar 25 08:43:19 katarynka volumio[10189]: info: ------------------------------------------- Mar 25 08:43:19 katarynka volumio[10189]: info: ----- MyVolumio plugins startup ---- Mar 25 08:43:19 katarynka volumio[10189]: info: ------------------------------------------- Mar 25 08:43:19 katarynka volumio[10189]: info: [MyVolumio PluginManager] Fetching plans data.... Mar 25 08:43:19 katarynka volumio[10189]: error: MPD error: The expression evaluated to a falsy value: Mar 25 08:43:19 katarynka volumio[10189]: assert.ok(self.idling) Mar 25 08:43:19 katarynka volumio[10189]: error: The expression evaluated to a falsy value: Mar 25 08:43:19 katarynka volumio[10189]: assert.ok(self.idling) Mar 25 08:43:19 katarynka volumio[10189]: info: MPD running with PID10387 Mar 25 08:43:19 katarynka volumio[10189]: ,establishing connection Mar 25 08:43:19 katarynka volumio[10189]: error: updateQueue error: null Mar 25 08:43:19 katarynka volumio[10189]: error: updateQueue error: null Mar 25 08:43:21 katarynka volumio[10189]: info: Initializing connection to go-librespot Websocket Mar 25 08:43:21 katarynka volumio[10189]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 25 08:43:22 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Mar 25 08:43:22 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 08:43:22 katarynka sudo[10528]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Mar 25 08:43:22 katarynka sudo[10528]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 08:43:22 katarynka sudo[10530]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Mar 25 08:43:22 katarynka sudo[10530]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 08:43:22 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 08:43:22 katarynka go-librespot[10531]: go-librespot daemon starting... Mar 25 08:43:22 katarynka go-librespot[10534]: time="2026-03-25T08:43:22+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 08:43:22 katarynka go-librespot[10534]: time="2026-03-25T08:43:22+01:00" level=debug msg="app state loaded" Mar 25 08:43:22 katarynka go-librespot[10534]: time="2026-03-25T08:43:22+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 08:43:22 katarynka systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Mar 25 08:43:22 katarynka systemd[1]: mpd_monitor.service: Deactivated successfully. Mar 25 08:43:22 katarynka systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Mar 25 08:43:22 katarynka systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Mar 25 08:43:22 katarynka sudo[10530]: pam_unix(sudo:session): session closed for user root Mar 25 08:43:22 katarynka mpd_monitor.sh[10540]: MPD Monitor Service: Starting MPD Monitor Service Mar 25 08:43:22 katarynka sudo[10528]: pam_unix(sudo:session): session closed for user root Mar 25 08:43:22 katarynka volumio[10189]: info: Successfully started MPD Monitor Mar 25 08:43:22 katarynka volumio[10189]: info: Successfully started MPD Monitor Mar 25 08:43:23 katarynka go-librespot[10534]: time="2026-03-25T08:43: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:43:23 katarynka go-librespot[10534]: time="2026-03-25T08:43: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:43:23 katarynka go-librespot[10534]: time="2026-03-25T08:43: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:43:23 katarynka go-librespot[10534]: time="2026-03-25T08:43:23+01:00" level=info msg="zeroconf server listening on port 43269" Mar 25 08:43:23 katarynka go-librespot[10534]: time="2026-03-25T08:43:23+01:00" level=debug msg="obtained new client token: AAB13c9XGn093DLMjtKsyMm+lU5ay0lzWaqYMde0o0SpKiuL9eyFcqPg0lt59oRzgK/nNKHO0kezK4ZczzjEfUxMDR3q0CcMGWituMVFW1OHL/uMbPvLAED37mZwv2k/vDY7D8b/CoWdKefXN7EHSs/P5uQEQKvw6/xzZNGsPy796lkgEWXle12mjv+SVGz0tN7Ivp7ZT815R5JiM58C5yrNaX0TmZKOZoD9TUPDR98jahOOjhzjf69PL6I=" Mar 25 08:43:23 katarynka go-librespot[10534]: time="2026-03-25T08:43:23+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 08:43:23 katarynka go-librespot[10534]: time="2026-03-25T08:43: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:43:23 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 08:43:23 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 08:43:24 katarynka volumio[10189]: info: Initializing connection to go-librespot Websocket Mar 25 08:43:24 katarynka volumio[10189]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 25 08:43:24 katarynka volumio[10189]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Mar 25 08:43:26 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Mar 25 08:43:26 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 08:43:26 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 08:43:26 katarynka go-librespot[10545]: go-librespot daemon starting... Mar 25 08:43:26 katarynka go-librespot[10546]: time="2026-03-25T08:43:26+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 08:43:26 katarynka go-librespot[10546]: time="2026-03-25T08:43:26+01:00" level=debug msg="app state loaded" Mar 25 08:43:26 katarynka go-librespot[10546]: time="2026-03-25T08:43:26+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 08:43:27 katarynka go-librespot[10546]: time="2026-03-25T08:43: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 25 08:43:27 katarynka go-librespot[10546]: time="2026-03-25T08:43:27+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:43:27 katarynka go-librespot[10546]: time="2026-03-25T08:43:27+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:43:27 katarynka go-librespot[10546]: time="2026-03-25T08:43:27+01:00" level=info msg="zeroconf server listening on port 32883" Mar 25 08:43:27 katarynka go-librespot[10546]: time="2026-03-25T08:43:27+01:00" level=debug msg="obtained new client token: AAC3gzl6IuMA6EFMlfZEyfkJDzHX7ZvuaIfPlWX8PnYGolvRsM2nfOy2MGzpLKjMq1hSuFcMwhmUMa2PHJhbY+rqJAkyG1fsKOXX4ty0NHVQ13YfhD99I3ymwCrxlmTzVG4qYP7Mf4tpCnMbdkUoeE0EK2oqs3YkH+IuEWMpRYdzHJ27qEX66M8J1lZhgmxP6qADUPQvpREuChHCbo+774Rvn6NM8GGL5rOABvVfRVPGXZPbYznh7ELq1nc=" Mar 25 08:43:27 katarynka volumio[10189]: info: Initializing connection to go-librespot Websocket Mar 25 08:43:27 katarynka go-librespot[10546]: time="2026-03-25T08:43:27+01:00" level=debug msg="new websocket client" Mar 25 08:43:27 katarynka volumio[10189]: info: Connection to go-librespot Websocket established Mar 25 08:43:27 katarynka go-librespot[10546]: time="2026-03-25T08:43:27+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 08:43:27 katarynka go-librespot[10546]: time="2026-03-25T08:43:27+01:00" level=debug msg="completed keyexchange" Mar 25 08:43:27 katarynka go-librespot[10546]: time="2026-03-25T08:43:27+01:00" level=debug msg="completed challenge" Mar 25 08:43:28 katarynka volumio[10189]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Mar 25 08:43:28 katarynka volumio[10189]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Mar 25 08:43:28 katarynka volumio[10189]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Mar 25 08:43:28 katarynka volumio[10189]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Mar 25 08:43:28 katarynka volumio[10189]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Mar 25 08:43:28 katarynka volumio[10189]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Mar 25 08:43:28 katarynka volumio[10189]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Mar 25 08:43:28 katarynka volumio[10189]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Mar 25 08:43:28 katarynka volumio[10189]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Mar 25 08:43:28 katarynka volumio[10189]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Mar 25 08:43:28 katarynka volumio[10189]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Mar 25 08:43:28 katarynka volumio[10189]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Mar 25 08:43:28 katarynka volumio[10189]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Mar 25 08:43:28 katarynka volumio[10189]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Mar 25 08:43:28 katarynka volumio[10189]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Mar 25 08:43:28 katarynka volumio[10189]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Mar 25 08:43:28 katarynka volumio[10189]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Mar 25 08:43:28 katarynka volumio[10189]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Mar 25 08:43:28 katarynka volumio[10189]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Mar 25 08:43:28 katarynka volumio[10189]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Mar 25 08:43:28 katarynka volumio[10189]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Mar 25 08:43:28 katarynka volumio[10189]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Mar 25 08:43:28 katarynka volumio[10189]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Mar 25 08:43:28 katarynka volumio[10189]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Mar 25 08:43:28 katarynka volumio[10189]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Mar 25 08:43:28 katarynka volumio[10189]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Mar 25 08:43:28 katarynka volumio[10189]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Mar 25 08:43:28 katarynka volumio[10189]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Mar 25 08:43:28 katarynka volumio[10189]: info: Adding plugin bluetooth to MyMusic Plugins Mar 25 08:43:28 katarynka volumio[10189]: info: Adding plugin multiroom to MyMusic Plugins Mar 25 08:43:28 katarynka volumio[10189]: info: Adding plugin metavolumio to MyMusic Plugins Mar 25 08:43:28 katarynka volumio[10189]: info: Adding plugin cd_controller to MyMusic Plugins Mar 25 08:43:28 katarynka volumio[10189]: info: Adding plugin qobuzconnect to MyMusic Plugins Mar 25 08:43:28 katarynka volumio[10189]: info: Adding plugin smart_inputs to MyMusic Plugins Mar 25 08:43:28 katarynka volumio[10189]: info: Adding plugin tidalconnect to MyMusic Plugins Mar 25 08:43:28 katarynka volumio[10189]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Mar 25 08:43:28 katarynka go-librespot[10546]: time="2026-03-25T08:43:28+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 25 08:43:28 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 08:43:28 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 08:43:30 katarynka volumio[10189]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Mar 25 08:43:30 katarynka volumio[10189]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Mar 25 08:43:30 katarynka volumio[10189]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 08:43:30 katarynka volumio[10189]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 08:43:30 katarynka volumio[10189]: info: Starting MyVolumio Remote Streaming Endpoints Mar 25 08:43:30 katarynka volumio[10189]: info: MyVolumio login type: Token Mar 25 08:43:30 katarynka volumio[10189]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Mar 25 08:43:30 katarynka volumio[10189]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Mar 25 08:43:31 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Mar 25 08:43:31 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 08:43:31 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 08:43:31 katarynka go-librespot[10554]: go-librespot daemon starting... Mar 25 08:43:31 katarynka go-librespot[10555]: time="2026-03-25T08:43:31+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 08:43:31 katarynka go-librespot[10555]: time="2026-03-25T08:43:31+01:00" level=debug msg="app state loaded" Mar 25 08:43:31 katarynka go-librespot[10555]: time="2026-03-25T08:43:31+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 08:43:32 katarynka volumio[10189]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Mar 25 08:43:32 katarynka volumio[10189]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Mar 25 08:43:32 katarynka volumio[10189]: info: Streaming services startup Mar 25 08:43:32 katarynka volumio[10189]: info: Starting Streaming Daemon Mar 25 08:43:32 katarynka go-librespot[10555]: time="2026-03-25T08:43:32+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 25 08:43:32 katarynka go-librespot[10555]: time="2026-03-25T08:43:32+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:43:32 katarynka go-librespot[10555]: time="2026-03-25T08:43:32+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:43:32 katarynka go-librespot[10555]: time="2026-03-25T08:43:32+01:00" level=info msg="zeroconf server listening on port 43755" Mar 25 08:43:32 katarynka sudo[10564]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Mar 25 08:43:32 katarynka sudo[10564]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 08:43:32 katarynka volumio[10189]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Mar 25 08:43:32 katarynka sudo[10564]: pam_unix(sudo:session): session closed for user root Mar 25 08:43:32 katarynka go-librespot[10555]: time="2026-03-25T08:43:32+01:00" level=debug msg="obtained new client token: AABQL613cDWAJP1Ycx+FqI7N0oNxcKizpxxCwjIZBKFxJv4k4D/IwDyco15bJL12ljdQzGkrdSsXAS16xaeJpVXdkz9lfLBJqgU7UGI32QtFKei1XkaMi1oaoJFZE33jn9CrafA4mMYavx6txvlnOldyWeX5my9f9CopZB1Ec4DynS3sV+WGybj4MJyQue6ZPTIP+qyEqXp2kUR/N+Kq3mFxLREAi6GZ09wdhm6Of3x1qmxG/AHYwYPp" Mar 25 08:43:32 katarynka volumio[10189]: info: Getting Spotify volume Mar 25 08:43:32 katarynka go-librespot[10555]: time="2026-03-25T08:43:32+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 08:43:32 katarynka volumio[10189]: info: Connection to go-librespot Websocket closed Mar 25 08:43:32 katarynka volumio[10189]: error: Cannot start Volumio Streaming Daemon Mar 25 08:43:32 katarynka volumio[10189]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Mar 25 08:43:32 katarynka volumio[10189]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Mar 25 08:43:32 katarynka go-librespot[10555]: time="2026-03-25T08:43:32+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:43:32 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 08:43:32 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 08:43:32 katarynka volumio[10189]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 25 08:43:32 katarynka volumio[10189]: Error: socket hang up Mar 25 08:43:32 katarynka volumio[10189]: at connResetException (node:internal/errors:720:14) Mar 25 08:43:32 katarynka volumio[10189]: at Socket.socketOnEnd (node:_http_client:519:23) Mar 25 08:43:32 katarynka volumio[10189]: at Socket.emit (node:events:526:35) Mar 25 08:43:32 katarynka volumio[10189]: at endReadableNT (node:internal/streams/readable:1376:12) Mar 25 08:43:32 katarynka volumio[10189]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Mar 25 08:43:32 katarynka volumio[10189]: code: 'ECONNRESET', Mar 25 08:43:32 katarynka volumio[10189]: response: undefined Mar 25 08:43:32 katarynka volumio[10189]: } Mar 25 08:43:32 katarynka volumio[10189]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 25 08:43:33 katarynka sudo[10598]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-03-25 08:42' Mar 25 08:43:33 katarynka sudo[10598]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 08:43:34 katarynka sudo[10598]: pam_unix(sudo:session): session closed for user root Mar 25 08:43:34 katarynka systemd[1]: Starting setdatetime-helper.service - Time Synchronization Helper Service... Mar 25 08:43:34 katarynka systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Mar 25 08:43:34 katarynka volumio-remote-updater[622]: [2026-03-25 08:43:34] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Mar 25 08:43:34 katarynka volumio-remote-updater[622]: [2026-03-25 08:43:34] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Mar 25 08:43:34 katarynka systemd[1]: volumio.service: Failed with result 'exit-code'. Mar 25 08:43:34 katarynka systemd[1]: volumio.service: Consumed 48.734s CPU time. Mar 25 08:43:34 katarynka systemd[1]: Started dynamicswap.service - dynamicswap service. Mar 25 08:43:34 katarynka systemd[1]: dynamicswap.service: Deactivated successfully. Mar 25 08:43:34 katarynka systemd[1]: volumio.service: Scheduled restart job, restart counter is at 26170. Mar 25 08:43:34 katarynka systemd[1]: Started dynamicswap.service - dynamicswap service. Mar 25 08:43:34 katarynka systemd[1]: Stopped volumio.service - Volumio Backend Module. Mar 25 08:43:34 katarynka systemd[1]: volumio.service: Consumed 48.734s CPU time. Mar 25 08:43:34 katarynka systemd[1]: Started volumio.service - Volumio Backend Module. Mar 25 08:43:35 katarynka systemd[1]: dynamicswap.service: Deactivated successfully. Mar 25 08:43:35 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Mar 25 08:43:35 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 08:43:35 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 08:43:35 katarynka go-librespot[10642]: go-librespot daemon starting... Mar 25 08:43:35 katarynka go-librespot[10643]: time="2026-03-25T08:43:35+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 08:43:35 katarynka go-librespot[10643]: time="2026-03-25T08:43:35+01:00" level=debug msg="app state loaded" Mar 25 08:43:35 katarynka go-librespot[10643]: time="2026-03-25T08:43:35+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 08:43:36 katarynka go-librespot[10643]: time="2026-03-25T08:43:36+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 25 08:43:36 katarynka go-librespot[10643]: time="2026-03-25T08:43:36+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:43:36 katarynka go-librespot[10643]: time="2026-03-25T08:43:36+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:43:36 katarynka go-librespot[10643]: time="2026-03-25T08:43:36+01:00" level=info msg="zeroconf server listening on port 45991" Mar 25 08:43:36 katarynka go-librespot[10643]: time="2026-03-25T08:43:36+01:00" level=debug msg="obtained new client token: AACQE5hpuYeRpgWCTO/vp1n8EJFjFH3MpwQYt6rMXUk2qeI9Lzk7GoO+r6aueBh8qkRBsoJmHaoHGunlQUuIu6NFLyQBx5PLIluMabX3CtPaHX5Lcf2yXiW2MYhTneFKgAqr76D165XrM1EvwNYay6TjXWUUtSnfqSFmNAZEJuEpdzdRA4DDez2+CtH57ztGB0zGqH4p9lFztiKtCDaFQux8MPzhxE/HL4d7qGANqQU728n6vX4UnQR/" Mar 25 08:43:36 katarynka go-librespot[10643]: time="2026-03-25T08:43:36+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 08:43:36 katarynka go-librespot[10643]: time="2026-03-25T08:43:36+01:00" level=debug msg="completed keyexchange" Mar 25 08:43:36 katarynka go-librespot[10643]: time="2026-03-25T08:43:36+01:00" level=debug msg="completed challenge" Mar 25 08:43:36 katarynka go-librespot[10643]: time="2026-03-25T08:43: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:43:36 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 08:43:36 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 08:43:37 katarynka systemd[1]: setdatetime-helper.service: Deactivated successfully. Mar 25 08:43:37 katarynka systemd[1]: Finished setdatetime-helper.service - Time Synchronization Helper Service. Mar 25 08:43:37 katarynka systemd[1]: setdatetime-helper.service: Consumed 2.082s CPU time. Mar 25 08:43:39 katarynka volumio[10627]: info: ------------------------------------------- Mar 25 08:43:39 katarynka volumio[10627]: info: ----- Volumio3 ---- Mar 25 08:43:39 katarynka volumio[10627]: info: ------------------------------------------- Mar 25 08:43:39 katarynka volumio[10627]: info: ----- System startup ---- Mar 25 08:43:39 katarynka volumio[10627]: info: ------------------------------------------- Mar 25 08:43:39 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Mar 25 08:43:39 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 08:43:39 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 08:43:39 katarynka go-librespot[10668]: go-librespot daemon starting... Mar 25 08:43:39 katarynka volumio-remote-updater[622]: [2026-03-25 08:43:39] [connect] Successful connection Mar 25 08:43:39 katarynka go-librespot[10669]: time="2026-03-25T08:43:39+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 08:43:39 katarynka go-librespot[10669]: time="2026-03-25T08:43:39+01:00" level=debug msg="app state loaded" Mar 25 08:43:39 katarynka go-librespot[10669]: time="2026-03-25T08:43:39+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 08:43:40 katarynka go-librespot[10669]: time="2026-03-25T08:43:40+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Mar 25 08:43:40 katarynka go-librespot[10669]: time="2026-03-25T08:43:40+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:43:40 katarynka go-librespot[10669]: time="2026-03-25T08:43:40+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:43:40 katarynka go-librespot[10669]: time="2026-03-25T08:43:40+01:00" level=info msg="zeroconf server listening on port 33489" Mar 25 08:43:40 katarynka go-librespot[10669]: time="2026-03-25T08:43:40+01:00" level=debug msg="obtained new client token: AAAfZLd+KO20kNQeh0bLCPZqOuGrsqj62ksSotUt5lg6iFkXXzgtdGp2slzsqyHpC/7OKv/qtTSqwQU1DdntYw91LxUX5uWmEWeI+CnYVW0rfShEvi6kCHCi7XxFhGYi1QU6Lp9aGLjx/xgayjNXvqPP9TbLXM6RABlzSJRE3KD7yL0Ik3MQRgff5voW1ovrQLH+rNyhb4raMkBt2Tx3kksZcgch6x+zmWjf2jodZ14pVMuA4i2FwVIc2Yc=" Mar 25 08:43:40 katarynka go-librespot[10669]: time="2026-03-25T08:43:40+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 08:43:40 katarynka volumio[10627]: info: MYVOLUMIO Environment detected Mar 25 08:43:40 katarynka go-librespot[10669]: time="2026-03-25T08:43:40+01:00" level=debug msg="completed keyexchange" Mar 25 08:43:40 katarynka go-librespot[10669]: time="2026-03-25T08:43:40+01:00" level=debug msg="completed challenge" Mar 25 08:43:40 katarynka go-librespot[10669]: time="2026-03-25T08:43: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:43:40 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 08:43:40 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 08:43:40 katarynka volumio[10627]: info: Plugin folders cleanup Mar 25 08:43:40 katarynka volumio[10627]: info: Scanning into folder /volumio/app/plugins/ Mar 25 08:43:40 katarynka volumio[10627]: info: Scanning category audio_interface Mar 25 08:43:40 katarynka volumio[10627]: info: Scanning category miscellanea Mar 25 08:43:40 katarynka volumio[10627]: info: Scanning category music_service Mar 25 08:43:40 katarynka volumio[10627]: info: Scanning category plugins.json Mar 25 08:43:40 katarynka volumio[10627]: info: Scanning category system_controller Mar 25 08:43:40 katarynka volumio[10627]: info: Scanning category user_interface Mar 25 08:43:40 katarynka volumio[10627]: info: Scanning into folder /data/plugins/ Mar 25 08:43:40 katarynka volumio[10627]: info: Scanning category music_service Mar 25 08:43:40 katarynka volumio[10627]: info: Plugin folders cleanup completed Mar 25 08:43:40 katarynka volumio[10627]: info: ------------------------------------------- Mar 25 08:43:40 katarynka volumio[10627]: info: ----- Core plugins startup ---- Mar 25 08:43:40 katarynka volumio[10627]: info: ------------------------------------------- Mar 25 08:43:40 katarynka volumio[10627]: info: Loading plugins from folder /volumio/app/plugins/ Mar 25 08:43:40 katarynka volumio[10627]: info: Adding plugin upnp to MyMusic Plugins Mar 25 08:43:40 katarynka volumio[10627]: info: Adding plugin airplay_emulation to MyMusic Plugins Mar 25 08:43:40 katarynka volumio[10627]: info: Adding plugin upnp_browser to MyMusic Plugins Mar 25 08:43:40 katarynka volumio[10627]: info: Loading plugins from folder /data/plugins/ Mar 25 08:43:40 katarynka volumio[10627]: info: Loading plugin "system"... Mar 25 08:43:40 katarynka volumio[10627]: info: Loading plugin "appearance"... Mar 25 08:43:42 katarynka volumio[10627]: info: Loading plugin "network"... Mar 25 08:43:42 katarynka volumio[10627]: info: Refreshing Cached IP Addresses Mar 25 08:43:42 katarynka sudo[10683]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 25 08:43:42 katarynka sudo[10683]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 08:43:42 katarynka volumio[10627]: info: Loading plugin "services"... Mar 25 08:43:42 katarynka sudo[10683]: pam_unix(sudo:session): session closed for user root Mar 25 08:43:42 katarynka volumio[10627]: info: Loading plugin "alsa_controller"... Mar 25 08:43:42 katarynka sudo[10685]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 25 08:43:42 katarynka sudo[10692]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Mar 25 08:43:42 katarynka sudo[10685]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 08:43:42 katarynka sudo[10692]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 08:43:43 katarynka sudo[10685]: pam_unix(sudo:session): session closed for user root Mar 25 08:43:43 katarynka volumio[10627]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 25 08:43:43 katarynka volumio[10627]: info: Loading plugin "wizard"... Mar 25 08:43:43 katarynka volumio[10627]: info: Loading plugin "networkfs"... Mar 25 08:43:43 katarynka volumio[10627]: info: Starting Udev Watcher for removable devices Mar 25 08:43:43 katarynka volumio[10627]: info: Ignoring mount for partition: boot Mar 25 08:43:43 katarynka volumio[10627]: info: Ignoring mount for partition: volumio Mar 25 08:43:43 katarynka volumio[10627]: info: Ignoring mount for partition: volumio_data Mar 25 08:43:43 katarynka volumio[10627]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 25 08:43:43 katarynka volumio[10627]: info: Loading plugin "volumio_command_line_client"... Mar 25 08:43:43 katarynka volumio[10627]: info: Loading plugin "upnp"... Mar 25 08:43:43 katarynka volumio[10627]: info: [1774424623286] Starting Upmpd Daemon Mar 25 08:43:43 katarynka volumio[10627]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 25 08:43:43 katarynka volumio[10627]: info: Loading plugin "my_music"... Mar 25 08:43:43 katarynka volumio[10627]: info: Loading plugin "mpd"... Mar 25 08:43:43 katarynka sudo[10692]: pam_unix(sudo:session): session closed for user root Mar 25 08:43:43 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Mar 25 08:43:43 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 08:43:43 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 08:43:43 katarynka go-librespot[10719]: go-librespot daemon starting... Mar 25 08:43:44 katarynka volumio[10627]: info: Loading plugin "upnp_browser"... Mar 25 08:43:44 katarynka go-librespot[10720]: time="2026-03-25T08:43:44+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 08:43:44 katarynka go-librespot[10720]: time="2026-03-25T08:43:44+01:00" level=debug msg="app state loaded" Mar 25 08:43:44 katarynka go-librespot[10720]: time="2026-03-25T08:43:44+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 08:43:44 katarynka go-librespot[10720]: time="2026-03-25T08:43:44+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 25 08:43:44 katarynka go-librespot[10720]: time="2026-03-25T08:43:44+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:43:44 katarynka go-librespot[10720]: time="2026-03-25T08:43:44+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:43:44 katarynka go-librespot[10720]: time="2026-03-25T08:43:44+01:00" level=info msg="zeroconf server listening on port 38825" Mar 25 08:43:44 katarynka go-librespot[10720]: time="2026-03-25T08:43:44+01:00" level=debug msg="obtained new client token: AADIDQd3s/Pb5Xrov2rSKfWun7CqdjK990Wg6y5pbVwrAqtTXTkCwvr6SMGhqMOrfT+AO8eOk5hf0w6K04SmzE+1tsAqXBkbXE8OALigQWMcUS/ne6qelderJpbVc0RY7iExuedgedhI3wJvnWn4VL2HjWZ3mrN7GjpGlGU+0NaI5X+60r/ahZdwcRtyV9L8Dp7WefF7WKz8Rb77HKxT7+Yx2vFcQcSU2o6WKfwcJZLKSoHl+q6Ia5H47Ms=" Mar 25 08:43:44 katarynka go-librespot[10720]: time="2026-03-25T08:43:44+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 08:43:44 katarynka go-librespot[10720]: time="2026-03-25T08:43:44+01:00" level=debug msg="completed keyexchange" Mar 25 08:43:44 katarynka go-librespot[10720]: time="2026-03-25T08:43:44+01:00" level=debug msg="completed challenge" Mar 25 08:43:45 katarynka go-librespot[10720]: time="2026-03-25T08:43:45+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 25 08:43:45 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 08:43:45 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 08:43:47 katarynka volumio[10627]: info: Starting UPNP Browser Mar 25 08:43:47 katarynka volumio[10627]: info: Loading plugin "alarm-clock"... Mar 25 08:43:47 katarynka volumio[10627]: info: Loading plugin "airplay_emulation"... Mar 25 08:43:47 katarynka volumio[10627]: info: Starting Shairport Sync Mar 25 08:43:47 katarynka volumio[10627]: info: Loading plugin "last_100"... Mar 25 08:43:47 katarynka volumio[10627]: info: Loading plugin "webradio"... Mar 25 08:43:47 katarynka volumio[10627]: info: Loading plugin "i2s_dacs"... Mar 25 08:43:47 katarynka volumio[10627]: info: Loading plugin "volumiodiscovery"... Mar 25 08:43:47 katarynka volumio[10627]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Mar 25 08:43:47 katarynka volumio[10627]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 25 08:43:47 katarynka volumio[10627]: *** WARNING *** For more information see Mar 25 08:43:47 katarynka volumio[10627]: *** 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:43:47 katarynka volumio[10627]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 25 08:43:47 katarynka node[10627]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Mar 25 08:43:47 katarynka volumio[10627]: *** WARNING *** For more information see Mar 25 08:43:47 katarynka node[10627]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 25 08:43:47 katarynka node[10627]: *** WARNING *** For more information see Mar 25 08:43:47 katarynka node[10627]: *** 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:43:47 katarynka node[10627]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 25 08:43:47 katarynka node[10627]: *** WARNING *** For more information see Mar 25 08:43:47 katarynka volumio[10627]: info: Applying required configuration parameters for plugin volumiodiscovery Mar 25 08:43:47 katarynka volumio[10627]: info: Discovery: Started advertising with name: katarynka Mar 25 08:43:47 katarynka volumio[10627]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 25 08:43:47 katarynka volumio[10627]: info: Loading plugin "spop"... Mar 25 08:43:48 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Mar 25 08:43:48 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 08:43:48 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 08:43:48 katarynka go-librespot[10729]: go-librespot daemon starting... Mar 25 08:43:48 katarynka go-librespot[10730]: time="2026-03-25T08:43:48+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 08:43:48 katarynka go-librespot[10730]: time="2026-03-25T08:43:48+01:00" level=debug msg="app state loaded" Mar 25 08:43:48 katarynka go-librespot[10730]: time="2026-03-25T08:43:48+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 08:43:49 katarynka go-librespot[10730]: time="2026-03-25T08:43:49+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 25 08:43:49 katarynka go-librespot[10730]: time="2026-03-25T08:43:49+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:43:49 katarynka go-librespot[10730]: time="2026-03-25T08:43:49+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:43:49 katarynka go-librespot[10730]: time="2026-03-25T08:43:49+01:00" level=info msg="zeroconf server listening on port 35413" Mar 25 08:43:49 katarynka go-librespot[10730]: time="2026-03-25T08:43:49+01:00" level=debug msg="obtained new client token: AADu4G/7njUKtisCcQZp5huxPtmXstjXvWfch1H6TAFj5yZhFR/mZ6kQruGDF632aUsBhWUHI/IaYx5ECJHoUSaqRx775h7zh5FccR1BAidF7lREupN0dSoUBVRrdox4HxbZxCCkk6ED4ndWUhFSQ2vev9oEntW0/b6munUAPhhocJtBx8jlx/n5So2irWvgH7Fgf0wi9tfOOpKs1gtdJbnCy4hGiybsuvQUgbTlBAj3IU+9i0anqOZwdyk=" Mar 25 08:43:49 katarynka go-librespot[10730]: time="2026-03-25T08:43:49+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 08:43:49 katarynka go-librespot[10730]: time="2026-03-25T08:43:49+01:00" level=debug msg="completed keyexchange" Mar 25 08:43:49 katarynka go-librespot[10730]: time="2026-03-25T08:43:49+01:00" level=debug msg="completed challenge" Mar 25 08:43:49 katarynka go-librespot[10730]: time="2026-03-25T08:43:49+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 25 08:43:49 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 08:43:49 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 08:43:49 katarynka volumio[10627]: info: Loading plugin "outputs"... Mar 25 08:43:49 katarynka volumio[10627]: info: Loading plugin "albumart"... Mar 25 08:43:50 katarynka volumio[10627]: info: Plugin example_plugin is not enabled Mar 25 08:43:50 katarynka volumio[10627]: info: Loading plugin "inputs"... Mar 25 08:43:50 katarynka volumio[10627]: info: Loading plugin "updater_comm"... Mar 25 08:43:50 katarynka volumio[10627]: info: Plugin mpdemulation is not enabled Mar 25 08:43:50 katarynka volumio[10627]: info: Loading plugin "rest_api"... Mar 25 08:43:50 katarynka volumio[10627]: info: Loading plugin "websocket"... Mar 25 08:43:50 katarynka volumio[10627]: info: Starting Socket.io Server version 1.7.4 Mar 25 08:43:50 katarynka volumio[10627]: info: Loading i18n strings for locale pl Mar 25 08:43:50 katarynka volumio[10627]: Updating browse sources language Mar 25 08:43:50 katarynka volumio[10627]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 25 08:43:50 katarynka volumio[10627]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 25 08:43:50 katarynka volumio[10627]: info: CoreCommandRouter::initPlayerControls Mar 25 08:43:50 katarynka volumio[10627]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 08:43:50 katarynka volumio[10627]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 08:43:50 katarynka volumio[10627]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 08:43:50 katarynka volumio[10627]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 08:43:50 katarynka volumio[10627]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 08:43:50 katarynka volumio[10627]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 08:43:50 katarynka volumio[10627]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 08:43:50 katarynka volumio[10627]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 08:43:50 katarynka volumio[10627]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 25 08:43:50 katarynka volumio[10627]: Express server listening on port 3000 Mar 25 08:43:50 katarynka volumio[10627]: [Metrics] WebUI: 12s 691.15ms Mar 25 08:43:50 katarynka volumio[10627]: info: CoreStateMachine::resetVolumioState Mar 25 08:43:50 katarynka volumio[10627]: info: CoreStateMachine::getcurrentVolume Mar 25 08:43:50 katarynka volumio[10627]: info: CoreCommandRouter::volumioRetrievevolume Mar 25 08:43:50 katarynka volumio[10627]: info: Cannot read play queue from file Mar 25 08:43:50 katarynka volumio[10627]: info: Volumio Network Manager: Network status updated: 2 Mar 25 08:43:51 katarynka volumio[10738]: Forking 3 albumart workers Mar 25 08:43:51 katarynka volumio[10627]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 08:43:51 katarynka volumio[10627]: info: VolumeController:: Volume=96 Mute =false Mar 25 08:43:51 katarynka volumio[10627]: info: CoreStateMachine::pushState Mar 25 08:43:51 katarynka volumio[10627]: info: CorePlayQueue::getTrack 0 Mar 25 08:43:51 katarynka volumio[10627]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 25 08:43:51 katarynka volumio[10627]: info: CoreCommandRouter::volumioPushState Mar 25 08:43:51 katarynka volumio[10627]: info: CoreStateMachine::updateTrackBlock Mar 25 08:43:51 katarynka volumio[10627]: info: CorePlayQueue::getTrackBlock Mar 25 08:43:51 katarynka volumio[10627]: info: CoreCommandRouter::volumioRetrievevolume Mar 25 08:43:51 katarynka volumio[10627]: info: CoreStateMachine::setRepeat null single undefined Mar 25 08:43:51 katarynka volumio[10627]: info: CoreStateMachine::pushState Mar 25 08:43:51 katarynka volumio[10627]: info: CorePlayQueue::getTrack 0 Mar 25 08:43:51 katarynka volumio[10627]: info: CoreCommandRouter::volumioPushState Mar 25 08:43:51 katarynka volumio[10627]: info: CoreStateMachine::setRandom null Mar 25 08:43:51 katarynka volumio[10627]: info: CoreStateMachine::pushState Mar 25 08:43:51 katarynka volumio[10627]: info: CorePlayQueue::getTrack 0 Mar 25 08:43:51 katarynka volumio[10627]: info: CoreCommandRouter::volumioPushState Mar 25 08:43:51 katarynka volumio[10627]: info: Setting Device type: Raspberry PI Mar 25 08:43:51 katarynka volumio[10627]: info: Completed loading Core Plugins Mar 25 08:43:51 katarynka volumio[10627]: info: Preparing to generate the ALSA configuration file Mar 25 08:43:51 katarynka volumio[10627]: info: Asound.conf file unchanged, so no further update is needed Mar 25 08:43:51 katarynka volumio[10627]: info: Output device has changed, restarting MPD Mar 25 08:43:51 katarynka volumio[10627]: info: Output device has changed, restarting Shairport Sync Mar 25 08:43:51 katarynka volumio[10627]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 08:43:51 katarynka volumio[10627]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 08:43:51 katarynka sudo[10792]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 25 08:43:51 katarynka sudo[10792]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 08:43:51 katarynka volumio[10627]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 25 08:43:51 katarynka sudo[10792]: pam_unix(sudo:session): session closed for user root Mar 25 08:43:51 katarynka volumio[10627]: info: ___________ START PLUGINS ___________ Mar 25 08:43:51 katarynka sudo[10794]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 25 08:43:51 katarynka sudo[10794]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 08:43:51 katarynka volumio[10627]: info: ControllerMpd::onStart: Initializing MPD Mar 25 08:43:51 katarynka volumio[10627]: info: Creating MPD Configuration file Mar 25 08:43:51 katarynka volumio[10627]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 25 08:43:51 katarynka volumio[10627]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 25 08:43:51 katarynka volumio[10627]: info: [1774424631850] CoreMusicLibrary::Adding element Serwery Mediów Mar 25 08:43:51 katarynka volumio[10627]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 25 08:43:51 katarynka volumio[10627]: info: UPNP Browser: Client initialized successfully Mar 25 08:43:51 katarynka systemd[1]: Stopping mpd.service - Music Player Daemon... Mar 25 08:43:51 katarynka sudo[10802]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 25 08:43:51 katarynka sudo[10802]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 08:43:51 katarynka sudo[10804]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 25 08:43:51 katarynka sudo[10804]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 08:43:51 katarynka sudo[10802]: pam_unix(sudo:session): session closed for user root Mar 25 08:43:51 katarynka volumio[10627]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 08:43:51 katarynka volumio[10627]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 08:43:52 katarynka systemd[1]: mpd.service: Deactivated successfully. Mar 25 08:43:52 katarynka systemd[1]: Stopped mpd.service - Music Player Daemon. Mar 25 08:43:52 katarynka systemd[1]: mpd.service: Consumed 7.728s CPU time. Mar 25 08:43:52 katarynka systemd[1]: mpd.socket: Deactivated successfully. Mar 25 08:43:52 katarynka volumio[10627]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 25 08:43:52 katarynka systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Mar 25 08:43:52 katarynka systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Mar 25 08:43:52 katarynka volumio[10627]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 08:43:52 katarynka volumio[10627]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 08:43:52 katarynka systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Mar 25 08:43:52 katarynka volumio[10627]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 25 08:43:52 katarynka volumio[10627]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 25 08:43:52 katarynka volumio[10627]: info: [1774424632196] CoreMusicLibrary::Adding element Last_100 Mar 25 08:43:52 katarynka volumio[10627]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 25 08:43:52 katarynka systemd[1]: Starting mpd.service - Music Player Daemon... Mar 25 08:43:52 katarynka volumio[10627]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 25 08:43:52 katarynka volumio[10627]: info: [1774424632221] CoreMusicLibrary::Adding element Webradio Mar 25 08:43:52 katarynka volumio[10627]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 25 08:43:52 katarynka volumio[10627]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 25 08:43:52 katarynka volumio[10627]: info: Initializing BBC Radios Mar 25 08:43:52 katarynka volumio-remote-updater[622]: [2026-03-25 08:43:52] [connect] Successful connection Mar 25 08:43:52 katarynka volumio[10627]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 25 08:43:52 katarynka volumio[10627]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 08:43:52 katarynka volumio[10627]: info: Creating Spotify config file Mar 25 08:43:52 katarynka volumio[10627]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 08:43:52 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Mar 25 08:43:52 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 08:43:52 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 08:43:52 katarynka go-librespot[10830]: go-librespot daemon starting... Mar 25 08:43:52 katarynka sudo[10816]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Mar 25 08:43:52 katarynka sudo[10816]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Mar 25 08:43:52 katarynka sudo[10816]: pam_unix(sudo:session): session closed for user root Mar 25 08:43:52 katarynka go-librespot[10831]: time="2026-03-25T08:43:52+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 08:43:53 katarynka go-librespot[10831]: time="2026-03-25T08:43:53+01:00" level=info msg="zeroconf server listening on port 43079" Mar 25 08:43:54 katarynka volumio[10627]: info: Volumio Calling Home Mar 25 08:43:54 katarynka volumio[10753]: Starting albumart workers Mar 25 08:43:54 katarynka volumio[10627]: info: Discovery: adding 4d616d77-6a8c-4da2-85a4-840d70f98e51 Mar 25 08:43:54 katarynka volumio[10627]: info: Discovery: Found device katarynka Mar 25 08:43:54 katarynka volumio[10627]: info: CoreCommandRouter::volumioGetState Mar 25 08:43:54 katarynka volumio[10627]: info: CorePlayQueue::getTrack 0 Mar 25 08:43:54 katarynka volumio[10627]: info: Discovery: this is already registered, 4d616d77-6a8c-4da2-85a4-840d70f98e51 Mar 25 08:43:54 katarynka volumio[10627]: info: Discovery: Found device katarynka Mar 25 08:43:54 katarynka volumio[10627]: info: CoreCommandRouter::volumioGetState Mar 25 08:43:54 katarynka volumio[10627]: info: CorePlayQueue::getTrack 0 Mar 25 08:43:54 katarynka volumio[10627]: info: MPD Permissions set Mar 25 08:43:54 katarynka volumio[10627]: info: MPD Permissions set Mar 25 08:43:54 katarynka sudo[10861]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 25 08:43:54 katarynka volumio[10627]: info: VolumeController:: Volume=96 Mute =false Mar 25 08:43:55 katarynka sudo[10861]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 08:43:55 katarynka volumio[10627]: info: CoreStateMachine::pushState Mar 25 08:43:55 katarynka volumio[10627]: info: CorePlayQueue::getTrack 0 Mar 25 08:43:55 katarynka volumio[10754]: Starting albumart workers Mar 25 08:43:55 katarynka volumio[10627]: info: CoreCommandRouter::volumioPushState Mar 25 08:43:55 katarynka sudo[10859]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 25 08:43:55 katarynka sudo[10859]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 08:43:55 katarynka sudo[10861]: pam_unix(sudo:session): session closed for user root Mar 25 08:43:55 katarynka sudo[10859]: pam_unix(sudo:session): session closed for user root Mar 25 08:43:55 katarynka volumio-remote-updater[622]: [2026-03-25 08:43:55] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1774424632 101 Mar 25 08:43:55 katarynka volumio[10627]: 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:43:55 katarynka volumio[10627]: info: Volumio called home Mar 25 08:43:55 katarynka volumio[10627]: info: Spotify config file written Mar 25 08:43:55 katarynka volumio[10752]: Starting albumart workers Mar 25 08:43:55 katarynka sudo[10865]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Mar 25 08:43:55 katarynka sudo[10865]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 08:43:55 katarynka systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Mar 25 08:43:55 katarynka systemd[1]: go-librespot-daemon.service: Deactivated successfully. Mar 25 08:43:55 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 08:43:55 katarynka volumio[10627]: 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:43:55 katarynka go-librespot[10867]: go-librespot daemon starting... Mar 25 08:43:55 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 08:43:55 katarynka volumio[10627]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 08:43:55 katarynka sudo[10865]: pam_unix(sudo:session): session closed for user root Mar 25 08:43:55 katarynka volumio[10627]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 08:43:55 katarynka volumio[10627]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 08:43:55 katarynka volumio[10627]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 08:43:55 katarynka volumio[10627]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 08:43:55 katarynka volumio[10627]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 08:43:55 katarynka volumio[10627]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 08:43:55 katarynka volumio[10627]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 08:43:55 katarynka go-librespot[10868]: time="2026-03-25T08:43:55+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 08:43:55 katarynka go-librespot[10868]: time="2026-03-25T08:43:55+01:00" level=debug msg="app state loaded" Mar 25 08:43:55 katarynka go-librespot[10868]: time="2026-03-25T08:43:55+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 08:43:55 katarynka volumio[10627]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 08:43:55 katarynka volumio[10627]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 08:43:55 katarynka volumio[10627]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 08:43:55 katarynka volumio[10627]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 08:43:55 katarynka volumio[10627]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 08:43:55 katarynka volumio[10627]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 08:43:55 katarynka volumio[10627]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 08:43:55 katarynka volumio[10627]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 08:43:55 katarynka volumio[10627]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 08:43:55 katarynka volumio[10627]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 08:43:56 katarynka volumio[10627]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 08:43:56 katarynka volumio[10627]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 08:43:56 katarynka volumio[10627]: info: No need to fix Spotify hosts Mar 25 08:43:56 katarynka go-librespot[10868]: time="2026-03-25T08:43:56+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 25 08:43:56 katarynka go-librespot[10868]: time="2026-03-25T08:43:56+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:43:56 katarynka go-librespot[10868]: time="2026-03-25T08:43:56+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:43:56 katarynka go-librespot[10868]: time="2026-03-25T08:43:56+01:00" level=info msg="zeroconf server listening on port 39383" Mar 25 08:43:56 katarynka go-librespot[10868]: time="2026-03-25T08:43:56+01:00" level=debug msg="obtained new client token: AABRebnZA+Xr04SBPlvbtLo/bm/fWI/Wm2mBT3dFTUChT2Mn8H2n2TTokHC9uaNg3XjL7xnm+Ujw5dnKiGb2NcmbT1kSI+Ifs5Zo8AYxyyqJjweJubH1orep3M2G1UVlLEwAHs2cxWto11UpxLoMrtI/pvf1BE7BsDAVdk+Y08KkKMgqsmD9q/haxqFdYHwYjygRR6bRb4Sg/hRZCKwYq8YnNgYdYPiDag5c9mhed05LPpLnYWtAH8uH3QA=" Mar 25 08:43:56 katarynka go-librespot[10868]: time="2026-03-25T08:43:56+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 08:43:56 katarynka volumio[10627]: info: Starting Shairport Sync Mar 25 08:43:56 katarynka volumio[10627]: info: Starting Shairport Sync Mar 25 08:43:56 katarynka sudo[10887]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 25 08:43:56 katarynka sudo[10887]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 08:43:56 katarynka go-librespot[10868]: time="2026-03-25T08:43:56+01:00" level=debug msg="completed keyexchange" Mar 25 08:43:56 katarynka go-librespot[10868]: time="2026-03-25T08:43:56+01:00" level=debug msg="completed challenge" Mar 25 08:43:56 katarynka volumio[10627]: info: Starting Shairport Sync Mar 25 08:43:56 katarynka go-librespot[10868]: time="2026-03-25T08:43:56+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 25 08:43:56 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 08:43:56 katarynka sudo[10891]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 25 08:43:56 katarynka sudo[10891]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 08:43:56 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 08:43:57 katarynka systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Mar 25 08:43:57 katarynka systemd[1]: shairport-sync.service: Deactivated successfully. Mar 25 08:43:57 katarynka systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 25 08:43:57 katarynka systemd[1]: shairport-sync.service: Consumed 2.325s CPU time. Mar 25 08:43:57 katarynka sudo[10898]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Mar 25 08:43:57 katarynka sudo[10898]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 08:43:57 katarynka sudo[10895]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 25 08:43:57 katarynka sudo[10895]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 08:43:57 katarynka systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 25 08:43:57 katarynka sudo[10887]: pam_unix(sudo:session): session closed for user root Mar 25 08:43:57 katarynka systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Mar 25 08:43:57 katarynka systemd[1]: shairport-sync.service: Deactivated successfully. Mar 25 08:43:57 katarynka systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 25 08:43:57 katarynka systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 25 08:43:57 katarynka sudo[10891]: pam_unix(sudo:session): session closed for user root Mar 25 08:43:57 katarynka sudo[10895]: pam_unix(sudo:session): session closed for user root Mar 25 08:43:57 katarynka sudo[10898]: pam_unix(sudo:session): session closed for user root Mar 25 08:43:57 katarynka volumio[10627]: info: Shairport-Sync Started Mar 25 08:43:57 katarynka volumio[10627]: Error adding Membership: Error: addMembership EINVAL Mar 25 08:43:57 katarynka volumio[10627]: info: Upmpdcli Daemon Started Mar 25 08:43:57 katarynka volumio[10627]: info: Shairport-Sync Started Mar 25 08:43:57 katarynka volumio[10627]: info: Shairport-Sync Started Mar 25 08:43:57 katarynka volumio[10627]: info: An error occurred while refreshing Spotify Token Error: Bad Request Mar 25 08:43:57 katarynka volumio[10627]: info: CoreCommandRouter::volumioGetState Mar 25 08:43:57 katarynka volumio[10627]: info: CorePlayQueue::getTrack 0 Mar 25 08:43:59 katarynka volumio[10627]: info: go-librespot daemon successfully initialized Mar 25 08:44:00 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Mar 25 08:44:00 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 08:44:00 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 08:44:00 katarynka go-librespot[10933]: go-librespot daemon starting... Mar 25 08:44:00 katarynka go-librespot[10934]: time="2026-03-25T08:44:00+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 08:44:00 katarynka go-librespot[10934]: time="2026-03-25T08:44:00+01:00" level=debug msg="app state loaded" Mar 25 08:44:00 katarynka go-librespot[10934]: time="2026-03-25T08:44:00+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 08:44:00 katarynka mpd[10838]: 2026-03-25T08:44:00 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Mar 25 08:44:00 katarynka systemd[1]: Started mpd.service - Music Player Daemon. Mar 25 08:44:00 katarynka sudo[10794]: pam_unix(sudo:session): session closed for user root Mar 25 08:44:00 katarynka sudo[10804]: pam_unix(sudo:session): session closed for user root Mar 25 08:44:00 katarynka volumio[10627]: info: Completed starting Core Plugins Mar 25 08:44:00 katarynka volumio[10627]: info: ------------------------------------------- Mar 25 08:44:00 katarynka volumio[10627]: info: ----- MyVolumio plugins startup ---- Mar 25 08:44:00 katarynka volumio[10627]: info: ------------------------------------------- Mar 25 08:44:00 katarynka volumio[10627]: info: [MyVolumio PluginManager] Fetching plans data.... Mar 25 08:44:00 katarynka volumio[10627]: error: MPD error: The expression evaluated to a falsy value: Mar 25 08:44:00 katarynka volumio[10627]: assert.ok(self.idling) Mar 25 08:44:00 katarynka volumio[10627]: error: The expression evaluated to a falsy value: Mar 25 08:44:00 katarynka volumio[10627]: assert.ok(self.idling) Mar 25 08:44:00 katarynka go-librespot[10934]: time="2026-03-25T08:44:00+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Mar 25 08:44:00 katarynka go-librespot[10934]: time="2026-03-25T08:44:00+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Mar 25 08:44:00 katarynka go-librespot[10934]: time="2026-03-25T08:44:00+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Mar 25 08:44:00 katarynka volumio[10627]: info: MPD running with PID10838 Mar 25 08:44:00 katarynka volumio[10627]: ,establishing connection Mar 25 08:44:00 katarynka volumio[10627]: error: updateQueue error: null Mar 25 08:44:00 katarynka volumio[10627]: error: updateQueue error: null Mar 25 08:44:00 katarynka go-librespot[10934]: time="2026-03-25T08:44:00+01:00" level=info msg="zeroconf server listening on port 45149" Mar 25 08:44:00 katarynka go-librespot[10934]: time="2026-03-25T08:44:00+01:00" level=debug msg="obtained new client token: AAAFafKhU8dWE4VmyXGHkRf94QSjoteGE2+Ih7ws2IXcvPMDkZrqD4UL/aOlWRlH852pKyFYl6uktOn/oxPD3EVRJVAxnmE4NaMu6MG+NInafL1niNP491V9UopIbgb12ed7oB/HleDQ3jLUmzifohuRUrCohR0KsjFuTqz+fRyvfrvLtqbJNhjjSaXiUeqrvMcZisdZ0luhYr9ZfDX0eG2HBN8xTApD7BXLbzLhYVGYSELyPkOh9hYhxZM=" Mar 25 08:44:00 katarynka go-librespot[10934]: time="2026-03-25T08:44:00+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 08:44:01 katarynka go-librespot[10934]: time="2026-03-25T08:44:01+01:00" level=debug msg="completed keyexchange" Mar 25 08:44:01 katarynka go-librespot[10934]: time="2026-03-25T08:44:01+01:00" level=debug msg="completed challenge" Mar 25 08:44:01 katarynka go-librespot[10934]: time="2026-03-25T08:44:01+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 25 08:44:01 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 08:44:01 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 08:44:02 katarynka volumio[10627]: info: Initializing connection to go-librespot Websocket Mar 25 08:44:02 katarynka volumio[10627]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 25 08:44:03 katarynka sudo[10963]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Mar 25 08:44:03 katarynka sudo[10963]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 08:44:03 katarynka sudo[10966]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Mar 25 08:44:03 katarynka sudo[10966]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 08:44:03 katarynka systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Mar 25 08:44:03 katarynka systemd[1]: mpd_monitor.service: Deactivated successfully. Mar 25 08:44:03 katarynka systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Mar 25 08:44:03 katarynka systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Mar 25 08:44:03 katarynka mpd_monitor.sh[10968]: MPD Monitor Service: Starting MPD Monitor Service Mar 25 08:44:03 katarynka systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Mar 25 08:44:03 katarynka sudo[10963]: pam_unix(sudo:session): session closed for user root Mar 25 08:44:03 katarynka systemd[1]: mpd_monitor.service: Deactivated successfully. Mar 25 08:44:03 katarynka systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Mar 25 08:44:03 katarynka volumio[10627]: info: Successfully started MPD Monitor Mar 25 08:44:03 katarynka systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Mar 25 08:44:03 katarynka sudo[10966]: pam_unix(sudo:session): session closed for user root Mar 25 08:44:03 katarynka mpd_monitor.sh[10970]: MPD Monitor Service: Starting MPD Monitor Service Mar 25 08:44:03 katarynka volumio[10627]: info: Successfully started MPD Monitor Mar 25 08:44:04 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Mar 25 08:44:04 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 08:44:04 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 08:44:04 katarynka go-librespot[10974]: go-librespot daemon starting... Mar 25 08:44:04 katarynka go-librespot[10975]: time="2026-03-25T08:44:04+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 08:44:04 katarynka go-librespot[10975]: time="2026-03-25T08:44:04+01:00" level=debug msg="app state loaded" Mar 25 08:44:04 katarynka go-librespot[10975]: time="2026-03-25T08:44:04+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 08:44:04 katarynka go-librespot[10975]: time="2026-03-25T08:44:04+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 25 08:44:04 katarynka go-librespot[10975]: time="2026-03-25T08:44:04+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:44:04 katarynka go-librespot[10975]: time="2026-03-25T08:44:04+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:44:04 katarynka go-librespot[10975]: time="2026-03-25T08:44:04+01:00" level=info msg="zeroconf server listening on port 33327" Mar 25 08:44:04 katarynka go-librespot[10975]: time="2026-03-25T08:44:04+01:00" level=debug msg="obtained new client token: AAA00gHjQ784KCvbeYOZ/35mECTB98hSbFcuL90lM3Z1phCpb0DsG05K0Ty46IAKn6Dgm8siVGfGkBSd3tP52v3TBZs4/GRR8iS/YlwMG9sm5YYGKfecEeDE64Q1IY4gfKf/1xv9GC4YgLwAZMnDTzZcS6pQZv+ZB6Pnudv74OzROerUQkG682Aq7gmShUrcOTRwe5zWOmZ27/ArW7yA86XkwYAp3zAtU3UfgUb3Pne83n8+cbwnApkwl7c=" Mar 25 08:44:04 katarynka go-librespot[10975]: time="2026-03-25T08:44:04+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:44:04 katarynka go-librespot[10975]: time="2026-03-25T08:44:04+01:00" level=debug msg="connected to ap-gew4.spotify.com:443" Mar 25 08:44:05 katarynka go-librespot[10975]: time="2026-03-25T08:44:05+01:00" level=debug msg="completed keyexchange" Mar 25 08:44:05 katarynka go-librespot[10975]: time="2026-03-25T08:44:05+01:00" level=debug msg="completed challenge" Mar 25 08:44:05 katarynka go-librespot[10975]: time="2026-03-25T08:44:05+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 25 08:44:05 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 08:44:05 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 08:44:05 katarynka volumio[10627]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Mar 25 08:44:05 katarynka volumio[10627]: info: Initializing connection to go-librespot Websocket Mar 25 08:44:05 katarynka volumio[10627]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 25 08:44:08 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Mar 25 08:44:08 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 08:44:08 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 08:44:08 katarynka go-librespot[10982]: go-librespot daemon starting... Mar 25 08:44:08 katarynka go-librespot[10983]: time="2026-03-25T08:44:08+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 08:44:08 katarynka go-librespot[10983]: time="2026-03-25T08:44:08+01:00" level=debug msg="app state loaded" Mar 25 08:44:08 katarynka go-librespot[10983]: time="2026-03-25T08:44:08+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 08:44:08 katarynka go-librespot[10983]: time="2026-03-25T08:44:08+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 25 08:44:08 katarynka go-librespot[10983]: time="2026-03-25T08:44:08+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:44:08 katarynka go-librespot[10983]: time="2026-03-25T08:44:08+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:44:08 katarynka go-librespot[10983]: time="2026-03-25T08:44:08+01:00" level=info msg="zeroconf server listening on port 40825" Mar 25 08:44:08 katarynka go-librespot[10983]: time="2026-03-25T08:44:08+01:00" level=debug msg="obtained new client token: AAAvW5AK8vodLedlo4O7LEYNTtzOwDmrWzNQmaTDoVk2GnS6RNMsnJ7ww5qYRyk9qq5nURrAHYwF6qRYAXVxEnZdsMEh+6EpR1bn/TX0e4XHnTer1rBJQZ/YeQXITfG53Od0zKxaD1qMb5Hs4YOXlr8imcanijoswZu10Gv26KQis3yuoDSK3+2U+aqrQ5c+Awa93obSkZZSJXFKSBJE+6KABAJGrzsjZHvIjs+ro2UWMAwYx4bb6Jgqp6Q=" Mar 25 08:44:08 katarynka volumio[10627]: info: Initializing connection to go-librespot Websocket Mar 25 08:44:08 katarynka go-librespot[10983]: time="2026-03-25T08:44:08+01:00" level=debug msg="new websocket client" Mar 25 08:44:08 katarynka volumio[10627]: info: Connection to go-librespot Websocket established Mar 25 08:44:08 katarynka go-librespot[10983]: time="2026-03-25T08:44:08+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 08:44:08 katarynka volumio[10627]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Mar 25 08:44:08 katarynka volumio[10627]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Mar 25 08:44:08 katarynka volumio[10627]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Mar 25 08:44:08 katarynka volumio[10627]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Mar 25 08:44:08 katarynka volumio[10627]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Mar 25 08:44:08 katarynka volumio[10627]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Mar 25 08:44:08 katarynka volumio[10627]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Mar 25 08:44:08 katarynka volumio[10627]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Mar 25 08:44:08 katarynka volumio[10627]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Mar 25 08:44:08 katarynka volumio[10627]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Mar 25 08:44:08 katarynka volumio[10627]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Mar 25 08:44:08 katarynka volumio[10627]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Mar 25 08:44:08 katarynka volumio[10627]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Mar 25 08:44:08 katarynka volumio[10627]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Mar 25 08:44:08 katarynka volumio[10627]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Mar 25 08:44:08 katarynka volumio[10627]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Mar 25 08:44:08 katarynka volumio[10627]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Mar 25 08:44:08 katarynka volumio[10627]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Mar 25 08:44:08 katarynka volumio[10627]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Mar 25 08:44:08 katarynka go-librespot[10983]: time="2026-03-25T08:44:08+01:00" level=debug msg="completed keyexchange" Mar 25 08:44:08 katarynka volumio[10627]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Mar 25 08:44:08 katarynka volumio[10627]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Mar 25 08:44:08 katarynka volumio[10627]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Mar 25 08:44:08 katarynka go-librespot[10983]: time="2026-03-25T08:44:08+01:00" level=debug msg="completed challenge" Mar 25 08:44:08 katarynka volumio[10627]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Mar 25 08:44:08 katarynka volumio[10627]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Mar 25 08:44:08 katarynka volumio[10627]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Mar 25 08:44:08 katarynka volumio[10627]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Mar 25 08:44:08 katarynka volumio[10627]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Mar 25 08:44:08 katarynka volumio[10627]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Mar 25 08:44:08 katarynka volumio[10627]: info: Adding plugin bluetooth to MyMusic Plugins Mar 25 08:44:08 katarynka volumio[10627]: info: Adding plugin multiroom to MyMusic Plugins Mar 25 08:44:08 katarynka volumio[10627]: info: Adding plugin metavolumio to MyMusic Plugins Mar 25 08:44:08 katarynka volumio[10627]: info: Adding plugin cd_controller to MyMusic Plugins Mar 25 08:44:08 katarynka volumio[10627]: info: Adding plugin qobuzconnect to MyMusic Plugins Mar 25 08:44:08 katarynka volumio[10627]: info: Adding plugin smart_inputs to MyMusic Plugins Mar 25 08:44:08 katarynka volumio[10627]: info: Adding plugin tidalconnect to MyMusic Plugins Mar 25 08:44:08 katarynka volumio[10627]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Mar 25 08:44:08 katarynka go-librespot[10983]: time="2026-03-25T08:44:08+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 25 08:44:08 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 08:44:08 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 08:44:10 katarynka volumio[10627]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Mar 25 08:44:10 katarynka volumio[10627]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Mar 25 08:44:10 katarynka volumio[10627]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 08:44:10 katarynka volumio[10627]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 08:44:10 katarynka volumio[10627]: info: Starting MyVolumio Remote Streaming Endpoints Mar 25 08:44:11 katarynka volumio[10627]: info: MyVolumio login type: Token Mar 25 08:44:11 katarynka volumio[10627]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Mar 25 08:44:11 katarynka volumio[10627]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Mar 25 08:44:12 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Mar 25 08:44:12 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 08:44:12 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 08:44:12 katarynka go-librespot[10991]: go-librespot daemon starting... Mar 25 08:44:12 katarynka go-librespot[10992]: time="2026-03-25T08:44:12+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 08:44:12 katarynka go-librespot[10992]: time="2026-03-25T08:44:12+01:00" level=debug msg="app state loaded" Mar 25 08:44:12 katarynka go-librespot[10992]: time="2026-03-25T08:44:12+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 08:44:12 katarynka go-librespot[10992]: time="2026-03-25T08:44:12+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 25 08:44:12 katarynka go-librespot[10992]: time="2026-03-25T08:44:12+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 25 08:44:12 katarynka go-librespot[10992]: time="2026-03-25T08:44:12+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 25 08:44:12 katarynka go-librespot[10992]: time="2026-03-25T08:44:12+01:00" level=info msg="zeroconf server listening on port 36797" Mar 25 08:44:12 katarynka go-librespot[10992]: time="2026-03-25T08:44:12+01:00" level=debug msg="obtained new client token: AADBixlhU5VKZl/ot+JRcZfNj/AtjL6tFWLNC38qLqUOyaj4RkTu60CMr1FC18iriTyHZirMIcXx00Zvl9GCnh+L+SjP0hubkFdtKL9ydGHwBTpDLcp9q9w76t0Q//vZeJinfUT7J61XSsUaur/xI1Edy8DrpNcF3Vsf2iWzZh/qK6YcvfpaY53qFM3RwRTGSauRLrDL4nYV2RonfWUDe5e8/O90gEm7IOVICaIDEm1YdPaXNFCApyViz4A=" Mar 25 08:44:12 katarynka go-librespot[10992]: time="2026-03-25T08:44:12+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:44:12 katarynka volumio[10627]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Mar 25 08:44:12 katarynka volumio[10627]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Mar 25 08:44:12 katarynka volumio[10627]: info: Streaming services startup Mar 25 08:44:12 katarynka volumio[10627]: info: Starting Streaming Daemon Mar 25 08:44:13 katarynka go-librespot[10992]: time="2026-03-25T08:44:13+01:00" level=debug msg="connected to ap-gew4.spotify.com:443" Mar 25 08:44:13 katarynka sudo[11000]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Mar 25 08:44:13 katarynka volumio[10627]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Mar 25 08:44:13 katarynka sudo[11000]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 08:44:13 katarynka go-librespot[10992]: time="2026-03-25T08:44:13+01:00" level=debug msg="completed keyexchange" Mar 25 08:44:13 katarynka go-librespot[10992]: time="2026-03-25T08:44:13+01:00" level=debug msg="completed challenge" Mar 25 08:44:13 katarynka sudo[11000]: pam_unix(sudo:session): session closed for user root Mar 25 08:44:13 katarynka go-librespot[10992]: time="2026-03-25T08:44:13+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:44:13 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 08:44:13 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 08:44:13 katarynka volumio[10627]: info: Getting Spotify volume Mar 25 08:44:13 katarynka volumio[10627]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 25 08:44:13 katarynka volumio[10627]: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 25 08:44:13 katarynka volumio[10627]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Mar 25 08:44:13 katarynka volumio[10627]: errno: -111, Mar 25 08:44:13 katarynka volumio[10627]: code: 'ECONNREFUSED', Mar 25 08:44:13 katarynka volumio[10627]: syscall: 'connect', Mar 25 08:44:13 katarynka volumio[10627]: address: '127.0.0.1', Mar 25 08:44:13 katarynka volumio[10627]: port: 9879, Mar 25 08:44:13 katarynka volumio[10627]: response: undefined Mar 25 08:44:13 katarynka volumio[10627]: } Mar 25 08:44:13 katarynka volumio[10627]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 25 08:44:14 katarynka sudo[11034]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-03-25 08:43' Mar 25 08:44:14 katarynka sudo[11034]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 08:44:15 katarynka sudo[11034]: pam_unix(sudo:session): session closed for user root Mar 25 08:44:15 katarynka volumio-remote-updater[622]: [2026-03-25 08:44:15] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Mar 25 08:44:15 katarynka volumio-remote-updater[622]: [2026-03-25 08:44:15] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Mar 25 08:44:15 katarynka systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Mar 25 08:44:15 katarynka systemd[1]: volumio.service: Failed with result 'exit-code'. Mar 25 08:44:15 katarynka systemd[1]: volumio.service: Consumed 49.199s CPU time. Mar 25 08:44:15 katarynka systemd[1]: Started dynamicswap.service - dynamicswap service. Mar 25 08:44:15 katarynka systemd[1]: dynamicswap.service: Deactivated successfully. Mar 25 08:44:15 katarynka systemd[1]: volumio.service: Scheduled restart job, restart counter is at 26171. Mar 25 08:44:15 katarynka systemd[1]: Started dynamicswap.service - dynamicswap service. Mar 25 08:44:15 katarynka systemd[1]: Stopped volumio.service - Volumio Backend Module. Mar 25 08:44:15 katarynka systemd[1]: volumio.service: Consumed 49.199s CPU time. Mar 25 08:44:15 katarynka systemd[1]: Started volumio.service - Volumio Backend Module. Mar 25 08:44:15 katarynka systemd[1]: dynamicswap.service: Deactivated successfully. Mar 25 08:44:16 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Mar 25 08:44:16 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 08:44:16 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 08:44:16 katarynka go-librespot[11070]: go-librespot daemon starting... Mar 25 08:44:16 katarynka go-librespot[11071]: time="2026-03-25T08:44:16+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 08:44:16 katarynka go-librespot[11071]: time="2026-03-25T08:44:16+01:00" level=debug msg="app state loaded" Mar 25 08:44:16 katarynka go-librespot[11071]: time="2026-03-25T08:44:16+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 08:44:17 katarynka go-librespot[11071]: time="2026-03-25T08:44:16+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Mar 25 08:44:17 katarynka go-librespot[11071]: time="2026-03-25T08:44:16+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Mar 25 08:44:17 katarynka go-librespot[11071]: time="2026-03-25T08:44:16+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Mar 25 08:44:17 katarynka go-librespot[11071]: time="2026-03-25T08:44:17+01:00" level=info msg="zeroconf server listening on port 36041" Mar 25 08:44:17 katarynka go-librespot[11071]: time="2026-03-25T08:44:17+01:00" level=debug msg="obtained new client token: AABj5i5pn7QAy0xU8HXeRY2thRZC/mgCWG1IN+R/o0AWy0POeVoP1tciHS3RbAYmyv9liXzd5lZLmD3ojfZbolf3nbIJxN2MJKGNdMaMaaWLum9G5x0cuGBsicOgHK7hp96lQil3K/Ci5yzaX1hUjMO83s7IJJ6XkUAvhwkZSZPk0rc2KmUlI69idN/vnXbZZwgtoTMuhs8zEggk/F4lie016s5mJqXACsPZzQ3SDVo+00X2S3z7CaRw" Mar 25 08:44:17 katarynka go-librespot[11071]: time="2026-03-25T08:44:17+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 08:44:17 katarynka go-librespot[11071]: time="2026-03-25T08:44:17+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:44:17 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 08:44:17 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 08:44:19 katarynka volumio[11055]: info: ------------------------------------------- Mar 25 08:44:19 katarynka volumio[11055]: info: ----- Volumio3 ---- Mar 25 08:44:19 katarynka volumio[11055]: info: ------------------------------------------- Mar 25 08:44:19 katarynka volumio[11055]: info: ----- System startup ---- Mar 25 08:44:19 katarynka volumio[11055]: info: ------------------------------------------- Mar 25 08:44:20 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Mar 25 08:44:20 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 08:44:20 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 08:44:20 katarynka go-librespot[11084]: go-librespot daemon starting... Mar 25 08:44:20 katarynka volumio-remote-updater[622]: [2026-03-25 08:44:20] [connect] Successful connection Mar 25 08:44:20 katarynka go-librespot[11085]: time="2026-03-25T08:44:20+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 08:44:20 katarynka go-librespot[11085]: time="2026-03-25T08:44:20+01:00" level=debug msg="app state loaded" Mar 25 08:44:20 katarynka go-librespot[11085]: time="2026-03-25T08:44:20+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 08:44:21 katarynka go-librespot[11085]: time="2026-03-25T08:44:21+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 25 08:44:21 katarynka go-librespot[11085]: time="2026-03-25T08:44:21+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:44:21 katarynka go-librespot[11085]: time="2026-03-25T08:44:21+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:44:21 katarynka go-librespot[11085]: time="2026-03-25T08:44:21+01:00" level=info msg="zeroconf server listening on port 33195" Mar 25 08:44:21 katarynka volumio[11055]: info: MYVOLUMIO Environment detected Mar 25 08:44:21 katarynka go-librespot[11085]: time="2026-03-25T08:44:21+01:00" level=debug msg="obtained new client token: AACgQgBsB2jbFXCZVgwu95KmNxiukaCAeoAwkVqWp+g9/MvgYGbC5bW5sHnC0ahBVuoreK4RcBTe2omNPG960YzByMDXBGWFFxSo6uQQrupwUBfnIXFel0absLUIUajV+zO4rTp36zNCs3S5oaSAGi9cBW7lKuxyLjKzWqq0d7+NDK9C74kTgjTNqqm+PlBaoE+sbjv8hLKRoEvF176QfVUMrzwfl+MCiQvp2CoBEqjKmIr+F9Pt1NPv" Mar 25 08:44:21 katarynka volumio[11055]: info: Plugin folders cleanup Mar 25 08:44:21 katarynka volumio[11055]: info: Scanning into folder /volumio/app/plugins/ Mar 25 08:44:21 katarynka volumio[11055]: info: Scanning category audio_interface Mar 25 08:44:21 katarynka volumio[11055]: info: Scanning category miscellanea Mar 25 08:44:21 katarynka volumio[11055]: info: Scanning category music_service Mar 25 08:44:21 katarynka volumio[11055]: info: Scanning category plugins.json Mar 25 08:44:21 katarynka volumio[11055]: info: Scanning category system_controller Mar 25 08:44:21 katarynka volumio[11055]: info: Scanning category user_interface Mar 25 08:44:21 katarynka volumio[11055]: info: Scanning into folder /data/plugins/ Mar 25 08:44:21 katarynka volumio[11055]: info: Scanning category music_service Mar 25 08:44:21 katarynka volumio[11055]: info: Plugin folders cleanup completed Mar 25 08:44:21 katarynka volumio[11055]: info: ------------------------------------------- Mar 25 08:44:21 katarynka volumio[11055]: info: ----- Core plugins startup ---- Mar 25 08:44:21 katarynka volumio[11055]: info: ------------------------------------------- Mar 25 08:44:21 katarynka volumio[11055]: info: Loading plugins from folder /volumio/app/plugins/ Mar 25 08:44:21 katarynka volumio[11055]: info: Adding plugin upnp to MyMusic Plugins Mar 25 08:44:21 katarynka go-librespot[11085]: time="2026-03-25T08:44:21+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 08:44:21 katarynka volumio[11055]: info: Adding plugin airplay_emulation to MyMusic Plugins Mar 25 08:44:21 katarynka volumio[11055]: info: Adding plugin upnp_browser to MyMusic Plugins Mar 25 08:44:21 katarynka volumio[11055]: info: Loading plugins from folder /data/plugins/ Mar 25 08:44:21 katarynka volumio[11055]: info: Loading plugin "system"... Mar 25 08:44:21 katarynka go-librespot[11085]: time="2026-03-25T08:44:21+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:44:21 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 08:44:21 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 08:44:21 katarynka volumio[11055]: info: Loading plugin "appearance"... Mar 25 08:44:23 katarynka volumio[11055]: info: Loading plugin "network"... Mar 25 08:44:23 katarynka volumio[11055]: info: Refreshing Cached IP Addresses Mar 25 08:44:23 katarynka sudo[11100]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 25 08:44:23 katarynka sudo[11100]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 08:44:23 katarynka sudo[11100]: pam_unix(sudo:session): session closed for user root Mar 25 08:44:23 katarynka sudo[11102]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 25 08:44:23 katarynka sudo[11102]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 08:44:23 katarynka volumio[11055]: info: Loading plugin "services"... Mar 25 08:44:23 katarynka sudo[11102]: pam_unix(sudo:session): session closed for user root Mar 25 08:44:23 katarynka volumio[11055]: info: Loading plugin "alsa_controller"... Mar 25 08:44:23 katarynka sudo[11110]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Mar 25 08:44:23 katarynka sudo[11110]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 08:44:23 katarynka volumio[11055]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 25 08:44:23 katarynka volumio[11055]: info: Loading plugin "wizard"... Mar 25 08:44:23 katarynka volumio[11055]: info: Loading plugin "networkfs"... Mar 25 08:44:23 katarynka volumio[11055]: info: Starting Udev Watcher for removable devices Mar 25 08:44:23 katarynka volumio[11055]: info: Ignoring mount for partition: boot Mar 25 08:44:23 katarynka volumio[11055]: info: Ignoring mount for partition: volumio Mar 25 08:44:23 katarynka volumio[11055]: info: Ignoring mount for partition: volumio_data Mar 25 08:44:23 katarynka volumio[11055]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 25 08:44:23 katarynka volumio[11055]: info: Loading plugin "volumio_command_line_client"... Mar 25 08:44:23 katarynka volumio[11055]: info: Loading plugin "upnp"... Mar 25 08:44:23 katarynka volumio[11055]: info: [1774424663765] Starting Upmpd Daemon Mar 25 08:44:23 katarynka volumio[11055]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 25 08:44:23 katarynka volumio[11055]: info: Loading plugin "my_music"... Mar 25 08:44:23 katarynka volumio[11055]: info: Loading plugin "mpd"... Mar 25 08:44:24 katarynka sudo[11110]: pam_unix(sudo:session): session closed for user root Mar 25 08:44:24 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Mar 25 08:44:24 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 08:44:24 katarynka volumio[11055]: info: Loading plugin "upnp_browser"... Mar 25 08:44:24 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 08:44:24 katarynka go-librespot[11136]: go-librespot daemon starting... Mar 25 08:44:24 katarynka go-librespot[11137]: time="2026-03-25T08:44:24+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 08:44:24 katarynka go-librespot[11137]: time="2026-03-25T08:44:24+01:00" level=debug msg="app state loaded" Mar 25 08:44:24 katarynka go-librespot[11137]: time="2026-03-25T08:44:24+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 08:44:24 katarynka go-librespot[11137]: time="2026-03-25T08:44:24+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Mar 25 08:44:24 katarynka go-librespot[11137]: time="2026-03-25T08:44:24+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:44:24 katarynka go-librespot[11137]: time="2026-03-25T08:44:24+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:44:25 katarynka go-librespot[11137]: time="2026-03-25T08:44:25+01:00" level=info msg="zeroconf server listening on port 34849" Mar 25 08:44:25 katarynka go-librespot[11137]: time="2026-03-25T08:44:25+01:00" level=debug msg="obtained new client token: AABhNnTk6uDnO2pMmRsY5RQdc+10zLlg0Zs4i6O+EK9kXNLIWhPI4+S93PIed7ICpMk0Dc0Nltzo5xg4bms+9MzOHlnPA1B7GoY33KTLrE/nAtqUQw8L+3kqJvoE+9jqdP3sSJacCfgF5xQh5kanJznLiGUEoD8GL6GBVIeTNc+zjZmBenA4LFo5I95w2Qqd1+TKyAgJcTrmQslhxZ9ES6X2bjad4T++TGVjJADdXpYIpk8GlhVhnb+h" Mar 25 08:44:25 katarynka go-librespot[11137]: time="2026-03-25T08:44:25+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 08:44:25 katarynka go-librespot[11137]: time="2026-03-25T08:44:25+01:00" level=debug msg="completed keyexchange" Mar 25 08:44:25 katarynka go-librespot[11137]: time="2026-03-25T08:44:25+01:00" level=debug msg="completed challenge" Mar 25 08:44:25 katarynka go-librespot[11137]: time="2026-03-25T08:44:25+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 25 08:44:25 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 08:44:25 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 08:44:27 katarynka volumio[11055]: info: Starting UPNP Browser Mar 25 08:44:27 katarynka volumio[11055]: info: Loading plugin "alarm-clock"... Mar 25 08:44:27 katarynka volumio[11055]: info: Loading plugin "airplay_emulation"... Mar 25 08:44:27 katarynka volumio[11055]: info: Starting Shairport Sync Mar 25 08:44:27 katarynka volumio[11055]: info: Loading plugin "last_100"... Mar 25 08:44:27 katarynka volumio[11055]: info: Loading plugin "webradio"... Mar 25 08:44:28 katarynka volumio[11055]: info: Loading plugin "i2s_dacs"... Mar 25 08:44:28 katarynka volumio[11055]: info: Loading plugin "volumiodiscovery"... Mar 25 08:44:28 katarynka volumio[11055]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Mar 25 08:44:28 katarynka volumio[11055]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 25 08:44:28 katarynka volumio[11055]: *** WARNING *** For more information see Mar 25 08:44:28 katarynka volumio[11055]: *** 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:44:28 katarynka volumio[11055]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 25 08:44:28 katarynka node[11055]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Mar 25 08:44:28 katarynka volumio[11055]: *** WARNING *** For more information see Mar 25 08:44:28 katarynka node[11055]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 25 08:44:28 katarynka node[11055]: *** WARNING *** For more information see Mar 25 08:44:28 katarynka node[11055]: *** 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:44:28 katarynka node[11055]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 25 08:44:28 katarynka node[11055]: *** WARNING *** For more information see Mar 25 08:44:28 katarynka volumio[11055]: info: Applying required configuration parameters for plugin volumiodiscovery Mar 25 08:44:28 katarynka volumio[11055]: info: Discovery: Started advertising with name: katarynka Mar 25 08:44:28 katarynka volumio[11055]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 25 08:44:28 katarynka volumio[11055]: info: Loading plugin "spop"... Mar 25 08:44:28 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Mar 25 08:44:28 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 08:44:28 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 08:44:28 katarynka go-librespot[11146]: go-librespot daemon starting... Mar 25 08:44:28 katarynka go-librespot[11147]: time="2026-03-25T08:44:28+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 08:44:28 katarynka go-librespot[11147]: time="2026-03-25T08:44:28+01:00" level=debug msg="app state loaded" Mar 25 08:44:28 katarynka go-librespot[11147]: time="2026-03-25T08:44:28+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 08:44:28 katarynka go-librespot[11147]: time="2026-03-25T08:44:28+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 25 08:44:28 katarynka go-librespot[11147]: time="2026-03-25T08:44:28+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:44:28 katarynka go-librespot[11147]: time="2026-03-25T08:44:28+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:44:29 katarynka go-librespot[11147]: time="2026-03-25T08:44:29+01:00" level=info msg="zeroconf server listening on port 44819" Mar 25 08:44:29 katarynka go-librespot[11147]: time="2026-03-25T08:44:29+01:00" level=debug msg="obtained new client token: AAAz2kVqFF6A0TD1xnoT+XLmPXaPzNRsgnVZf0xi+C9YwGqsZjDkiBzb9+h+iR7kKv4oKlRKtGDZ10yD3jPgWsLqcB2mp1jo0yGiCz9Bx7c2C3oPkYLJ2tYz0CxzKdqUiVFzpPNiUYBjxvIMrSJ+6jLc4q/pEnsRCV15CBgr7zX+8VaoucxD+Rf5Kqm0dHvXgxtXQ9udTvAqVL8yqGZctof8KZd4AiOPb8I2D/S4RWxkbzb65Pse3j/l" Mar 25 08:44:29 katarynka go-librespot[11147]: time="2026-03-25T08:44:29+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 08:44:29 katarynka go-librespot[11147]: time="2026-03-25T08:44:29+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:44:29 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 08:44:29 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 08:44:30 katarynka volumio[11055]: info: Loading plugin "outputs"... Mar 25 08:44:30 katarynka volumio[11055]: info: Loading plugin "albumart"... Mar 25 08:44:30 katarynka volumio[11055]: info: Plugin example_plugin is not enabled Mar 25 08:44:30 katarynka volumio[11055]: info: Loading plugin "inputs"... Mar 25 08:44:30 katarynka volumio[11055]: info: Loading plugin "updater_comm"... Mar 25 08:44:30 katarynka volumio[11055]: info: Plugin mpdemulation is not enabled Mar 25 08:44:30 katarynka volumio[11055]: info: Loading plugin "rest_api"... Mar 25 08:44:30 katarynka volumio[11055]: info: Loading plugin "websocket"... Mar 25 08:44:30 katarynka volumio[11055]: info: Starting Socket.io Server version 1.7.4 Mar 25 08:44:30 katarynka volumio[11055]: info: Loading i18n strings for locale pl Mar 25 08:44:30 katarynka volumio[11055]: Updating browse sources language Mar 25 08:44:30 katarynka volumio[11055]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 25 08:44:31 katarynka volumio[11055]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 25 08:44:31 katarynka volumio[11055]: info: CoreCommandRouter::initPlayerControls Mar 25 08:44:31 katarynka volumio[11055]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 08:44:31 katarynka volumio[11055]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 08:44:31 katarynka volumio[11055]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 08:44:31 katarynka volumio[11055]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 08:44:31 katarynka volumio[11055]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 08:44:31 katarynka volumio[11055]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 08:44:31 katarynka volumio[11055]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 08:44:31 katarynka volumio[11055]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 08:44:31 katarynka volumio[11055]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 25 08:44:31 katarynka volumio[11055]: Express server listening on port 3000 Mar 25 08:44:31 katarynka volumio[11055]: [Metrics] WebUI: 12s 510.08ms Mar 25 08:44:31 katarynka volumio[11055]: info: CoreStateMachine::resetVolumioState Mar 25 08:44:31 katarynka volumio[11055]: info: CoreStateMachine::getcurrentVolume Mar 25 08:44:31 katarynka volumio[11055]: info: CoreCommandRouter::volumioRetrievevolume Mar 25 08:44:31 katarynka volumio[11055]: info: Cannot read play queue from file Mar 25 08:44:31 katarynka volumio[11055]: info: Volumio Network Manager: Network status updated: 2 Mar 25 08:44:31 katarynka volumio[11055]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 08:44:31 katarynka volumio[11055]: info: CoreStateMachine::setRepeat null single undefined Mar 25 08:44:31 katarynka volumio[11055]: info: CoreStateMachine::pushState Mar 25 08:44:31 katarynka volumio[11155]: Forking 3 albumart workers Mar 25 08:44:31 katarynka volumio[11055]: info: CorePlayQueue::getTrack 0 Mar 25 08:44:31 katarynka volumio[11055]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 25 08:44:31 katarynka volumio[11055]: info: CoreCommandRouter::volumioPushState Mar 25 08:44:31 katarynka volumio[11055]: info: CoreStateMachine::setRandom null Mar 25 08:44:31 katarynka volumio[11055]: info: CoreStateMachine::pushState Mar 25 08:44:31 katarynka volumio[11055]: info: CorePlayQueue::getTrack 0 Mar 25 08:44:31 katarynka volumio[11055]: info: CoreCommandRouter::volumioPushState Mar 25 08:44:31 katarynka volumio[11055]: info: Setting Device type: Raspberry PI Mar 25 08:44:31 katarynka volumio[11055]: info: Completed loading Core Plugins Mar 25 08:44:31 katarynka volumio[11055]: info: Preparing to generate the ALSA configuration file Mar 25 08:44:31 katarynka volumio[11055]: info: VolumeController:: Volume=96 Mute =false Mar 25 08:44:31 katarynka volumio[11055]: info: CoreStateMachine::pushState Mar 25 08:44:31 katarynka volumio[11055]: info: CorePlayQueue::getTrack 0 Mar 25 08:44:31 katarynka volumio[11055]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 25 08:44:31 katarynka volumio[11055]: info: CoreCommandRouter::volumioPushState Mar 25 08:44:31 katarynka volumio[11055]: info: CoreStateMachine::updateTrackBlock Mar 25 08:44:31 katarynka volumio[11055]: info: CorePlayQueue::getTrackBlock Mar 25 08:44:31 katarynka volumio[11055]: info: CoreCommandRouter::volumioRetrievevolume Mar 25 08:44:31 katarynka volumio[11055]: info: Asound.conf file unchanged, so no further update is needed Mar 25 08:44:31 katarynka volumio[11055]: info: Output device has changed, restarting MPD Mar 25 08:44:31 katarynka volumio[11055]: info: Output device has changed, restarting Shairport Sync Mar 25 08:44:31 katarynka volumio[11055]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 08:44:31 katarynka volumio[11055]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 08:44:31 katarynka sudo[11208]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 25 08:44:31 katarynka volumio[11055]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 25 08:44:31 katarynka sudo[11208]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 08:44:31 katarynka volumio[11055]: info: ___________ START PLUGINS ___________ Mar 25 08:44:31 katarynka sudo[11210]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 25 08:44:31 katarynka sudo[11208]: pam_unix(sudo:session): session closed for user root Mar 25 08:44:31 katarynka volumio[11055]: info: ControllerMpd::onStart: Initializing MPD Mar 25 08:44:31 katarynka volumio[11055]: info: Creating MPD Configuration file Mar 25 08:44:31 katarynka sudo[11210]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 08:44:32 katarynka volumio[11055]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 25 08:44:32 katarynka volumio[11055]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 25 08:44:32 katarynka volumio[11055]: info: [1774424672026] CoreMusicLibrary::Adding element Serwery Mediów Mar 25 08:44:32 katarynka volumio[11055]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 25 08:44:32 katarynka volumio[11055]: info: UPNP Browser: Client initialized successfully Mar 25 08:44:32 katarynka systemd[1]: Stopping mpd.service - Music Player Daemon... Mar 25 08:44:32 katarynka sudo[11219]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 25 08:44:32 katarynka sudo[11219]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 08:44:32 katarynka sudo[11221]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 25 08:44:32 katarynka sudo[11221]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 08:44:32 katarynka sudo[11219]: pam_unix(sudo:session): session closed for user root Mar 25 08:44:32 katarynka volumio[11055]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 08:44:32 katarynka volumio[11055]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 08:44:32 katarynka systemd[1]: mpd.service: Deactivated successfully. Mar 25 08:44:32 katarynka systemd[1]: Stopped mpd.service - Music Player Daemon. Mar 25 08:44:32 katarynka systemd[1]: mpd.service: Consumed 7.677s CPU time. Mar 25 08:44:32 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Mar 25 08:44:32 katarynka volumio[11055]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 25 08:44:32 katarynka volumio[11055]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 08:44:32 katarynka volumio[11055]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 08:44:32 katarynka systemd[1]: mpd.socket: Deactivated successfully. Mar 25 08:44:32 katarynka systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Mar 25 08:44:32 katarynka systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Mar 25 08:44:32 katarynka volumio[11055]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 25 08:44:32 katarynka volumio[11055]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 25 08:44:32 katarynka volumio[11055]: info: [1774424672385] CoreMusicLibrary::Adding element Last_100 Mar 25 08:44:32 katarynka volumio[11055]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 25 08:44:32 katarynka systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Mar 25 08:44:32 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 08:44:32 katarynka volumio[11055]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 25 08:44:32 katarynka volumio[11055]: info: [1774424672414] CoreMusicLibrary::Adding element Webradio Mar 25 08:44:32 katarynka volumio[11055]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 25 08:44:32 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 08:44:32 katarynka systemd[1]: Starting mpd.service - Music Player Daemon... Mar 25 08:44:32 katarynka go-librespot[11233]: go-librespot daemon starting... Mar 25 08:44:32 katarynka volumio[11055]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 25 08:44:32 katarynka volumio[11055]: info: Initializing BBC Radios Mar 25 08:44:32 katarynka systemd[1]: mpd.service: Deactivated successfully. Mar 25 08:44:32 katarynka systemd[1]: Stopped mpd.service - Music Player Daemon. Mar 25 08:44:32 katarynka systemd[1]: mpd.socket: Deactivated successfully. Mar 25 08:44:32 katarynka systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Mar 25 08:44:32 katarynka systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Mar 25 08:44:32 katarynka go-librespot[11235]: time="2026-03-25T08:44:32+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 08:44:32 katarynka go-librespot[11235]: time="2026-03-25T08:44:32+01:00" level=debug msg="app state loaded" Mar 25 08:44:32 katarynka go-librespot[11235]: time="2026-03-25T08:44:32+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 08:44:32 katarynka systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Mar 25 08:44:32 katarynka systemd[1]: Starting mpd.service - Music Player Daemon... Mar 25 08:44:32 katarynka volumio[11055]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 25 08:44:32 katarynka volumio[11055]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 08:44:32 katarynka volumio[11055]: info: Creating Spotify config file Mar 25 08:44:32 katarynka volumio[11055]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 08:44:33 katarynka volumio-remote-updater[622]: [2026-03-25 08:44:33] [connect] Successful connection Mar 25 08:44:33 katarynka go-librespot[11235]: time="2026-03-25T08:44: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 25 08:44:33 katarynka go-librespot[11235]: time="2026-03-25T08:44:33+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:44:33 katarynka go-librespot[11235]: time="2026-03-25T08:44:33+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:44:33 katarynka go-librespot[11235]: time="2026-03-25T08:44:33+01:00" level=info msg="zeroconf server listening on port 38081" Mar 25 08:44:33 katarynka sudo[11247]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Mar 25 08:44:33 katarynka sudo[11247]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Mar 25 08:44:33 katarynka sudo[11247]: pam_unix(sudo:session): session closed for user root Mar 25 08:44:33 katarynka go-librespot[11235]: time="2026-03-25T08:44:33+01:00" level=debug msg="obtained new client token: AABbRDr4xYUYhPo3gEvOfPmvIU0UVZSoBfyT/0tplql3vfvEdSe3ByIgyLlG/cxsCIaYQcKxFXTtXYY7Jey3dQ7Jy0WqTCfjUS0X/vjiWnNakQlO93EToN8jJW4VHGKjZK17vIctK5ter9YWa+MJgVJ3pVKNaR+yHNyqvIeKVZPsj2Dvakl0cLuJvNZqI3UiIdggcxCQwNL88rElMGgmZWnBUo/vgxX7nmjEAIKJadHSSwFO8sqPuhAgiM0=" Mar 25 08:44:33 katarynka go-librespot[11235]: time="2026-03-25T08:44:33+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 08:44:33 katarynka go-librespot[11235]: time="2026-03-25T08:44:33+01:00" level=debug msg="completed keyexchange" Mar 25 08:44:33 katarynka go-librespot[11235]: time="2026-03-25T08:44:33+01:00" level=debug msg="completed challenge" Mar 25 08:44:33 katarynka go-librespot[11235]: time="2026-03-25T08:44:33+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 25 08:44:33 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 08:44:33 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 08:44:34 katarynka volumio[11055]: info: Volumio Calling Home Mar 25 08:44:35 katarynka volumio[11174]: Starting albumart workers Mar 25 08:44:35 katarynka volumio[11055]: info: Discovery: adding 4d616d77-6a8c-4da2-85a4-840d70f98e51 Mar 25 08:44:35 katarynka sudo[11279]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 25 08:44:35 katarynka sudo[11279]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 08:44:35 katarynka volumio[11055]: info: Discovery: Found device katarynka Mar 25 08:44:35 katarynka volumio[11055]: info: CoreCommandRouter::volumioGetState Mar 25 08:44:35 katarynka volumio[11055]: info: CorePlayQueue::getTrack 0 Mar 25 08:44:35 katarynka sudo[11279]: pam_unix(sudo:session): session closed for user root Mar 25 08:44:35 katarynka volumio[11055]: info: Discovery: this is already registered, 4d616d77-6a8c-4da2-85a4-840d70f98e51 Mar 25 08:44:35 katarynka volumio[11055]: info: Discovery: Found device katarynka Mar 25 08:44:35 katarynka volumio[11055]: info: CoreCommandRouter::volumioGetState Mar 25 08:44:35 katarynka volumio[11055]: info: CorePlayQueue::getTrack 0 Mar 25 08:44:35 katarynka sudo[11281]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 25 08:44:35 katarynka sudo[11281]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 08:44:35 katarynka volumio[11055]: info: VolumeController:: Volume=96 Mute =false Mar 25 08:44:35 katarynka volumio[11055]: info: CoreStateMachine::pushState Mar 25 08:44:35 katarynka volumio[11055]: info: CorePlayQueue::getTrack 0 Mar 25 08:44:35 katarynka volumio[11055]: info: CoreCommandRouter::volumioPushState Mar 25 08:44:35 katarynka sudo[11281]: pam_unix(sudo:session): session closed for user root Mar 25 08:44:35 katarynka volumio[11055]: info: MPD Permissions set Mar 25 08:44:35 katarynka volumio[11055]: info: MPD Permissions set Mar 25 08:44:35 katarynka volumio-remote-updater[622]: [2026-03-25 08:44:35] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1774424673 101 Mar 25 08:44:35 katarynka volumio[11055]: 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:44:35 katarynka volumio[11177]: Starting albumart workers Mar 25 08:44:35 katarynka volumio[11055]: info: Volumio called home Mar 25 08:44:35 katarynka volumio[11055]: info: Spotify config file written Mar 25 08:44:35 katarynka volumio[11176]: Starting albumart workers Mar 25 08:44:35 katarynka sudo[11285]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Mar 25 08:44:36 katarynka sudo[11285]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 08:44:36 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 08:44:36 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 08:44:36 katarynka go-librespot[11287]: go-librespot daemon starting... Mar 25 08:44:36 katarynka sudo[11285]: pam_unix(sudo:session): session closed for user root Mar 25 08:44:36 katarynka go-librespot[11288]: time="2026-03-25T08:44:36+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 08:44:36 katarynka go-librespot[11288]: time="2026-03-25T08:44:36+01:00" level=debug msg="app state loaded" Mar 25 08:44:36 katarynka volumio[11055]: 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:44:36 katarynka go-librespot[11288]: time="2026-03-25T08:44:36+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 08:44:36 katarynka volumio[11055]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 08:44:36 katarynka volumio[11055]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 08:44:36 katarynka volumio[11055]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 08:44:36 katarynka volumio[11055]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 08:44:36 katarynka volumio[11055]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 08:44:36 katarynka volumio[11055]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 08:44:36 katarynka volumio[11055]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 08:44:36 katarynka volumio[11055]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 08:44:36 katarynka volumio[11055]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 08:44:36 katarynka volumio[11055]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 08:44:36 katarynka volumio[11055]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 08:44:36 katarynka volumio[11055]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 08:44:36 katarynka volumio[11055]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 08:44:36 katarynka volumio[11055]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 08:44:36 katarynka volumio[11055]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 08:44:36 katarynka volumio[11055]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 08:44:36 katarynka volumio[11055]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 08:44:36 katarynka volumio[11055]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 08:44:36 katarynka volumio[11055]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 08:44:36 katarynka volumio[11055]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 08:44:36 katarynka volumio[11055]: info: No need to fix Spotify hosts Mar 25 08:44:36 katarynka go-librespot[11288]: time="2026-03-25T08:44:36+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 25 08:44:36 katarynka go-librespot[11288]: time="2026-03-25T08:44:36+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:44:36 katarynka go-librespot[11288]: time="2026-03-25T08:44:36+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:44:36 katarynka go-librespot[11288]: time="2026-03-25T08:44:36+01:00" level=info msg="zeroconf server listening on port 35541" Mar 25 08:44:37 katarynka go-librespot[11288]: time="2026-03-25T08:44:37+01:00" level=debug msg="obtained new client token: AABWE0PL89IGtLSC1LkNCDJ0VAkTFcY1GRIhGeFEhQ9O4MNasdcPxyscjnglUKfLnWu+pl9zJaSBimAEPnYiV+DwLUotp72kY0wsWqWPU+aY71gJ2W7Wrr6++6O9esrRJYG06WXxfH2tGaGRR7o1LIN0uaqRyYzVYcT31IXVk9xLsbHsnekN2RcHjZjFPIj0ZdnOnhUPWTKacMc54MiNOlIHLuDtrvAZl0cqcsxcobXIptrQNBym53sz" Mar 25 08:44:37 katarynka go-librespot[11288]: time="2026-03-25T08:44:37+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 08:44:37 katarynka go-librespot[11288]: time="2026-03-25T08:44:37+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:44:37 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 08:44:37 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 08:44:37 katarynka volumio[11055]: info: Starting Shairport Sync Mar 25 08:44:37 katarynka volumio[11055]: info: Starting Shairport Sync Mar 25 08:44:37 katarynka volumio[11055]: info: Starting Shairport Sync Mar 25 08:44:37 katarynka sudo[11306]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 25 08:44:37 katarynka sudo[11306]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 08:44:37 katarynka systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Mar 25 08:44:37 katarynka systemd[1]: shairport-sync.service: Deactivated successfully. Mar 25 08:44:37 katarynka systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 25 08:44:37 katarynka sudo[11309]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 25 08:44:37 katarynka systemd[1]: shairport-sync.service: Consumed 2.309s CPU time. Mar 25 08:44:37 katarynka sudo[11309]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 08:44:37 katarynka sudo[11319]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Mar 25 08:44:37 katarynka sudo[11319]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 08:44:37 katarynka systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 25 08:44:37 katarynka sudo[11313]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 25 08:44:37 katarynka sudo[11306]: pam_unix(sudo:session): session closed for user root Mar 25 08:44:37 katarynka sudo[11313]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 08:44:37 katarynka sudo[11319]: pam_unix(sudo:session): session closed for user root Mar 25 08:44:38 katarynka systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Mar 25 08:44:38 katarynka systemd[1]: shairport-sync.service: Deactivated successfully. Mar 25 08:44:38 katarynka systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 25 08:44:38 katarynka systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 25 08:44:38 katarynka systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Mar 25 08:44:38 katarynka sudo[11313]: pam_unix(sudo:session): session closed for user root Mar 25 08:44:38 katarynka systemd[1]: shairport-sync.service: Deactivated successfully. Mar 25 08:44:38 katarynka systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 25 08:44:38 katarynka systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 25 08:44:38 katarynka sudo[11309]: pam_unix(sudo:session): session closed for user root Mar 25 08:44:38 katarynka volumio[11055]: info: Upmpdcli Daemon Started Mar 25 08:44:38 katarynka volumio[11055]: info: Shairport-Sync Started Mar 25 08:44:38 katarynka volumio[11055]: Error adding Membership: Error: addMembership EINVAL Mar 25 08:44:38 katarynka volumio[11055]: info: An error occurred while refreshing Spotify Token Error: Bad Request Mar 25 08:44:38 katarynka volumio[11055]: info: Shairport-Sync Started Mar 25 08:44:38 katarynka volumio[11055]: info: Shairport-Sync Started Mar 25 08:44:38 katarynka volumio[11055]: info: CoreCommandRouter::volumioGetState Mar 25 08:44:38 katarynka volumio[11055]: info: CorePlayQueue::getTrack 0 Mar 25 08:44:40 katarynka volumio[11055]: info: go-librespot daemon successfully initialized Mar 25 08:44:40 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Mar 25 08:44:40 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 08:44:40 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 08:44:40 katarynka go-librespot[11365]: go-librespot daemon starting... Mar 25 08:44:40 katarynka go-librespot[11366]: time="2026-03-25T08:44:40+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 08:44:40 katarynka go-librespot[11366]: time="2026-03-25T08:44:40+01:00" level=debug msg="app state loaded" Mar 25 08:44:40 katarynka go-librespot[11366]: time="2026-03-25T08:44:40+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 08:44:40 katarynka go-librespot[11366]: time="2026-03-25T08:44:40+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 25 08:44:40 katarynka go-librespot[11366]: time="2026-03-25T08:44:40+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 25 08:44:40 katarynka go-librespot[11366]: time="2026-03-25T08:44:40+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 25 08:44:40 katarynka go-librespot[11366]: time="2026-03-25T08:44:40+01:00" level=info msg="zeroconf server listening on port 41463" Mar 25 08:44:41 katarynka mpd[11259]: 2026-03-25T08:44:41 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Mar 25 08:44:41 katarynka go-librespot[11366]: time="2026-03-25T08:44:41+01:00" level=debug msg="obtained new client token: AADUWIzWbCfbJncPzY2+AbCODl4WgW/MG19CKA1ezkPLDDB1fXv9IiLkysYfzrDvfJO1Do2xqvuvOz+NtEnOdB9WmbvbwT7qlQlCN9eBhHqqHXCiUd4qJqmVHNalKQmsvHkx4Ei00EwdYQHrYm21VoDc+3/piRBdSYowcfm5kMSUfFjOMkyZVy+6LOH0+T+Sb2M1S8sidocCI0Osaf5Ukz+KR3NzXuFMD38m0ODiO1zacNmK9UN/O/Ma" Mar 25 08:44:41 katarynka systemd[1]: Started mpd.service - Music Player Daemon. Mar 25 08:44:41 katarynka sudo[11221]: pam_unix(sudo:session): session closed for user root Mar 25 08:44:41 katarynka sudo[11210]: pam_unix(sudo:session): session closed for user root Mar 25 08:44:41 katarynka volumio[11055]: info: Completed starting Core Plugins Mar 25 08:44:41 katarynka volumio[11055]: info: ------------------------------------------- Mar 25 08:44:41 katarynka volumio[11055]: info: ----- MyVolumio plugins startup ---- Mar 25 08:44:41 katarynka volumio[11055]: info: ------------------------------------------- Mar 25 08:44:41 katarynka volumio[11055]: info: [MyVolumio PluginManager] Fetching plans data.... Mar 25 08:44:41 katarynka volumio[11055]: error: MPD error: The expression evaluated to a falsy value: Mar 25 08:44:41 katarynka volumio[11055]: assert.ok(self.idling) Mar 25 08:44:41 katarynka volumio[11055]: error: The expression evaluated to a falsy value: Mar 25 08:44:41 katarynka volumio[11055]: assert.ok(self.idling) Mar 25 08:44:41 katarynka volumio[11055]: error: updateQueue error: null Mar 25 08:44:41 katarynka volumio[11055]: info: MPD running with PID11259 Mar 25 08:44:41 katarynka volumio[11055]: ,establishing connection Mar 25 08:44:41 katarynka volumio[11055]: error: updateQueue error: null Mar 25 08:44:41 katarynka go-librespot[11366]: time="2026-03-25T08:44:41+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 08:44:41 katarynka go-librespot[11366]: time="2026-03-25T08:44:41+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:44:41 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 08:44:41 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 08:44:43 katarynka volumio[11055]: info: Initializing connection to go-librespot Websocket Mar 25 08:44:43 katarynka volumio[11055]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 25 08:44:44 katarynka sudo[11395]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Mar 25 08:44:44 katarynka sudo[11395]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 08:44:44 katarynka sudo[11397]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Mar 25 08:44:44 katarynka sudo[11397]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 08:44:44 katarynka systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Mar 25 08:44:44 katarynka systemd[1]: mpd_monitor.service: Deactivated successfully. Mar 25 08:44:44 katarynka systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Mar 25 08:44:44 katarynka systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Mar 25 08:44:44 katarynka sudo[11395]: pam_unix(sudo:session): session closed for user root Mar 25 08:44:44 katarynka mpd_monitor.sh[11400]: MPD Monitor Service: Starting MPD Monitor Service Mar 25 08:44:44 katarynka volumio[11055]: info: Successfully started MPD Monitor Mar 25 08:44:44 katarynka sudo[11397]: pam_unix(sudo:session): session closed for user root Mar 25 08:44:44 katarynka volumio[11055]: info: Successfully started MPD Monitor Mar 25 08:44:44 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 11. Mar 25 08:44:44 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 08:44:44 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 08:44:44 katarynka go-librespot[11404]: go-librespot daemon starting... Mar 25 08:44:45 katarynka go-librespot[11405]: time="2026-03-25T08:44:45+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 08:44:45 katarynka go-librespot[11405]: time="2026-03-25T08:44:45+01:00" level=debug msg="app state loaded" Mar 25 08:44:45 katarynka go-librespot[11405]: time="2026-03-25T08:44:45+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 08:44:45 katarynka go-librespot[11405]: time="2026-03-25T08:44:45+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 25 08:44:45 katarynka go-librespot[11405]: time="2026-03-25T08:44:45+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:44:45 katarynka go-librespot[11405]: time="2026-03-25T08:44:45+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:44:45 katarynka go-librespot[11405]: time="2026-03-25T08:44:45+01:00" level=info msg="zeroconf server listening on port 46155" Mar 25 08:44:45 katarynka go-librespot[11405]: time="2026-03-25T08:44:45+01:00" level=debug msg="obtained new client token: AAA0zD7+vmq0yOQhYz8b+OVq0VS8ZkpSeS+aPEt7G+2kB1+6gTcS8aXblaVUs8vThQuIMLaosE9OBOvx11rFqtvMpzZ02ymRieLKKBq9xnuqqJsWv6jKNMs4PU9X0V+NWsapGz6MLefZDPw3u/noN3zsnKvEKIkEk/lCrT/+sOIHRoZDfi66m/XTZ1chYr8T5tR1AyAcXpHlUDlstat0/JVfa1VcFDjlOGMzahmsI7zM1jS/OJ0gtRPrtDQ=" Mar 25 08:44:45 katarynka go-librespot[11405]: time="2026-03-25T08:44:45+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 08:44:45 katarynka go-librespot[11405]: time="2026-03-25T08:44:45+01:00" level=debug msg="completed keyexchange" Mar 25 08:44:45 katarynka go-librespot[11405]: time="2026-03-25T08:44:45+01:00" level=debug msg="completed challenge" Mar 25 08:44:45 katarynka go-librespot[11405]: time="2026-03-25T08:44:45+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 25 08:44:45 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 08:44:45 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 08:44:46 katarynka volumio[11055]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Mar 25 08:44:46 katarynka volumio[11055]: info: Initializing connection to go-librespot Websocket Mar 25 08:44:46 katarynka volumio[11055]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 25 08:44:48 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 12. Mar 25 08:44:48 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 08:44:48 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 08:44:48 katarynka go-librespot[11412]: go-librespot daemon starting... Mar 25 08:44:49 katarynka go-librespot[11413]: time="2026-03-25T08:44:49+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 08:44:49 katarynka go-librespot[11413]: time="2026-03-25T08:44:49+01:00" level=debug msg="app state loaded" Mar 25 08:44:49 katarynka go-librespot[11413]: time="2026-03-25T08:44:49+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 08:44:49 katarynka volumio[11055]: info: Initializing connection to go-librespot Websocket Mar 25 08:44:49 katarynka go-librespot[11413]: time="2026-03-25T08:44:49+01:00" level=debug msg="new websocket client" Mar 25 08:44:49 katarynka volumio[11055]: info: Connection to go-librespot Websocket established Mar 25 08:44:49 katarynka go-librespot[11413]: time="2026-03-25T08:44:49+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 25 08:44:49 katarynka go-librespot[11413]: time="2026-03-25T08:44:49+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:44:49 katarynka go-librespot[11413]: time="2026-03-25T08:44:49+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:44:49 katarynka go-librespot[11413]: time="2026-03-25T08:44:49+01:00" level=info msg="zeroconf server listening on port 44155" Mar 25 08:44:49 katarynka volumio[11055]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Mar 25 08:44:49 katarynka volumio[11055]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Mar 25 08:44:49 katarynka volumio[11055]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Mar 25 08:44:49 katarynka volumio[11055]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Mar 25 08:44:49 katarynka volumio[11055]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Mar 25 08:44:49 katarynka volumio[11055]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Mar 25 08:44:49 katarynka volumio[11055]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Mar 25 08:44:49 katarynka volumio[11055]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Mar 25 08:44:49 katarynka volumio[11055]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Mar 25 08:44:49 katarynka volumio[11055]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Mar 25 08:44:49 katarynka volumio[11055]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Mar 25 08:44:49 katarynka volumio[11055]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Mar 25 08:44:49 katarynka volumio[11055]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Mar 25 08:44:49 katarynka volumio[11055]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Mar 25 08:44:49 katarynka volumio[11055]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Mar 25 08:44:49 katarynka volumio[11055]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Mar 25 08:44:49 katarynka volumio[11055]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Mar 25 08:44:49 katarynka volumio[11055]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Mar 25 08:44:49 katarynka volumio[11055]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Mar 25 08:44:49 katarynka volumio[11055]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Mar 25 08:44:49 katarynka volumio[11055]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Mar 25 08:44:49 katarynka volumio[11055]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Mar 25 08:44:49 katarynka volumio[11055]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Mar 25 08:44:49 katarynka volumio[11055]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Mar 25 08:44:49 katarynka volumio[11055]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Mar 25 08:44:49 katarynka volumio[11055]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Mar 25 08:44:49 katarynka volumio[11055]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Mar 25 08:44:49 katarynka volumio[11055]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Mar 25 08:44:49 katarynka volumio[11055]: info: Adding plugin bluetooth to MyMusic Plugins Mar 25 08:44:49 katarynka volumio[11055]: info: Adding plugin multiroom to MyMusic Plugins Mar 25 08:44:49 katarynka volumio[11055]: info: Adding plugin metavolumio to MyMusic Plugins Mar 25 08:44:49 katarynka volumio[11055]: info: Adding plugin cd_controller to MyMusic Plugins Mar 25 08:44:49 katarynka volumio[11055]: info: Adding plugin qobuzconnect to MyMusic Plugins Mar 25 08:44:49 katarynka volumio[11055]: info: Adding plugin smart_inputs to MyMusic Plugins Mar 25 08:44:49 katarynka volumio[11055]: info: Adding plugin tidalconnect to MyMusic Plugins Mar 25 08:44:49 katarynka volumio[11055]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Mar 25 08:44:49 katarynka go-librespot[11413]: time="2026-03-25T08:44:49+01:00" level=debug msg="obtained new client token: AADZhpoKr2JKtpKRPtxn4vW21K2YLqQxXXH5kuM3Ha1JWBnH24LWYvr2ReYhfadbUeBT+ciYzH0KxZcEQPVeoY61hHOdSnIAsTLABS/fV/UynUZYLsSyGGPAJ0ay3ttW/5u7aEzMa87YDtBeL0qB1g3DoSUSxhbA+JmTC6C8Qn72NpRcVuUCWC+ezuelG7f2BNKOMNTuBU0Hfmukxjcm6pjsuKTFNpyqAu8AdKVVO2P9pMUjvCkdhwc6WDA=" Mar 25 08:44:49 katarynka go-librespot[11413]: time="2026-03-25T08:44:49+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 08:44:49 katarynka go-librespot[11413]: time="2026-03-25T08:44:49+01:00" level=debug msg="completed keyexchange" Mar 25 08:44:49 katarynka go-librespot[11413]: time="2026-03-25T08:44:49+01:00" level=debug msg="completed challenge" Mar 25 08:44:49 katarynka go-librespot[11413]: time="2026-03-25T08:44:49+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 25 08:44:49 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 08:44:49 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 08:44:51 katarynka volumio[11055]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Mar 25 08:44:51 katarynka volumio[11055]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Mar 25 08:44:51 katarynka volumio[11055]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 08:44:51 katarynka volumio[11055]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 08:44:51 katarynka volumio[11055]: info: Starting MyVolumio Remote Streaming Endpoints Mar 25 08:44:51 katarynka volumio[11055]: info: MyVolumio login type: Token Mar 25 08:44:51 katarynka volumio[11055]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Mar 25 08:44:51 katarynka volumio[11055]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Mar 25 08:44:52 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 13. Mar 25 08:44:52 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 08:44:52 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 08:44:52 katarynka go-librespot[11422]: go-librespot daemon starting... Mar 25 08:44:53 katarynka go-librespot[11423]: time="2026-03-25T08:44:53+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 08:44:53 katarynka go-librespot[11423]: time="2026-03-25T08:44:53+01:00" level=debug msg="app state loaded" Mar 25 08:44:53 katarynka go-librespot[11423]: time="2026-03-25T08:44:53+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 08:44:53 katarynka volumio[11055]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Mar 25 08:44:53 katarynka volumio[11055]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Mar 25 08:44:53 katarynka volumio[11055]: info: Streaming services startup Mar 25 08:44:53 katarynka volumio[11055]: info: Starting Streaming Daemon Mar 25 08:44:53 katarynka sudo[11431]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Mar 25 08:44:53 katarynka sudo[11431]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 08:44:53 katarynka volumio[11055]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Mar 25 08:44:53 katarynka go-librespot[11423]: time="2026-03-25T08:44:53+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 25 08:44:53 katarynka go-librespot[11423]: time="2026-03-25T08:44:53+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:44:53 katarynka go-librespot[11423]: time="2026-03-25T08:44:53+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:44:53 katarynka go-librespot[11423]: time="2026-03-25T08:44:53+01:00" level=info msg="zeroconf server listening on port 37693" Mar 25 08:44:53 katarynka sudo[11431]: pam_unix(sudo:session): session closed for user root Mar 25 08:44:53 katarynka volumio[11055]: info: Getting Spotify volume Mar 25 08:44:53 katarynka go-librespot[11423]: time="2026-03-25T08:44:53+01:00" level=debug msg="obtained new client token: AABtnQIgbg40idh8qdYrkPg2FXG6g2nj3Q8XbX5xFnYV4c3mHdbSMPp6inYE4Fo1uXSFTMrbKIa3FJbiFh3qr1A7LYanryugM3sHgzPdNecK2N+qsaQRXJvrMN9oHGYT/4oSSs/XGbolCakG0aE306ogfOlmVNxqW8LnzdKj00On9kB1hfwz0fyQaPufdLu/twGXP0iqEtIrpvjV/2HqwctdAQmEUuc7y8Zc+7kppnUqyWyOuPPZQ19fk6I=" Mar 25 08:44:53 katarynka volumio[11055]: info: Connection to go-librespot Websocket closed Mar 25 08:44:53 katarynka volumio[11055]: error: Cannot start Volumio Streaming Daemon Mar 25 08:44:53 katarynka volumio[11055]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Mar 25 08:44:53 katarynka volumio[11055]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Mar 25 08:44:53 katarynka volumio[11055]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Mar 25 08:44:53 katarynka go-librespot[11423]: time="2026-03-25T08:44:53+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 08:44:54 katarynka volumio[11055]: info: CoreCommandRouter::volumioGetState Mar 25 08:44:54 katarynka volumio[11055]: info: CorePlayQueue::getTrack 0 Mar 25 08:44:54 katarynka volumio[11055]: SPOTIFY: RECEIVED VOLUMIO VOLUME 96 Mar 25 08:44:54 katarynka volumio[11055]: SPOTIFY: SPOTIFY VOLUME undefined Mar 25 08:44:54 katarynka volumio[11055]: SPOTIFY: VOLUMIO VOLUME 96 Mar 25 08:44:54 katarynka volumio[11055]: info: Aligning Spotify Volume to Volumio Volume Mar 25 08:44:54 katarynka volumio[11055]: info: CoreCommandRouter::volumioGetState Mar 25 08:44:54 katarynka volumio[11055]: info: CorePlayQueue::getTrack 0 Mar 25 08:44:54 katarynka volumio[11055]: info: Setting Spotify Volume from Volumio: 96 Mar 25 08:44:54 katarynka go-librespot[11423]: time="2026-03-25T08:44:54+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:44:54 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 08:44:54 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 08:44:54 katarynka volumio[11055]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 25 08:44:54 katarynka volumio[11055]: Error: socket hang up Mar 25 08:44:54 katarynka volumio[11055]: at connResetException (node:internal/errors:720:14) Mar 25 08:44:54 katarynka volumio[11055]: at Socket.socketOnEnd (node:_http_client:519:23) Mar 25 08:44:54 katarynka volumio[11055]: at Socket.emit (node:events:526:35) Mar 25 08:44:54 katarynka volumio[11055]: at endReadableNT (node:internal/streams/readable:1376:12) Mar 25 08:44:54 katarynka volumio[11055]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Mar 25 08:44:54 katarynka volumio[11055]: code: 'ECONNRESET', Mar 25 08:44:54 katarynka volumio[11055]: response: undefined Mar 25 08:44:54 katarynka volumio[11055]: } Mar 25 08:44:54 katarynka volumio[11055]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 25 08:44:55 katarynka sudo[11465]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-03-25 08:43' Mar 25 08:44:55 katarynka sudo[11465]: 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"