Mar 25 18:30:00 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Mar 25 18:30:00 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 18:30:00 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 18:30:00 katarynka go-librespot[23517]: go-librespot daemon starting... Mar 25 18:30:00 katarynka go-librespot[23518]: time="2026-03-25T18:30:00+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 18:30:00 katarynka go-librespot[23518]: time="2026-03-25T18:30:00+01:00" level=debug msg="app state loaded" Mar 25 18:30:00 katarynka go-librespot[23518]: time="2026-03-25T18:30:00+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 18:30:00 katarynka go-librespot[23518]: time="2026-03-25T18:30:00+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 25 18:30:00 katarynka go-librespot[23518]: time="2026-03-25T18:30:00+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 25 18:30:00 katarynka go-librespot[23518]: time="2026-03-25T18:30:00+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 25 18:30:00 katarynka go-librespot[23518]: time="2026-03-25T18:30:00+01:00" level=info msg="zeroconf server listening on port 42263" Mar 25 18:30:00 katarynka go-librespot[23518]: time="2026-03-25T18:30:00+01:00" level=debug msg="obtained new client token: AABXYJ8Aa6oLyJ08vPAZHnbFJUz9y/LALnxuWvQBN28wZODe2uMP0PPNnZhelNox6/3w3DOxCY90mkCQ/ltI26gdZmSm2j9mxeZCaoeqWrwYRJR9m1sNjGor7LE9dghcGx7yM6EvrEnvgdy5GrZ9kIIpL6lWCpWZdvYpcc6R67ryDxzQGkOiWhoB9nOSakcS3y+GuSKd3xSnroVBEsZ49hTe1wGK4TqeyjchJN5WpE2g4rlMvRFlT0rhBpI=" Mar 25 18:30:00 katarynka volumio[23483]: info: Loading plugin "network"... Mar 25 18:30:00 katarynka volumio[23483]: info: Refreshing Cached IP Addresses Mar 25 18:30:01 katarynka sudo[23526]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 25 18:30:01 katarynka sudo[23526]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 18:30:01 katarynka sudo[23528]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 25 18:30:01 katarynka sudo[23528]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 18:30:01 katarynka sudo[23526]: pam_unix(sudo:session): session closed for user root Mar 25 18:30:01 katarynka volumio[23483]: info: Loading plugin "services"... Mar 25 18:30:01 katarynka sudo[23528]: pam_unix(sudo:session): session closed for user root Mar 25 18:30:01 katarynka volumio[23483]: info: Loading plugin "alsa_controller"... Mar 25 18:30:01 katarynka sudo[23536]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Mar 25 18:30:01 katarynka sudo[23536]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 18:30:01 katarynka volumio[23483]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 25 18:30:01 katarynka volumio[23483]: info: Loading plugin "wizard"... Mar 25 18:30:01 katarynka volumio[23483]: info: Loading plugin "networkfs"... Mar 25 18:30:01 katarynka volumio[23483]: info: Starting Udev Watcher for removable devices Mar 25 18:30:01 katarynka go-librespot[23518]: time="2026-03-25T18:30:01+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 18:30:01 katarynka volumio[23483]: info: Ignoring mount for partition: boot Mar 25 18:30:01 katarynka volumio[23483]: info: Ignoring mount for partition: volumio Mar 25 18:30:01 katarynka volumio[23483]: info: Ignoring mount for partition: volumio_data Mar 25 18:30:01 katarynka volumio[23483]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 25 18:30:01 katarynka volumio[23483]: info: Loading plugin "volumio_command_line_client"... Mar 25 18:30:01 katarynka volumio[23483]: info: Loading plugin "upnp"... Mar 25 18:30:01 katarynka volumio[23483]: info: [1774459801412] Starting Upmpd Daemon Mar 25 18:30:01 katarynka volumio[23483]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 25 18:30:01 katarynka volumio[23483]: info: Loading plugin "my_music"... Mar 25 18:30:01 katarynka volumio[23483]: info: Loading plugin "mpd"... Mar 25 18:30:01 katarynka go-librespot[23518]: time="2026-03-25T18:30:01+01:00" level=debug msg="completed keyexchange" Mar 25 18:30:01 katarynka go-librespot[23518]: time="2026-03-25T18:30:01+01:00" level=debug msg="completed challenge" Mar 25 18:30:01 katarynka sudo[23536]: pam_unix(sudo:session): session closed for user root Mar 25 18:30:02 katarynka volumio[23483]: info: Loading plugin "upnp_browser"... Mar 25 18:30:02 katarynka go-librespot[23518]: time="2026-03-25T18:30:02+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 18:30:02 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 18:30:02 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 18:30:05 katarynka volumio[23483]: info: Starting UPNP Browser Mar 25 18:30:05 katarynka volumio[23483]: info: Loading plugin "alarm-clock"... Mar 25 18:30:05 katarynka volumio[23483]: info: Loading plugin "airplay_emulation"... Mar 25 18:30:05 katarynka volumio[23483]: info: Starting Shairport Sync Mar 25 18:30:05 katarynka volumio[23483]: info: Loading plugin "last_100"... Mar 25 18:30:05 katarynka volumio[23483]: info: Loading plugin "webradio"... Mar 25 18:30:05 katarynka volumio[23483]: info: Loading plugin "i2s_dacs"... Mar 25 18:30:05 katarynka volumio[23483]: info: Loading plugin "volumiodiscovery"... Mar 25 18:30:05 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Mar 25 18:30:05 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 18:30:05 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 18:30:05 katarynka volumio[23483]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Mar 25 18:30:05 katarynka volumio[23483]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 25 18:30:05 katarynka volumio[23483]: *** WARNING *** For more information see Mar 25 18:30:05 katarynka volumio[23483]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Mar 25 18:30:05 katarynka node[23483]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Mar 25 18:30:05 katarynka volumio[23483]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 25 18:30:05 katarynka volumio[23483]: *** WARNING *** For more information see Mar 25 18:30:05 katarynka node[23483]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 25 18:30:05 katarynka node[23483]: *** WARNING *** For more information see Mar 25 18:30:05 katarynka node[23483]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Mar 25 18:30:05 katarynka node[23483]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 25 18:30:05 katarynka go-librespot[23561]: go-librespot daemon starting... Mar 25 18:30:05 katarynka volumio[23483]: info: Applying required configuration parameters for plugin volumiodiscovery Mar 25 18:30:05 katarynka node[23483]: *** WARNING *** For more information see Mar 25 18:30:05 katarynka volumio[23483]: info: Discovery: Started advertising with name: katarynka Mar 25 18:30:05 katarynka go-librespot[23562]: time="2026-03-25T18:30:05+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 18:30:05 katarynka go-librespot[23562]: time="2026-03-25T18:30:05+01:00" level=debug msg="app state loaded" Mar 25 18:30:05 katarynka go-librespot[23562]: time="2026-03-25T18:30:05+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 18:30:05 katarynka volumio[23483]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 25 18:30:05 katarynka volumio[23483]: info: Loading plugin "spop"... Mar 25 18:30:06 katarynka go-librespot[23562]: time="2026-03-25T18:30:06+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Mar 25 18:30:06 katarynka go-librespot[23562]: time="2026-03-25T18:30:06+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 18:30:06 katarynka go-librespot[23562]: time="2026-03-25T18:30:06+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 18:30:06 katarynka go-librespot[23562]: time="2026-03-25T18:30:06+01:00" level=info msg="zeroconf server listening on port 40951" Mar 25 18:30:06 katarynka go-librespot[23562]: time="2026-03-25T18:30:06+01:00" level=debug msg="obtained new client token: AAAyLQNM+8HFOTrZBv9REV5Bo+aLGC6hqKw2/aj1tbvBdjbcJXdXdVclrSAYtq/uahxU6xwaq9nLpYOp6NpGrhVYzEfGIKbO3Rw4i5MTO/84JzoHv4gICwuWFermXoU49QgH/g1aVvLlqCsPtcl92GK/MMkxtxEADoxUxp9XKTzqJ/lw9o0gB1+o9/olwA2kVraMpmyYYycyew3hbd2058xosIdZSvdqU4werIsv7KKISiN9062A+SU6wo8=" Mar 25 18:30:06 katarynka go-librespot[23562]: time="2026-03-25T18:30:06+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 18:30:06 katarynka go-librespot[23562]: time="2026-03-25T18:30:06+01:00" level=warning msg="failed to connect to AP ap-gew4.spotify.com:443, retrying with a different AP" error="dial tcp 34.158.1.133:443: connect: connection refused" Mar 25 18:30:06 katarynka go-librespot[23562]: time="2026-03-25T18:30:06+01:00" level=debug msg="connected to ap-gew4.spotify.com:80" Mar 25 18:30:06 katarynka go-librespot[23562]: time="2026-03-25T18:30:06+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Mar 25 18:30:06 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 18:30:06 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 18:30:07 katarynka volumio[23483]: info: Loading plugin "outputs"... Mar 25 18:30:07 katarynka volumio[23483]: info: Loading plugin "albumart"... Mar 25 18:30:07 katarynka volumio[23483]: info: Plugin example_plugin is not enabled Mar 25 18:30:07 katarynka volumio[23483]: info: Loading plugin "inputs"... Mar 25 18:30:08 katarynka volumio[23483]: info: Loading plugin "updater_comm"... Mar 25 18:30:08 katarynka volumio[23483]: info: Plugin mpdemulation is not enabled Mar 25 18:30:08 katarynka volumio[23483]: info: Loading plugin "rest_api"... Mar 25 18:30:08 katarynka volumio[23483]: info: Loading plugin "websocket"... Mar 25 18:30:08 katarynka volumio[23483]: info: Starting Socket.io Server version 1.7.4 Mar 25 18:30:08 katarynka volumio[23483]: info: Loading i18n strings for locale pl Mar 25 18:30:08 katarynka volumio[23483]: Updating browse sources language Mar 25 18:30:08 katarynka volumio[23483]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 25 18:30:08 katarynka volumio[23483]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 25 18:30:08 katarynka volumio[23483]: info: CoreCommandRouter::initPlayerControls Mar 25 18:30:08 katarynka volumio[23483]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 18:30:08 katarynka volumio[23483]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 18:30:08 katarynka volumio[23483]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 18:30:08 katarynka volumio[23483]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 18:30:08 katarynka volumio[23483]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 18:30:08 katarynka volumio[23483]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 18:30:08 katarynka volumio[23483]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 18:30:08 katarynka volumio[23483]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 18:30:08 katarynka volumio[23483]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 25 18:30:08 katarynka volumio[23483]: Express server listening on port 3000 Mar 25 18:30:08 katarynka volumio[23483]: [Metrics] WebUI: 12s 490.07ms Mar 25 18:30:08 katarynka volumio[23483]: info: CoreStateMachine::resetVolumioState Mar 25 18:30:08 katarynka volumio[23483]: info: CoreStateMachine::getcurrentVolume Mar 25 18:30:08 katarynka volumio[23483]: info: CoreCommandRouter::volumioRetrievevolume Mar 25 18:30:08 katarynka volumio[23483]: info: Cannot read play queue from file Mar 25 18:30:08 katarynka volumio[23483]: info: Volumio Network Manager: Network status updated: 2 Mar 25 18:30:08 katarynka volumio[23576]: Forking 3 albumart workers Mar 25 18:30:09 katarynka volumio[23483]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 18:30:09 katarynka volumio[23483]: info: CoreStateMachine::setRepeat null single undefined Mar 25 18:30:09 katarynka volumio[23483]: info: CoreStateMachine::pushState Mar 25 18:30:09 katarynka volumio[23483]: info: CorePlayQueue::getTrack 0 Mar 25 18:30:09 katarynka volumio[23483]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 25 18:30:09 katarynka volumio[23483]: info: CoreCommandRouter::volumioPushState Mar 25 18:30:09 katarynka volumio[23483]: info: CoreStateMachine::setRandom null Mar 25 18:30:09 katarynka volumio[23483]: info: CoreStateMachine::pushState Mar 25 18:30:09 katarynka volumio[23483]: info: CorePlayQueue::getTrack 0 Mar 25 18:30:09 katarynka volumio[23483]: info: CoreCommandRouter::volumioPushState Mar 25 18:30:09 katarynka volumio[23483]: info: Setting Device type: Raspberry PI Mar 25 18:30:09 katarynka volumio[23483]: info: Completed loading Core Plugins Mar 25 18:30:09 katarynka volumio[23483]: info: Preparing to generate the ALSA configuration file Mar 25 18:30:09 katarynka volumio[23483]: info: VolumeController:: Volume=96 Mute =false Mar 25 18:30:09 katarynka volumio[23483]: info: CoreStateMachine::pushState Mar 25 18:30:09 katarynka volumio[23483]: info: CorePlayQueue::getTrack 0 Mar 25 18:30:09 katarynka volumio[23483]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 25 18:30:09 katarynka volumio[23483]: info: CoreCommandRouter::volumioPushState Mar 25 18:30:09 katarynka volumio[23483]: info: CoreStateMachine::updateTrackBlock Mar 25 18:30:09 katarynka volumio[23483]: info: CorePlayQueue::getTrackBlock Mar 25 18:30:09 katarynka volumio[23483]: info: CoreCommandRouter::volumioRetrievevolume Mar 25 18:30:09 katarynka volumio[23483]: info: Asound.conf file unchanged, so no further update is needed Mar 25 18:30:09 katarynka volumio[23483]: info: Output device has changed, restarting MPD Mar 25 18:30:09 katarynka volumio[23483]: info: Output device has changed, restarting Shairport Sync Mar 25 18:30:09 katarynka volumio[23483]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 18:30:09 katarynka volumio[23483]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 18:30:09 katarynka sudo[23629]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 25 18:30:09 katarynka sudo[23629]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 18:30:09 katarynka sudo[23631]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 25 18:30:09 katarynka sudo[23631]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 18:30:09 katarynka sudo[23629]: pam_unix(sudo:session): session closed for user root Mar 25 18:30:09 katarynka volumio[23483]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 25 18:30:09 katarynka volumio[23483]: info: ___________ START PLUGINS ___________ Mar 25 18:30:09 katarynka volumio[23483]: info: ControllerMpd::onStart: Initializing MPD Mar 25 18:30:09 katarynka volumio[23483]: info: Creating MPD Configuration file Mar 25 18:30:09 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Mar 25 18:30:09 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 18:30:09 katarynka volumio[23483]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 25 18:30:09 katarynka volumio[23483]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 25 18:30:09 katarynka volumio[23483]: info: [1774459809736] CoreMusicLibrary::Adding element Serwery Mediów Mar 25 18:30:09 katarynka volumio[23483]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 25 18:30:09 katarynka volumio[23483]: info: UPNP Browser: Client initialized successfully Mar 25 18:30:09 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 18:30:09 katarynka go-librespot[23641]: go-librespot daemon starting... Mar 25 18:30:09 katarynka systemd[1]: Stopping mpd.service - Music Player Daemon... Mar 25 18:30:09 katarynka sudo[23639]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 25 18:30:09 katarynka upmpdcli[1473]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Mar 25 18:30:09 katarynka sudo[23639]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 18:30:09 katarynka sudo[23642]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 25 18:30:09 katarynka sudo[23642]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 18:30:09 katarynka sudo[23639]: pam_unix(sudo:session): session closed for user root Mar 25 18:30:09 katarynka go-librespot[23643]: time="2026-03-25T18:30:09+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 18:30:09 katarynka go-librespot[23643]: time="2026-03-25T18:30:09+01:00" level=debug msg="app state loaded" Mar 25 18:30:09 katarynka go-librespot[23643]: time="2026-03-25T18:30:09+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 18:30:09 katarynka systemd[1]: mpd.service: Deactivated successfully. Mar 25 18:30:09 katarynka systemd[1]: Stopped mpd.service - Music Player Daemon. Mar 25 18:30:09 katarynka systemd[1]: mpd.service: Consumed 7.666s CPU time. Mar 25 18:30:09 katarynka systemd[1]: mpd.socket: Deactivated successfully. Mar 25 18:30:09 katarynka systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Mar 25 18:30:09 katarynka systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Mar 25 18:30:09 katarynka volumio[23483]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 18:30:09 katarynka volumio[23483]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 18:30:10 katarynka volumio[23483]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 25 18:30:10 katarynka systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Mar 25 18:30:10 katarynka volumio[23483]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 18:30:10 katarynka volumio[23483]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 18:30:10 katarynka systemd[1]: Starting mpd.service - Music Player Daemon... Mar 25 18:30:10 katarynka volumio[23483]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 25 18:30:10 katarynka volumio[23483]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 25 18:30:10 katarynka volumio[23483]: info: [1774459810121] CoreMusicLibrary::Adding element Last_100 Mar 25 18:30:10 katarynka volumio[23483]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 25 18:30:10 katarynka volumio[23483]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 25 18:30:10 katarynka volumio[23483]: info: [1774459810153] CoreMusicLibrary::Adding element Webradio Mar 25 18:30:10 katarynka volumio[23483]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 25 18:30:10 katarynka systemd[1]: mpd.service: Deactivated successfully. Mar 25 18:30:10 katarynka systemd[1]: Stopped mpd.service - Music Player Daemon. Mar 25 18:30:10 katarynka systemd[1]: mpd.socket: Deactivated successfully. Mar 25 18:30:10 katarynka systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Mar 25 18:30:10 katarynka systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Mar 25 18:30:10 katarynka volumio[23483]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 25 18:30:10 katarynka volumio[23483]: info: Initializing BBC Radios Mar 25 18:30:10 katarynka systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Mar 25 18:30:10 katarynka systemd[1]: Starting mpd.service - Music Player Daemon... Mar 25 18:30:10 katarynka volumio[23483]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 25 18:30:10 katarynka volumio[23483]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 18:30:10 katarynka go-librespot[23643]: time="2026-03-25T18:30:10+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Mar 25 18:30:10 katarynka go-librespot[23643]: time="2026-03-25T18:30:10+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Mar 25 18:30:10 katarynka go-librespot[23643]: time="2026-03-25T18:30:10+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Mar 25 18:30:10 katarynka volumio[23483]: info: Creating Spotify config file Mar 25 18:30:10 katarynka volumio[23483]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 18:30:10 katarynka go-librespot[23643]: time="2026-03-25T18:30:10+01:00" level=info msg="zeroconf server listening on port 45121" Mar 25 18:30:10 katarynka volumio-remote-updater[686]: [2026-03-25 18:30:10] [connect] Successful connection Mar 25 18:30:10 katarynka go-librespot[23643]: time="2026-03-25T18:30:10+01:00" level=debug msg="obtained new client token: AAAiWKZTBwWf5SaPitE4a+Aq3M6xEeqqG0tL6Uzk8cPOlh7aXEuwMp6Gp5oh6zX9HT+0Oc4kn/TkGV4CrMX4W1odVAB1swOQW1CUn90cYNO11pLccgpXkbdfvREXmPdyZSChyb9wnolUhvKi/Ku7KaOdw3xLuS3HJI+qFq+0MaU6KIClku4/gkbsUnvCEU/orYyjVz/d07eZcpCs0XjgfiMvAhJBgO6oPHsQOthgOZIDQ6KUjdYQrY2VgHI=" Mar 25 18:30:10 katarynka sudo[23665]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Mar 25 18:30:10 katarynka sudo[23665]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Mar 25 18:30:10 katarynka sudo[23665]: pam_unix(sudo:session): session closed for user root Mar 25 18:30:11 katarynka go-librespot[23643]: time="2026-03-25T18:30:11+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 18:30:11 katarynka go-librespot[23643]: time="2026-03-25T18:30:11+01:00" level=debug msg="completed keyexchange" Mar 25 18:30:11 katarynka go-librespot[23643]: time="2026-03-25T18:30:11+01:00" level=debug msg="completed challenge" Mar 25 18:30:11 katarynka go-librespot[23643]: time="2026-03-25T18:30:11+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 25 18:30:11 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 18:30:11 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 18:30:12 katarynka volumio[23483]: info: Volumio Calling Home Mar 25 18:30:12 katarynka volumio[23592]: Starting albumart workers Mar 25 18:30:12 katarynka volumio[23590]: Starting albumart workers Mar 25 18:30:13 katarynka volumio[23593]: Starting albumart workers Mar 25 18:30:13 katarynka volumio[23483]: info: Discovery: adding 4d616d77-6a8c-4da2-85a4-840d70f98e51 Mar 25 18:30:13 katarynka volumio[23483]: info: Discovery: Found device katarynka Mar 25 18:30:13 katarynka volumio[23483]: info: CoreCommandRouter::volumioGetState Mar 25 18:30:13 katarynka volumio[23483]: info: CorePlayQueue::getTrack 0 Mar 25 18:30:13 katarynka volumio[23483]: info: Discovery: this is already registered, 4d616d77-6a8c-4da2-85a4-840d70f98e51 Mar 25 18:30:13 katarynka volumio[23483]: info: Discovery: Found device katarynka Mar 25 18:30:13 katarynka volumio[23483]: info: CoreCommandRouter::volumioGetState Mar 25 18:30:13 katarynka volumio[23483]: info: CorePlayQueue::getTrack 0 Mar 25 18:30:13 katarynka sudo[23700]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 25 18:30:13 katarynka sudo[23699]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 25 18:30:13 katarynka sudo[23700]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 18:30:13 katarynka sudo[23699]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 18:30:13 katarynka sudo[23700]: pam_unix(sudo:session): session closed for user root Mar 25 18:30:13 katarynka sudo[23699]: pam_unix(sudo:session): session closed for user root Mar 25 18:30:13 katarynka volumio[23483]: info: MPD Permissions set Mar 25 18:30:13 katarynka volumio[23483]: info: MPD Permissions set Mar 25 18:30:13 katarynka volumio-remote-updater[686]: [2026-03-25 18:30:13] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1774459810 101 Mar 25 18:30:13 katarynka volumio[23483]: 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 18:30:13 katarynka volumio[23483]: info: Volumio called home Mar 25 18:30:13 katarynka volumio[23483]: info: Spotify config file written Mar 25 18:30:14 katarynka sudo[23706]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Mar 25 18:30:14 katarynka sudo[23706]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 18:30:14 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 18:30:14 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 18:30:14 katarynka go-librespot[23708]: go-librespot daemon starting... Mar 25 18:30:14 katarynka sudo[23706]: pam_unix(sudo:session): session closed for user root Mar 25 18:30:14 katarynka go-librespot[23709]: time="2026-03-25T18:30:14+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 18:30:14 katarynka go-librespot[23709]: time="2026-03-25T18:30:14+01:00" level=debug msg="app state loaded" Mar 25 18:30:14 katarynka go-librespot[23709]: time="2026-03-25T18:30:14+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 18:30:14 katarynka volumio[23483]: 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 18:30:14 katarynka volumio[23483]: info: VolumeController:: Volume=96 Mute =false Mar 25 18:30:14 katarynka volumio[23483]: info: CoreStateMachine::pushState Mar 25 18:30:14 katarynka volumio[23483]: info: CorePlayQueue::getTrack 0 Mar 25 18:30:14 katarynka volumio[23483]: info: CoreCommandRouter::volumioPushState Mar 25 18:30:14 katarynka volumio[23483]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 18:30:14 katarynka volumio[23483]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 18:30:14 katarynka volumio[23483]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 18:30:14 katarynka volumio[23483]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 18:30:14 katarynka volumio[23483]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 18:30:14 katarynka volumio[23483]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 18:30:14 katarynka volumio[23483]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 18:30:14 katarynka volumio[23483]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 18:30:14 katarynka volumio[23483]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 18:30:14 katarynka volumio[23483]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 18:30:14 katarynka volumio[23483]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 18:30:14 katarynka volumio[23483]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 18:30:14 katarynka volumio[23483]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 18:30:14 katarynka volumio[23483]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 18:30:14 katarynka volumio[23483]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 18:30:14 katarynka volumio[23483]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 18:30:14 katarynka volumio[23483]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 18:30:14 katarynka volumio[23483]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 18:30:14 katarynka volumio[23483]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 18:30:14 katarynka volumio[23483]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 18:30:14 katarynka volumio[23483]: info: No need to fix Spotify hosts Mar 25 18:30:14 katarynka go-librespot[23709]: time="2026-03-25T18:30:14+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Mar 25 18:30:14 katarynka go-librespot[23709]: time="2026-03-25T18:30:14+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Mar 25 18:30:14 katarynka go-librespot[23709]: time="2026-03-25T18:30:14+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Mar 25 18:30:15 katarynka go-librespot[23709]: time="2026-03-25T18:30:15+01:00" level=info msg="zeroconf server listening on port 44013" Mar 25 18:30:15 katarynka go-librespot[23709]: time="2026-03-25T18:30:15+01:00" level=debug msg="obtained new client token: AACPDHDDChXKPGNuxe6KCTcY62u5uZn7rjyROjaNAOyK/3aIJfWdory958ppRe+hxbqtQ9o7equQwzICZ3kYtGnsAURN/57qaPMsqbwa2KJCudlY8rS1L2BpF0SAmU4gWQoCQXGY+fRc4KVz/0DHlBWGn7azNZR/f4oZJRAci0hZ+gG3vwPlZFyd+1FsDAMX8Te7H5RVXVwaRbYT9B3C7YmiUygqHlZt0sjTG921f6aJBD6kWiAFzMhU" Mar 25 18:30:15 katarynka go-librespot[23709]: time="2026-03-25T18:30:15+01:00" level=warning msg="failed to connect to AP ap-gew4.spotify.com:4070, retrying with a different AP" error="dial tcp 34.158.1.133:4070: connect: connection refused" Mar 25 18:30:15 katarynka go-librespot[23709]: time="2026-03-25T18:30:15+01:00" level=debug msg="connected to ap-gew4.spotify.com:443" Mar 25 18:30:15 katarynka volumio[23483]: info: Starting Shairport Sync Mar 25 18:30:15 katarynka go-librespot[23709]: time="2026-03-25T18:30:15+01:00" level=debug msg="completed keyexchange" Mar 25 18:30:15 katarynka go-librespot[23709]: time="2026-03-25T18:30:15+01:00" level=debug msg="completed challenge" Mar 25 18:30:15 katarynka volumio[23483]: info: Starting Shairport Sync Mar 25 18:30:15 katarynka go-librespot[23709]: time="2026-03-25T18:30: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 18:30:15 katarynka volumio[23483]: info: Starting Shairport Sync Mar 25 18:30:15 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 18:30:15 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 18:30:15 katarynka sudo[23744]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 25 18:30:15 katarynka sudo[23744]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 18:30:15 katarynka sudo[23747]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 25 18:30:15 katarynka sudo[23747]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 18:30:15 katarynka sudo[23749]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 25 18:30:15 katarynka sudo[23749]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 18:30:15 katarynka sudo[23751]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Mar 25 18:30:15 katarynka sudo[23751]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 18:30:15 katarynka volumio[23483]: info: CoreCommandRouter::volumioGetState Mar 25 18:30:15 katarynka volumio[23483]: info: CorePlayQueue::getTrack 0 Mar 25 18:30:15 katarynka upmpdcli[1473]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Timeout Mar 25 18:30:15 katarynka upmpdcli[1473]: :2:../src/mpdcli.cxx:396::MPDCli::updStatus: connection failed Mar 25 18:30:15 katarynka upmpdcli[1473]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Mar 25 18:30:15 katarynka systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Mar 25 18:30:15 katarynka sudo[23751]: pam_unix(sudo:session): session closed for user root Mar 25 18:30:15 katarynka systemd[1]: shairport-sync.service: Deactivated successfully. Mar 25 18:30:15 katarynka systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 25 18:30:15 katarynka systemd[1]: shairport-sync.service: Consumed 2.146s CPU time. Mar 25 18:30:15 katarynka volumio[23483]: info: Upmpdcli Daemon Started Mar 25 18:30:15 katarynka systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 25 18:30:15 katarynka sudo[23749]: pam_unix(sudo:session): session closed for user root Mar 25 18:30:15 katarynka sudo[23747]: pam_unix(sudo:session): session closed for user root Mar 25 18:30:15 katarynka sudo[23744]: pam_unix(sudo:session): session closed for user root Mar 25 18:30:15 katarynka volumio[23483]: info: Shairport-Sync Started Mar 25 18:30:15 katarynka volumio[23483]: Error adding Membership: Error: addMembership EINVAL Mar 25 18:30:15 katarynka volumio[23483]: info: Shairport-Sync Started Mar 25 18:30:15 katarynka volumio[23483]: info: Shairport-Sync Started Mar 25 18:30:16 katarynka volumio[23483]: info: An error occurred while refreshing Spotify Token Error: Bad Request Mar 25 18:30:18 katarynka volumio[23483]: info: go-librespot daemon successfully initialized Mar 25 18:30:18 katarynka mpd[23679]: 2026-03-25T18:30:18 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Mar 25 18:30:18 katarynka systemd[1]: Started mpd.service - Music Player Daemon. Mar 25 18:30:18 katarynka upmpdcli[1473]: :3:../src/mpdcli.cxx:148::MPDCli::startEventLoop: already started Mar 25 18:30:18 katarynka sudo[23631]: pam_unix(sudo:session): session closed for user root Mar 25 18:30:18 katarynka sudo[23642]: pam_unix(sudo:session): session closed for user root Mar 25 18:30:18 katarynka volumio[23483]: info: Completed starting Core Plugins Mar 25 18:30:18 katarynka volumio[23483]: info: ------------------------------------------- Mar 25 18:30:18 katarynka volumio[23483]: info: ----- MyVolumio plugins startup ---- Mar 25 18:30:18 katarynka volumio[23483]: info: ------------------------------------------- Mar 25 18:30:18 katarynka volumio[23483]: info: [MyVolumio PluginManager] Fetching plans data.... Mar 25 18:30:18 katarynka volumio[23483]: error: MPD error: The expression evaluated to a falsy value: Mar 25 18:30:18 katarynka volumio[23483]: assert.ok(self.idling) Mar 25 18:30:18 katarynka volumio[23483]: error: The expression evaluated to a falsy value: Mar 25 18:30:18 katarynka volumio[23483]: assert.ok(self.idling) Mar 25 18:30:18 katarynka volumio[23483]: error: updateQueue error: null Mar 25 18:30:18 katarynka volumio[23483]: info: MPD running with PID23679 Mar 25 18:30:18 katarynka volumio[23483]: ,establishing connection Mar 25 18:30:18 katarynka volumio[23483]: error: updateQueue error: null Mar 25 18:30:18 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Mar 25 18:30:18 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 18:30:18 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 18:30:18 katarynka go-librespot[23778]: go-librespot daemon starting... Mar 25 18:30:18 katarynka go-librespot[23779]: time="2026-03-25T18:30:18+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 18:30:18 katarynka go-librespot[23779]: time="2026-03-25T18:30:18+01:00" level=debug msg="app state loaded" Mar 25 18:30:18 katarynka go-librespot[23779]: time="2026-03-25T18:30:18+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 18:30:19 katarynka go-librespot[23779]: time="2026-03-25T18:30: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 18:30:19 katarynka go-librespot[23779]: time="2026-03-25T18:30: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 18:30:19 katarynka go-librespot[23779]: time="2026-03-25T18:30: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 18:30:19 katarynka go-librespot[23779]: time="2026-03-25T18:30:19+01:00" level=info msg="zeroconf server listening on port 36999" Mar 25 18:30:19 katarynka go-librespot[23779]: time="2026-03-25T18:30:19+01:00" level=debug msg="obtained new client token: AACxcKh9gqJqCXV1PjF0hkmT5YRsZfTxBU+4FVnrXGaxIJB45J5vJ7W8ba2KLxt0D2GsXbUIsbrJO1q/B3ZD4u9xiaipTfcWMURuwkKuJzITJIPCS3RrqggVlCPeKqvjCiRjgKMu2zbXxzyaSkRhLW9om9mz72VS0USRQTWnaaT6DCzxhkvNDHiccTVGKChUhN2b5fKCz9bslLqYxrRYH49YZpEQMNLpjtp4NFJVM5OpIDtPWU9x68rId+E=" Mar 25 18:30:19 katarynka go-librespot[23779]: time="2026-03-25T18:30:19+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 18:30:19 katarynka go-librespot[23779]: time="2026-03-25T18:30:19+01:00" level=debug msg="completed keyexchange" Mar 25 18:30:19 katarynka go-librespot[23779]: time="2026-03-25T18:30:19+01:00" level=debug msg="completed challenge" Mar 25 18:30:19 katarynka go-librespot[23779]: time="2026-03-25T18:30: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 18:30:19 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 18:30:19 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 18:30:21 katarynka volumio[23483]: info: Initializing connection to go-librespot Websocket Mar 25 18:30:21 katarynka volumio[23483]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 25 18:30:21 katarynka sudo[23801]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Mar 25 18:30:21 katarynka sudo[23801]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 18:30:21 katarynka sudo[23803]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Mar 25 18:30:21 katarynka sudo[23803]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 18:30:21 katarynka systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Mar 25 18:30:21 katarynka systemd[1]: mpd_monitor.service: Deactivated successfully. Mar 25 18:30:21 katarynka systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Mar 25 18:30:21 katarynka systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Mar 25 18:30:21 katarynka sudo[23803]: pam_unix(sudo:session): session closed for user root Mar 25 18:30:21 katarynka sudo[23801]: pam_unix(sudo:session): session closed for user root Mar 25 18:30:21 katarynka mpd_monitor.sh[23806]: MPD Monitor Service: Starting MPD Monitor Service Mar 25 18:30:21 katarynka volumio[23483]: info: Successfully started MPD Monitor Mar 25 18:30:21 katarynka volumio[23483]: info: Successfully started MPD Monitor Mar 25 18:30:22 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Mar 25 18:30:22 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 18:30:22 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 18:30:22 katarynka go-librespot[23810]: go-librespot daemon starting... Mar 25 18:30:22 katarynka go-librespot[23811]: time="2026-03-25T18:30:22+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 18:30:22 katarynka go-librespot[23811]: time="2026-03-25T18:30:22+01:00" level=debug msg="app state loaded" Mar 25 18:30:22 katarynka go-librespot[23811]: time="2026-03-25T18:30:22+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 18:30:23 katarynka go-librespot[23811]: time="2026-03-25T18:30:23+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 25 18:30:23 katarynka go-librespot[23811]: time="2026-03-25T18:30:23+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 18:30:23 katarynka go-librespot[23811]: time="2026-03-25T18:30:23+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 18:30:23 katarynka go-librespot[23811]: time="2026-03-25T18:30:23+01:00" level=info msg="zeroconf server listening on port 33583" Mar 25 18:30:23 katarynka go-librespot[23811]: time="2026-03-25T18:30:23+01:00" level=debug msg="obtained new client token: AAAi5i6IZ1LuniBM1D50DKv7o/bpTY9pbZWFCCAQSH2PKTGxU00D65xkDj48Fv/NENCcKTKUkT/Ut0ly4foQDZ+mEW4qoZsORTCxryHm2hxwzwgg1ycD444kiVeAZbIf2MV479mCdwp12cjdZZxY2Y52/TAQ3ORdEFKEjUcMvOkuUKqNoFYhg8u5TwnR1cWspKn95aqlNo/eMtOLymR8Tg7yrT3AfrTHrLNeDS1CV3r3iIYoSEzTNOgRrDE=" Mar 25 18:30:23 katarynka go-librespot[23811]: time="2026-03-25T18:30:23+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 18:30:23 katarynka go-librespot[23811]: time="2026-03-25T18:30:23+01:00" level=debug msg="completed keyexchange" Mar 25 18:30:23 katarynka go-librespot[23811]: time="2026-03-25T18:30:23+01:00" level=debug msg="completed challenge" Mar 25 18:30:23 katarynka volumio[23483]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Mar 25 18:30:23 katarynka go-librespot[23811]: time="2026-03-25T18:30:23+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 25 18:30:23 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 18:30:23 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 18:30:24 katarynka volumio[23483]: info: Initializing connection to go-librespot Websocket Mar 25 18:30:24 katarynka volumio[23483]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 25 18:30:26 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Mar 25 18:30:26 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 18:30:26 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 18:30:26 katarynka go-librespot[23818]: go-librespot daemon starting... Mar 25 18:30:26 katarynka go-librespot[23819]: time="2026-03-25T18:30:26+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 18:30:26 katarynka go-librespot[23819]: time="2026-03-25T18:30:26+01:00" level=debug msg="app state loaded" Mar 25 18:30:26 katarynka go-librespot[23819]: time="2026-03-25T18:30:26+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 18:30:26 katarynka volumio[23483]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Mar 25 18:30:26 katarynka volumio[23483]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Mar 25 18:30:26 katarynka volumio[23483]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Mar 25 18:30:26 katarynka volumio[23483]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Mar 25 18:30:26 katarynka volumio[23483]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Mar 25 18:30:26 katarynka volumio[23483]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Mar 25 18:30:26 katarynka volumio[23483]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Mar 25 18:30:26 katarynka volumio[23483]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Mar 25 18:30:26 katarynka volumio[23483]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Mar 25 18:30:26 katarynka volumio[23483]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Mar 25 18:30:26 katarynka volumio[23483]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Mar 25 18:30:26 katarynka volumio[23483]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Mar 25 18:30:26 katarynka volumio[23483]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Mar 25 18:30:26 katarynka volumio[23483]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Mar 25 18:30:26 katarynka volumio[23483]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Mar 25 18:30:26 katarynka volumio[23483]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Mar 25 18:30:26 katarynka volumio[23483]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Mar 25 18:30:26 katarynka volumio[23483]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Mar 25 18:30:26 katarynka volumio[23483]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Mar 25 18:30:26 katarynka volumio[23483]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Mar 25 18:30:26 katarynka volumio[23483]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Mar 25 18:30:26 katarynka volumio[23483]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Mar 25 18:30:26 katarynka volumio[23483]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Mar 25 18:30:26 katarynka volumio[23483]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Mar 25 18:30:26 katarynka volumio[23483]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Mar 25 18:30:26 katarynka volumio[23483]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Mar 25 18:30:26 katarynka volumio[23483]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Mar 25 18:30:26 katarynka volumio[23483]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Mar 25 18:30:26 katarynka volumio[23483]: info: Adding plugin bluetooth to MyMusic Plugins Mar 25 18:30:26 katarynka volumio[23483]: info: Adding plugin multiroom to MyMusic Plugins Mar 25 18:30:26 katarynka volumio[23483]: info: Adding plugin metavolumio to MyMusic Plugins Mar 25 18:30:26 katarynka volumio[23483]: info: Adding plugin cd_controller to MyMusic Plugins Mar 25 18:30:26 katarynka volumio[23483]: info: Adding plugin qobuzconnect to MyMusic Plugins Mar 25 18:30:26 katarynka volumio[23483]: info: Adding plugin smart_inputs to MyMusic Plugins Mar 25 18:30:26 katarynka volumio[23483]: info: Adding plugin tidalconnect to MyMusic Plugins Mar 25 18:30:26 katarynka volumio[23483]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Mar 25 18:30:27 katarynka go-librespot[23819]: time="2026-03-25T18:30:27+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Mar 25 18:30:27 katarynka go-librespot[23819]: time="2026-03-25T18:30:27+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Mar 25 18:30:27 katarynka go-librespot[23819]: time="2026-03-25T18:30:27+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Mar 25 18:30:27 katarynka go-librespot[23819]: time="2026-03-25T18:30:27+01:00" level=info msg="zeroconf server listening on port 44203" Mar 25 18:30:27 katarynka go-librespot[23819]: time="2026-03-25T18:30:27+01:00" level=debug msg="obtained new client token: AADO6wdgKJv/UwO8tn+AxiYBRDLAcb8dkJNmc0N6c9ApVojJnLI1LGhqHMTyRuq050oFAvJsrxyU+OxaTXiEZQ1+T2+0rK649O5dscevkgf6wbIm3eAtK2EbdMlaso5d5eqgQXhb57Yq4550OCzaSdIKtxYxutRlVvMXvQiSamUaw8muXJLy5j/UefLATj3gSZJddLtPtN4Am3iE2I2CZogeU+1YPVr4BLCtAsr7SM/tXLHq6vGRpjJHjw4=" Mar 25 18:30:27 katarynka go-librespot[23819]: time="2026-03-25T18:30:27+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 18:30:27 katarynka go-librespot[23819]: time="2026-03-25T18:30:27+01:00" level=debug msg="completed keyexchange" Mar 25 18:30:27 katarynka go-librespot[23819]: time="2026-03-25T18:30:27+01:00" level=debug msg="completed challenge" Mar 25 18:30:27 katarynka go-librespot[23819]: time="2026-03-25T18:30:27+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 25 18:30:27 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 18:30:27 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 18:30:29 katarynka volumio[23483]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Mar 25 18:30:29 katarynka volumio[23483]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Mar 25 18:30:29 katarynka volumio[23483]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 18:30:29 katarynka volumio[23483]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 18:30:29 katarynka volumio[23483]: info: Starting MyVolumio Remote Streaming Endpoints Mar 25 18:30:29 katarynka volumio[23483]: info: MyVolumio login type: Token Mar 25 18:30:29 katarynka volumio[23483]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Mar 25 18:30:29 katarynka volumio[23483]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Mar 25 18:30:30 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 11. Mar 25 18:30:30 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 18:30:30 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 18:30:30 katarynka go-librespot[23827]: go-librespot daemon starting... Mar 25 18:30:30 katarynka go-librespot[23828]: time="2026-03-25T18:30:30+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 18:30:30 katarynka go-librespot[23828]: time="2026-03-25T18:30:30+01:00" level=debug msg="app state loaded" Mar 25 18:30:30 katarynka go-librespot[23828]: time="2026-03-25T18:30:30+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 18:30:30 katarynka volumio[23483]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Mar 25 18:30:30 katarynka volumio[23483]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Mar 25 18:30:30 katarynka volumio[23483]: info: Streaming services startup Mar 25 18:30:30 katarynka volumio[23483]: info: Starting Streaming Daemon Mar 25 18:30:30 katarynka sudo[23837]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Mar 25 18:30:30 katarynka sudo[23837]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 18:30:30 katarynka volumio[23483]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Mar 25 18:30:31 katarynka sudo[23837]: pam_unix(sudo:session): session closed for user root Mar 25 18:30:31 katarynka volumio[23483]: info: Initializing connection to go-librespot Websocket Mar 25 18:30:31 katarynka volumio[23483]: error: Cannot start Volumio Streaming Daemon Mar 25 18:30:31 katarynka volumio[23483]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Mar 25 18:30:31 katarynka volumio[23483]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Mar 25 18:30:31 katarynka go-librespot[23828]: time="2026-03-25T18:30:31+01:00" level=debug msg="new websocket client" Mar 25 18:30:31 katarynka volumio[23483]: info: Connection to go-librespot Websocket established Mar 25 18:30:31 katarynka go-librespot[23828]: time="2026-03-25T18:30:31+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 25 18:30:31 katarynka go-librespot[23828]: time="2026-03-25T18:30:31+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 25 18:30:31 katarynka go-librespot[23828]: time="2026-03-25T18:30:31+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 25 18:30:31 katarynka go-librespot[23828]: time="2026-03-25T18:30:31+01:00" level=info msg="zeroconf server listening on port 35359" Mar 25 18:30:31 katarynka go-librespot[23828]: time="2026-03-25T18:30:31+01:00" level=debug msg="obtained new client token: AADns6zD2NmDiiKZgoiRqEzTpDoSMzNnkLrv+zE5DWEP4aIAB/Izdwe6m8VAjqxQLUNrZHRUPo3zV0jvsN9XNGMvtFDZ8u1zUtzLiICMHzBQFj0P9b+59BkH1aDtUqwfigGJakcGjJQrI2o7zJP1Wq/Jj8VEZBQaeS2DXj/xQElVMFI1APyKnVuoMJPQY8m4ewnfD4zzfQ8pHiXNWVDMnehb0x/+kDaMwKfozFUhoKKlKcmrKf80Ntdlq7k=" Mar 25 18:30:31 katarynka go-librespot[23828]: time="2026-03-25T18:30:31+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 18:30:31 katarynka go-librespot[23828]: time="2026-03-25T18:30:31+01:00" level=debug msg="completed keyexchange" Mar 25 18:30:31 katarynka go-librespot[23828]: time="2026-03-25T18:30:31+01:00" level=debug msg="completed challenge" Mar 25 18:30:31 katarynka go-librespot[23828]: time="2026-03-25T18:30:31+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 25 18:30:31 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 18:30:31 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 18:30:31 katarynka volumio[23483]: info: Connection to go-librespot Websocket closed Mar 25 18:30:31 katarynka volumio[23483]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Mar 25 18:30:32 katarynka volumio[23483]: info: MyVolumio token set successfully Mar 25 18:30:32 katarynka volumio[23483]: info: MYVOLUMIO: Adding device Mar 25 18:30:32 katarynka volumio[23483]: info: MYVOLUMIO: Evaluating Server Mar 25 18:30:32 katarynka volumio[23483]: info: MyVolumio status changed Mar 25 18:30:32 katarynka volumio[23483]: info: Streaming services startup Mar 25 18:30:32 katarynka volumio[23483]: info: Starting Streaming Daemon Mar 25 18:30:32 katarynka volumio[23483]: info: Removing browser output: myVolumio user plan is not superstar Mar 25 18:30:32 katarynka volumio[23483]: info: Removing audio output: Mar 25 18:30:32 katarynka volumio[23483]: info: Stoppping Tunnel 1 Mar 25 18:30:32 katarynka sudo[23882]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Mar 25 18:30:32 katarynka sudo[23882]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 18:30:32 katarynka sudo[23884]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Mar 25 18:30:32 katarynka sudo[23884]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 18:30:33 katarynka systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Mar 25 18:30:33 katarynka systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Mar 25 18:30:33 katarynka sudo[23882]: pam_unix(sudo:session): session closed for user root Mar 25 18:30:33 katarynka volumio[23483]: error: Cannot start Volumio Streaming Daemon Mar 25 18:30:33 katarynka volumio[23483]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Mar 25 18:30:33 katarynka volumio[23483]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Mar 25 18:30:33 katarynka systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Mar 25 18:30:33 katarynka systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Mar 25 18:30:33 katarynka systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Mar 25 18:30:33 katarynka systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Mar 25 18:30:33 katarynka systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Mar 25 18:30:33 katarynka systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Mar 25 18:30:33 katarynka sudo[23884]: pam_unix(sudo:session): session closed for user root Mar 25 18:30:33 katarynka volumio[23483]: info: Remote SSH Stopped Mar 25 18:30:33 katarynka volumio[23483]: info: Setting Geolocation for MyVolumio to eu10 Mar 25 18:30:33 katarynka volumio[23483]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 18:30:33 katarynka volumio[23483]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 18:30:33 katarynka volumio[23483]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 18:30:33 katarynka volumio[23483]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Mar 25 18:30:34 katarynka volumio[23483]: info: Getting Spotify volume Mar 25 18:30:34 katarynka volumio[23483]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 25 18:30:34 katarynka volumio[23483]: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 25 18:30:34 katarynka volumio[23483]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Mar 25 18:30:34 katarynka volumio[23483]: errno: -111, Mar 25 18:30:34 katarynka volumio[23483]: code: 'ECONNREFUSED', Mar 25 18:30:34 katarynka volumio[23483]: syscall: 'connect', Mar 25 18:30:34 katarynka volumio[23483]: address: '127.0.0.1', Mar 25 18:30:34 katarynka volumio[23483]: port: 9879, Mar 25 18:30:34 katarynka volumio[23483]: response: undefined Mar 25 18:30:34 katarynka volumio[23483]: } Mar 25 18:30:34 katarynka volumio[23483]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 25 18:30:34 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 12. Mar 25 18:30:34 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 18:30:34 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 18:30:34 katarynka go-librespot[23899]: go-librespot daemon starting... Mar 25 18:30:34 katarynka go-librespot[23900]: time="2026-03-25T18:30:34+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 18:30:34 katarynka go-librespot[23900]: time="2026-03-25T18:30:34+01:00" level=debug msg="app state loaded" Mar 25 18:30:34 katarynka go-librespot[23900]: time="2026-03-25T18:30:34+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 18:30:35 katarynka go-librespot[23900]: time="2026-03-25T18:30:35+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 25 18:30:35 katarynka go-librespot[23900]: time="2026-03-25T18:30:35+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 25 18:30:35 katarynka go-librespot[23900]: time="2026-03-25T18:30:35+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 25 18:30:35 katarynka go-librespot[23900]: time="2026-03-25T18:30:35+01:00" level=info msg="zeroconf server listening on port 37939" Mar 25 18:30:35 katarynka go-librespot[23900]: time="2026-03-25T18:30:35+01:00" level=debug msg="obtained new client token: AABmyuuv0LT0gx/leV2ZLSqkRPWVQ4udpx1jjDKwHg8A5ZwaAXwcXMznKy6drx5NQHcykux+6YwMhQACtHNNe6/l/f1eiFiaNEKfCsc7hYbDjjuU9E5+vwlZd2HBYlvlcmFh1p9dXhCqBD8y2gtzponkp7NfJ6ps42nwcvCkMcIVoj9181TjZJX4FfYXw5fbDNugrjLE+yalLbtuZroTZiC5MFG/iHl0jcmOdrMHTdWH0Lw3VjjQXGAOiM8=" Mar 25 18:30:35 katarynka go-librespot[23900]: time="2026-03-25T18:30:35+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 18:30:35 katarynka go-librespot[23900]: time="2026-03-25T18:30:35+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 18:30:35 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 18:30:35 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 18:30:35 katarynka sudo[23910]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-03-25 18:29' Mar 25 18:30:35 katarynka sudo[23910]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 18:30:36 katarynka sudo[23910]: pam_unix(sudo:session): session closed for user root Mar 25 18:30:36 katarynka volumio-remote-updater[686]: [2026-03-25 18:30:36] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Mar 25 18:30:36 katarynka volumio-remote-updater[686]: [2026-03-25 18:30:36] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Mar 25 18:30:36 katarynka systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Mar 25 18:30:36 katarynka systemd[1]: volumio.service: Failed with result 'exit-code'. Mar 25 18:30:36 katarynka systemd[1]: volumio.service: Consumed 50.263s CPU time. Mar 25 18:30:36 katarynka systemd[1]: Started dynamicswap.service - dynamicswap service. Mar 25 18:30:36 katarynka systemd[1]: dynamicswap.service: Deactivated successfully. Mar 25 18:30:36 katarynka systemd[1]: volumio.service: Scheduled restart job, restart counter is at 52. Mar 25 18:30:36 katarynka systemd[1]: Started dynamicswap.service - dynamicswap service. Mar 25 18:30:36 katarynka systemd[1]: Stopped volumio.service - Volumio Backend Module. Mar 25 18:30:36 katarynka systemd[1]: volumio.service: Consumed 50.263s CPU time. Mar 25 18:30:36 katarynka systemd[1]: Started volumio.service - Volumio Backend Module. Mar 25 18:30:36 katarynka systemd[1]: dynamicswap.service: Deactivated successfully. Mar 25 18:30:38 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 13. Mar 25 18:30:38 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 18:30:38 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 18:30:38 katarynka go-librespot[23937]: go-librespot daemon starting... Mar 25 18:30:38 katarynka go-librespot[23938]: time="2026-03-25T18:30:38+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 18:30:38 katarynka go-librespot[23938]: time="2026-03-25T18:30:38+01:00" level=debug msg="app state loaded" Mar 25 18:30:38 katarynka go-librespot[23938]: time="2026-03-25T18:30:38+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 18:30:39 katarynka go-librespot[23938]: time="2026-03-25T18:30:39+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 25 18:30:39 katarynka go-librespot[23938]: time="2026-03-25T18:30:39+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 25 18:30:39 katarynka go-librespot[23938]: time="2026-03-25T18:30:39+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 25 18:30:39 katarynka go-librespot[23938]: time="2026-03-25T18:30:39+01:00" level=info msg="zeroconf server listening on port 38243" Mar 25 18:30:39 katarynka go-librespot[23938]: time="2026-03-25T18:30:39+01:00" level=debug msg="obtained new client token: AABp4QeNTgvRKn9E/cCIY0CVMbYOX82StKXre3CKqU25hT0GhD6vIr87yA277MaS3bT+qPOKqq3ji7u4OlqDinKnMEe1a8Qb8NqESmsB9Lw4WLnMNnjaNkuGDZAXGLcNAOip74MsyUVToZ7ZJZonfKcKq+5EfHz0okl251sy/epJ12AnBMVHLcfe0r378TsWNgT8ghAcaIatQoRMrBqsoG03n9ANJe6NwAg/gYX9bPnhReZUNbTTOFRoXsc=" Mar 25 18:30:39 katarynka go-librespot[23938]: time="2026-03-25T18:30:39+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 18:30:39 katarynka go-librespot[23938]: time="2026-03-25T18:30:39+01:00" level=debug msg="completed keyexchange" Mar 25 18:30:39 katarynka go-librespot[23938]: time="2026-03-25T18:30:39+01:00" level=debug msg="completed challenge" Mar 25 18:30:39 katarynka go-librespot[23938]: time="2026-03-25T18:30:39+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 25 18:30:39 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 18:30:39 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 18:30:40 katarynka volumio[23922]: info: ------------------------------------------- Mar 25 18:30:40 katarynka volumio[23922]: info: ----- Volumio3 ---- Mar 25 18:30:40 katarynka volumio[23922]: info: ------------------------------------------- Mar 25 18:30:40 katarynka volumio[23922]: info: ----- System startup ---- Mar 25 18:30:40 katarynka volumio[23922]: info: ------------------------------------------- Mar 25 18:30:41 katarynka volumio-remote-updater[686]: [2026-03-25 18:30:41] [connect] Successful connection Mar 25 18:30:41 katarynka volumio[23922]: info: MYVOLUMIO Environment detected Mar 25 18:30:41 katarynka volumio[23922]: info: Plugin folders cleanup Mar 25 18:30:41 katarynka volumio[23922]: info: Scanning into folder /volumio/app/plugins/ Mar 25 18:30:41 katarynka volumio[23922]: info: Scanning category audio_interface Mar 25 18:30:41 katarynka volumio[23922]: info: Scanning category miscellanea Mar 25 18:30:41 katarynka volumio[23922]: info: Scanning category music_service Mar 25 18:30:41 katarynka volumio[23922]: info: Scanning category plugins.json Mar 25 18:30:41 katarynka volumio[23922]: info: Scanning category system_controller Mar 25 18:30:41 katarynka volumio[23922]: info: Scanning category user_interface Mar 25 18:30:42 katarynka volumio[23922]: info: Scanning into folder /data/plugins/ Mar 25 18:30:42 katarynka volumio[23922]: info: Scanning category music_service Mar 25 18:30:42 katarynka volumio[23922]: info: Plugin folders cleanup completed Mar 25 18:30:42 katarynka volumio[23922]: info: ------------------------------------------- Mar 25 18:30:42 katarynka volumio[23922]: info: ----- Core plugins startup ---- Mar 25 18:30:42 katarynka volumio[23922]: info: ------------------------------------------- Mar 25 18:30:42 katarynka volumio[23922]: info: Loading plugins from folder /volumio/app/plugins/ Mar 25 18:30:42 katarynka volumio[23922]: info: Adding plugin upnp to MyMusic Plugins Mar 25 18:30:42 katarynka volumio[23922]: info: Adding plugin airplay_emulation to MyMusic Plugins Mar 25 18:30:42 katarynka volumio[23922]: info: Adding plugin upnp_browser to MyMusic Plugins Mar 25 18:30:42 katarynka volumio[23922]: info: Loading plugins from folder /data/plugins/ Mar 25 18:30:42 katarynka volumio[23922]: info: Loading plugin "system"... Mar 25 18:30:42 katarynka volumio[23922]: info: Loading plugin "appearance"... Mar 25 18:30:42 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 14. Mar 25 18:30:42 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 18:30:42 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 18:30:42 katarynka go-librespot[23960]: go-librespot daemon starting... Mar 25 18:30:42 katarynka go-librespot[23961]: time="2026-03-25T18:30:42+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 18:30:42 katarynka go-librespot[23961]: time="2026-03-25T18:30:42+01:00" level=debug msg="app state loaded" Mar 25 18:30:42 katarynka go-librespot[23961]: time="2026-03-25T18:30:42+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 18:30:43 katarynka go-librespot[23961]: time="2026-03-25T18:30:43+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 25 18:30:43 katarynka go-librespot[23961]: time="2026-03-25T18:30:43+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 18:30:43 katarynka go-librespot[23961]: time="2026-03-25T18:30:43+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 18:30:43 katarynka go-librespot[23961]: time="2026-03-25T18:30:43+01:00" level=info msg="zeroconf server listening on port 44875" Mar 25 18:30:43 katarynka go-librespot[23961]: time="2026-03-25T18:30:43+01:00" level=debug msg="obtained new client token: AAB85zK+TOzkdXjokkTZGWKSNOfhH0otf50XIGZUrJzWs+M8jyweRpMoPdvKgsJ8Aq5wNBAmvrRpCq2AMoqcpKaHeeDh9+PVoZPAeoM0uroTtsfAfJwxSDNaGFFlJTrZ2MecD6pVqrwPsW3Igd21vIMF/nOBKI4XZojvcU8mXmnTLWKozj9r39EcMvXxX9gjszlu6aUGAA1BV6COjvDlRzdTUa3WFgsEWgnN2+hCDmH2AGcW+cbYCInr9As=" Mar 25 18:30:43 katarynka go-librespot[23961]: time="2026-03-25T18:30:43+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 18:30:43 katarynka go-librespot[23961]: time="2026-03-25T18:30:43+01:00" level=debug msg="connected to ap-gew4.spotify.com:443" Mar 25 18:30:43 katarynka go-librespot[23961]: time="2026-03-25T18:30:43+01:00" level=debug msg="completed keyexchange" Mar 25 18:30:43 katarynka go-librespot[23961]: time="2026-03-25T18:30:43+01:00" level=debug msg="completed challenge" Mar 25 18:30:43 katarynka go-librespot[23961]: time="2026-03-25T18:30:43+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 25 18:30:43 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 18:30:43 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 18:30:44 katarynka volumio[23922]: info: Loading plugin "network"... Mar 25 18:30:44 katarynka volumio[23922]: info: Refreshing Cached IP Addresses Mar 25 18:30:44 katarynka sudo[23970]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 25 18:30:44 katarynka sudo[23970]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 18:30:44 katarynka sudo[23972]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 25 18:30:44 katarynka sudo[23970]: pam_unix(sudo:session): session closed for user root Mar 25 18:30:44 katarynka sudo[23972]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 18:30:44 katarynka volumio[23922]: info: Loading plugin "services"... Mar 25 18:30:44 katarynka sudo[23972]: pam_unix(sudo:session): session closed for user root Mar 25 18:30:44 katarynka volumio[23922]: info: Loading plugin "alsa_controller"... Mar 25 18:30:44 katarynka sudo[23980]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Mar 25 18:30:44 katarynka sudo[23980]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 18:30:44 katarynka volumio[23922]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 25 18:30:44 katarynka volumio[23922]: info: Loading plugin "wizard"... Mar 25 18:30:44 katarynka volumio[23922]: info: Loading plugin "networkfs"... Mar 25 18:30:44 katarynka volumio[23922]: info: Starting Udev Watcher for removable devices Mar 25 18:30:44 katarynka volumio[23922]: info: Ignoring mount for partition: boot Mar 25 18:30:44 katarynka volumio[23922]: info: Ignoring mount for partition: volumio Mar 25 18:30:44 katarynka volumio[23922]: info: Ignoring mount for partition: volumio_data Mar 25 18:30:44 katarynka volumio[23922]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 25 18:30:44 katarynka volumio[23922]: info: Loading plugin "volumio_command_line_client"... Mar 25 18:30:44 katarynka volumio[23922]: info: Loading plugin "upnp"... Mar 25 18:30:44 katarynka volumio[23922]: info: [1774459844650] Starting Upmpd Daemon Mar 25 18:30:44 katarynka volumio[23922]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 25 18:30:44 katarynka volumio[23922]: info: Loading plugin "my_music"... Mar 25 18:30:44 katarynka volumio[23922]: info: Loading plugin "mpd"... Mar 25 18:30:45 katarynka sudo[23980]: pam_unix(sudo:session): session closed for user root Mar 25 18:30:45 katarynka volumio[23922]: info: Loading plugin "upnp_browser"... Mar 25 18:30:46 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 15. Mar 25 18:30:46 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 18:30:47 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 18:30:47 katarynka go-librespot[24004]: go-librespot daemon starting... Mar 25 18:30:47 katarynka go-librespot[24005]: time="2026-03-25T18:30:47+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 18:30:47 katarynka go-librespot[24005]: time="2026-03-25T18:30:47+01:00" level=debug msg="app state loaded" Mar 25 18:30:47 katarynka go-librespot[24005]: time="2026-03-25T18:30:47+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 18:30:47 katarynka go-librespot[24005]: time="2026-03-25T18:30:47+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Mar 25 18:30:47 katarynka go-librespot[24005]: time="2026-03-25T18:30:47+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 18:30:47 katarynka go-librespot[24005]: time="2026-03-25T18:30:47+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 18:30:47 katarynka go-librespot[24005]: time="2026-03-25T18:30:47+01:00" level=info msg="zeroconf server listening on port 46731" Mar 25 18:30:47 katarynka go-librespot[24005]: time="2026-03-25T18:30:47+01:00" level=debug msg="obtained new client token: AABqUHJZq6dlNC2wRKehmm/QyxtWxv7E7dbqQZ9X6zGZB2H2irK0JyIQ6ciEq6+ERMPzeb78me+zeiZzM1Xu8TRWVWYsYlUSKqpHShJWygXG+BzdLRv8C4WEGlOyUiJYs0djMIY84vQlEbr/ECidzCbms3tkX7DmO3KAo+0RS2xv3o16eerHXRryjvipbYNQB/ZNKFf7BuCcyUQLYUXYFpHy/deztAE2tYj6I8k9CTEDB2exD5dgYDVn1NQ=" Mar 25 18:30:47 katarynka go-librespot[24005]: time="2026-03-25T18:30:47+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 18:30:47 katarynka go-librespot[24005]: time="2026-03-25T18:30:47+01:00" level=debug msg="completed keyexchange" Mar 25 18:30:47 katarynka go-librespot[24005]: time="2026-03-25T18:30:47+01:00" level=debug msg="completed challenge" Mar 25 18:30:47 katarynka go-librespot[24005]: time="2026-03-25T18:30:47+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 25 18:30:47 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 18:30:47 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 18:30:48 katarynka volumio[23922]: info: Starting UPNP Browser Mar 25 18:30:48 katarynka volumio[23922]: info: Loading plugin "alarm-clock"... Mar 25 18:30:48 katarynka volumio[23922]: info: Loading plugin "airplay_emulation"... Mar 25 18:30:48 katarynka volumio[23922]: info: Starting Shairport Sync Mar 25 18:30:48 katarynka volumio[23922]: info: Loading plugin "last_100"... Mar 25 18:30:48 katarynka volumio[23922]: info: Loading plugin "webradio"... Mar 25 18:30:48 katarynka volumio[23922]: info: Loading plugin "i2s_dacs"... Mar 25 18:30:49 katarynka volumio[23922]: info: Loading plugin "volumiodiscovery"... Mar 25 18:30:49 katarynka volumio[23922]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Mar 25 18:30:49 katarynka volumio[23922]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 25 18:30:49 katarynka volumio[23922]: *** WARNING *** For more information see Mar 25 18:30:49 katarynka volumio[23922]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Mar 25 18:30:49 katarynka volumio[23922]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 25 18:30:49 katarynka volumio[23922]: *** WARNING *** For more information see Mar 25 18:30:49 katarynka node[23922]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Mar 25 18:30:49 katarynka node[23922]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 25 18:30:49 katarynka node[23922]: *** WARNING *** For more information see Mar 25 18:30:49 katarynka node[23922]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Mar 25 18:30:49 katarynka node[23922]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 25 18:30:49 katarynka node[23922]: *** WARNING *** For more information see Mar 25 18:30:49 katarynka volumio[23922]: info: Applying required configuration parameters for plugin volumiodiscovery Mar 25 18:30:49 katarynka volumio[23922]: info: Discovery: Started advertising with name: katarynka Mar 25 18:30:49 katarynka volumio[23922]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 25 18:30:49 katarynka volumio[23922]: info: Loading plugin "spop"... Mar 25 18:30:50 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 16. Mar 25 18:30:50 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 18:30:51 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 18:30:51 katarynka go-librespot[24016]: go-librespot daemon starting... Mar 25 18:30:51 katarynka go-librespot[24017]: time="2026-03-25T18:30:51+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 18:30:51 katarynka go-librespot[24017]: time="2026-03-25T18:30:51+01:00" level=debug msg="app state loaded" Mar 25 18:30:51 katarynka go-librespot[24017]: time="2026-03-25T18:30:51+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 18:30:51 katarynka volumio[23922]: info: Loading plugin "outputs"... Mar 25 18:30:51 katarynka volumio[23922]: info: Loading plugin "albumart"... Mar 25 18:30:51 katarynka volumio[23922]: info: Plugin example_plugin is not enabled Mar 25 18:30:51 katarynka volumio[23922]: info: Loading plugin "inputs"... Mar 25 18:30:51 katarynka volumio[23922]: info: Loading plugin "updater_comm"... Mar 25 18:30:51 katarynka volumio[23922]: info: Plugin mpdemulation is not enabled Mar 25 18:30:51 katarynka volumio[23922]: info: Loading plugin "rest_api"... Mar 25 18:30:51 katarynka volumio[23922]: info: Loading plugin "websocket"... Mar 25 18:30:51 katarynka go-librespot[24017]: time="2026-03-25T18:30:51+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Mar 25 18:30:51 katarynka go-librespot[24017]: time="2026-03-25T18:30:51+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Mar 25 18:30:51 katarynka go-librespot[24017]: time="2026-03-25T18:30:51+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Mar 25 18:30:51 katarynka volumio[23922]: info: Starting Socket.io Server version 1.7.4 Mar 25 18:30:51 katarynka volumio[23922]: info: Loading i18n strings for locale pl Mar 25 18:30:51 katarynka go-librespot[24017]: time="2026-03-25T18:30:51+01:00" level=info msg="zeroconf server listening on port 35991" Mar 25 18:30:51 katarynka volumio[23922]: Updating browse sources language Mar 25 18:30:51 katarynka volumio[23922]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 25 18:30:51 katarynka go-librespot[24017]: time="2026-03-25T18:30:51+01:00" level=debug msg="obtained new client token: AABCvFRZ9CsH37UXURcnh0qcpbjJst/YBP4ViIoQlcSBYIeAybnW++3E+2mqIIEyKshtekXWEtr8ViFKaYxi7BZp3mVplQVFIpm1iL9IU/3BpCkSkwSKD/RXwAZzoJ8JyegQJI7aHcfghJfwbC8knHCvnDF0N5DU4f9+Prfvg71Lyh4Sk8hupXf1cq2M8CcyVPbzvk5mbVHsXW/iJVBa9JzMdCFLesxoKk2LEsMz96iAzg1oLPtPLX0xRes=" Mar 25 18:30:51 katarynka go-librespot[24017]: time="2026-03-25T18:30:51+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 18:30:51 katarynka go-librespot[24017]: time="2026-03-25T18:30:51+01:00" level=debug msg="completed keyexchange" Mar 25 18:30:51 katarynka go-librespot[24017]: time="2026-03-25T18:30:51+01:00" level=debug msg="completed challenge" Mar 25 18:30:51 katarynka volumio[23922]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 25 18:30:51 katarynka volumio[23922]: info: CoreCommandRouter::initPlayerControls Mar 25 18:30:51 katarynka volumio[23922]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 18:30:51 katarynka volumio[23922]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 18:30:51 katarynka volumio[23922]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 18:30:51 katarynka volumio[23922]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 18:30:51 katarynka go-librespot[24017]: time="2026-03-25T18:30:51+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 25 18:30:51 katarynka volumio[23922]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 18:30:51 katarynka volumio[23922]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 18:30:51 katarynka volumio[23922]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 18:30:51 katarynka volumio[23922]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 18:30:52 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 18:30:52 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 18:30:52 katarynka volumio[23922]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 25 18:30:52 katarynka volumio[23922]: Express server listening on port 3000 Mar 25 18:30:52 katarynka volumio[23922]: [Metrics] WebUI: 12s 644.86ms Mar 25 18:30:52 katarynka volumio[23922]: info: CoreStateMachine::resetVolumioState Mar 25 18:30:52 katarynka volumio[23922]: info: CoreStateMachine::getcurrentVolume Mar 25 18:30:52 katarynka volumio[23922]: info: CoreCommandRouter::volumioRetrievevolume Mar 25 18:30:52 katarynka volumio[23922]: info: Cannot read play queue from file Mar 25 18:30:52 katarynka volumio[23922]: info: Volumio Network Manager: Network status updated: 2 Mar 25 18:30:52 katarynka volumio[24023]: Forking 3 albumart workers Mar 25 18:30:52 katarynka volumio[23922]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 18:30:52 katarynka volumio[23922]: info: CoreStateMachine::setRepeat null single undefined Mar 25 18:30:52 katarynka volumio[23922]: info: CoreStateMachine::pushState Mar 25 18:30:52 katarynka volumio[23922]: info: CorePlayQueue::getTrack 0 Mar 25 18:30:52 katarynka volumio[23922]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 25 18:30:52 katarynka volumio[23922]: info: CoreCommandRouter::volumioPushState Mar 25 18:30:52 katarynka volumio[23922]: info: CoreStateMachine::setRandom null Mar 25 18:30:52 katarynka volumio[23922]: info: CoreStateMachine::pushState Mar 25 18:30:52 katarynka volumio[23922]: info: CorePlayQueue::getTrack 0 Mar 25 18:30:52 katarynka volumio[23922]: info: CoreCommandRouter::volumioPushState Mar 25 18:30:52 katarynka volumio[23922]: info: VolumeController:: Volume=96 Mute =false Mar 25 18:30:52 katarynka volumio[23922]: info: CoreStateMachine::pushState Mar 25 18:30:52 katarynka volumio[23922]: info: CorePlayQueue::getTrack 0 Mar 25 18:30:52 katarynka volumio[23922]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 25 18:30:52 katarynka volumio[23922]: info: CoreCommandRouter::volumioPushState Mar 25 18:30:52 katarynka volumio[23922]: info: CoreStateMachine::updateTrackBlock Mar 25 18:30:52 katarynka volumio[23922]: info: CorePlayQueue::getTrackBlock Mar 25 18:30:52 katarynka volumio[23922]: info: CoreCommandRouter::volumioRetrievevolume Mar 25 18:30:52 katarynka volumio[23922]: info: Setting Device type: Raspberry PI Mar 25 18:30:52 katarynka volumio[23922]: info: Completed loading Core Plugins Mar 25 18:30:52 katarynka volumio[23922]: info: Preparing to generate the ALSA configuration file Mar 25 18:30:52 katarynka volumio[23922]: info: Asound.conf file unchanged, so no further update is needed Mar 25 18:30:52 katarynka volumio[23922]: info: Output device has changed, restarting MPD Mar 25 18:30:52 katarynka volumio[23922]: info: Output device has changed, restarting Shairport Sync Mar 25 18:30:52 katarynka volumio[23922]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 18:30:52 katarynka volumio[23922]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 18:30:53 katarynka sudo[24079]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 25 18:30:53 katarynka sudo[24079]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 18:30:53 katarynka sudo[24079]: pam_unix(sudo:session): session closed for user root Mar 25 18:30:53 katarynka sudo[24081]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 25 18:30:53 katarynka sudo[24081]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 18:30:53 katarynka volumio[23922]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 25 18:30:53 katarynka volumio[23922]: info: ___________ START PLUGINS ___________ Mar 25 18:30:53 katarynka volumio[23922]: info: ControllerMpd::onStart: Initializing MPD Mar 25 18:30:53 katarynka volumio[23922]: info: Creating MPD Configuration file Mar 25 18:30:53 katarynka systemd[1]: Stopping mpd.service - Music Player Daemon... Mar 25 18:30:53 katarynka upmpdcli[1473]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Mar 25 18:30:53 katarynka volumio[23922]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 25 18:30:53 katarynka volumio[23922]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 25 18:30:53 katarynka volumio[23922]: info: [1774459853244] CoreMusicLibrary::Adding element Serwery Mediów Mar 25 18:30:53 katarynka volumio[23922]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 25 18:30:53 katarynka sudo[24089]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 25 18:30:53 katarynka sudo[24089]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 18:30:53 katarynka sudo[24089]: pam_unix(sudo:session): session closed for user root Mar 25 18:30:53 katarynka systemd[1]: mpd.service: Deactivated successfully. Mar 25 18:30:53 katarynka systemd[1]: Stopped mpd.service - Music Player Daemon. Mar 25 18:30:53 katarynka systemd[1]: mpd.service: Consumed 7.671s CPU time. Mar 25 18:30:53 katarynka systemd[1]: mpd.socket: Deactivated successfully. Mar 25 18:30:53 katarynka systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Mar 25 18:30:53 katarynka systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Mar 25 18:30:53 katarynka volumio[23922]: info: UPNP Browser: Client initialized successfully Mar 25 18:30:53 katarynka volumio[23922]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 18:30:53 katarynka volumio[23922]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 18:30:53 katarynka systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Mar 25 18:30:53 katarynka sudo[24091]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 25 18:30:53 katarynka sudo[24091]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 18:30:53 katarynka systemd[1]: Starting mpd.service - Music Player Daemon... Mar 25 18:30:53 katarynka volumio[23922]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 25 18:30:53 katarynka volumio[23922]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 18:30:53 katarynka volumio[23922]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 18:30:53 katarynka systemd[1]: mpd.service: Deactivated successfully. Mar 25 18:30:53 katarynka systemd[1]: Stopped mpd.service - Music Player Daemon. Mar 25 18:30:53 katarynka systemd[1]: mpd.socket: Deactivated successfully. Mar 25 18:30:53 katarynka systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Mar 25 18:30:53 katarynka systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Mar 25 18:30:53 katarynka volumio[23922]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 25 18:30:53 katarynka volumio[23922]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 25 18:30:53 katarynka volumio[23922]: info: [1774459853617] CoreMusicLibrary::Adding element Last_100 Mar 25 18:30:53 katarynka volumio[23922]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 25 18:30:53 katarynka volumio[23922]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 25 18:30:53 katarynka volumio[23922]: info: [1774459853631] CoreMusicLibrary::Adding element Webradio Mar 25 18:30:53 katarynka volumio[23922]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 25 18:30:53 katarynka volumio[23922]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 25 18:30:53 katarynka systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Mar 25 18:30:53 katarynka volumio[23922]: info: Initializing BBC Radios Mar 25 18:30:53 katarynka systemd[1]: Starting mpd.service - Music Player Daemon... Mar 25 18:30:53 katarynka volumio-remote-updater[686]: [2026-03-25 18:30:53] [connect] Successful connection Mar 25 18:30:53 katarynka volumio[23922]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 25 18:30:53 katarynka volumio[23922]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 18:30:53 katarynka volumio[23922]: info: Creating Spotify config file Mar 25 18:30:53 katarynka volumio[23922]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 18:30:54 katarynka sudo[24105]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Mar 25 18:30:54 katarynka sudo[24105]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Mar 25 18:30:54 katarynka sudo[24105]: pam_unix(sudo:session): session closed for user root Mar 25 18:30:55 katarynka volumio[23922]: info: Volumio Calling Home Mar 25 18:30:55 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 17. Mar 25 18:30:55 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 18:30:55 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 18:30:55 katarynka go-librespot[24138]: go-librespot daemon starting... Mar 25 18:30:55 katarynka go-librespot[24139]: time="2026-03-25T18:30:55+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 18:30:55 katarynka volumio[23922]: info: Discovery: adding 4d616d77-6a8c-4da2-85a4-840d70f98e51 Mar 25 18:30:55 katarynka volumio[23922]: info: Discovery: Found device katarynka Mar 25 18:30:55 katarynka volumio[23922]: info: CoreCommandRouter::volumioGetState Mar 25 18:30:55 katarynka volumio[23922]: info: CorePlayQueue::getTrack 0 Mar 25 18:30:55 katarynka volumio[23922]: info: Discovery: this is already registered, 4d616d77-6a8c-4da2-85a4-840d70f98e51 Mar 25 18:30:55 katarynka volumio[23922]: info: Discovery: Found device katarynka Mar 25 18:30:55 katarynka volumio[23922]: info: CoreCommandRouter::volumioGetState Mar 25 18:30:55 katarynka volumio[23922]: info: CorePlayQueue::getTrack 0 Mar 25 18:30:56 katarynka volumio[23922]: info: MPD Permissions set Mar 25 18:30:56 katarynka volumio[23922]: info: MPD Permissions set Mar 25 18:30:56 katarynka volumio[23922]: info: VolumeController:: Volume=96 Mute =false Mar 25 18:30:56 katarynka volumio[23922]: info: CoreStateMachine::pushState Mar 25 18:30:56 katarynka volumio[23922]: info: CorePlayQueue::getTrack 0 Mar 25 18:30:56 katarynka sudo[24148]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 25 18:30:56 katarynka sudo[24148]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 18:30:56 katarynka volumio[23922]: info: CoreCommandRouter::volumioPushState Mar 25 18:30:56 katarynka sudo[24150]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 25 18:30:56 katarynka sudo[24150]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 18:30:56 katarynka sudo[24150]: pam_unix(sudo:session): session closed for user root Mar 25 18:30:56 katarynka go-librespot[24139]: time="2026-03-25T18:30:56+01:00" level=info msg="zeroconf server listening on port 40453" Mar 25 18:30:56 katarynka sudo[24148]: pam_unix(sudo:session): session closed for user root Mar 25 18:30:56 katarynka volumio-remote-updater[686]: [2026-03-25 18:30:56] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1774459853 101 Mar 25 18:30:56 katarynka volumio[23922]: 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 18:30:56 katarynka volumio[23922]: info: Volumio called home Mar 25 18:30:56 katarynka volumio[23922]: info: Spotify config file written Mar 25 18:30:56 katarynka volumio[24042]: Starting albumart workers Mar 25 18:30:56 katarynka sudo[24154]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Mar 25 18:30:56 katarynka sudo[24154]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 18:30:56 katarynka systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Mar 25 18:30:56 katarynka systemd[1]: go-librespot-daemon.service: Deactivated successfully. Mar 25 18:30:56 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 18:30:56 katarynka volumio[24041]: Starting albumart workers Mar 25 18:30:56 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 18:30:56 katarynka go-librespot[24156]: go-librespot daemon starting... Mar 25 18:30:56 katarynka sudo[24154]: pam_unix(sudo:session): session closed for user root Mar 25 18:30:56 katarynka go-librespot[24157]: time="2026-03-25T18:30:56+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 18:30:56 katarynka volumio[24039]: Starting albumart workers Mar 25 18:30:56 katarynka go-librespot[24157]: time="2026-03-25T18:30:56+01:00" level=debug msg="app state loaded" Mar 25 18:30:56 katarynka go-librespot[24157]: time="2026-03-25T18:30:56+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 18:30:56 katarynka volumio[23922]: 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 18:30:56 katarynka volumio[23922]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 18:30:56 katarynka volumio[23922]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 18:30:56 katarynka volumio[23922]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 18:30:56 katarynka volumio[23922]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 18:30:56 katarynka volumio[23922]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 18:30:56 katarynka volumio[23922]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 18:30:56 katarynka volumio[23922]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 18:30:56 katarynka volumio[23922]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 18:30:57 katarynka volumio[23922]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 18:30:57 katarynka volumio[23922]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 18:30:57 katarynka volumio[23922]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 18:30:57 katarynka volumio[23922]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 18:30:57 katarynka volumio[23922]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 18:30:57 katarynka volumio[23922]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 18:30:57 katarynka volumio[23922]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 18:30:57 katarynka volumio[23922]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 18:30:57 katarynka volumio[23922]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 18:30:57 katarynka volumio[23922]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 18:30:57 katarynka volumio[23922]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 18:30:57 katarynka volumio[23922]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 18:30:57 katarynka volumio[23922]: info: No need to fix Spotify hosts Mar 25 18:30:57 katarynka go-librespot[24157]: time="2026-03-25T18:30:57+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 18:30:57 katarynka go-librespot[24157]: time="2026-03-25T18:30:57+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 18:30:57 katarynka go-librespot[24157]: time="2026-03-25T18:30:57+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 18:30:57 katarynka go-librespot[24157]: time="2026-03-25T18:30:57+01:00" level=info msg="zeroconf server listening on port 37031" Mar 25 18:30:57 katarynka volumio[23922]: info: Starting Shairport Sync Mar 25 18:30:57 katarynka go-librespot[24157]: time="2026-03-25T18:30:57+01:00" level=debug msg="obtained new client token: AACeO9R1ETWNt0R485ka3l6vp64HmMAZstFvIjZNgWrjw67eCj11gS/nDvRHCPVwXf2DWUJ+JVmjO5Yylk6f4PJHm54Lo74H59WKmI5D+vMVW7C7n1cTDShLM92qI5JPOznQpWU5yvA87F2N2ccALZoCb/EHcskN5ynhgtWwLwLN2suroKWWvvVNXtF3F9uQ02j1UD+b5/IBH7IuC6CUf+dwzrGLDocsFaA9MwRG5KY6O7kNUVRqkg+uUK0=" Mar 25 18:30:57 katarynka volumio[23922]: info: Starting Shairport Sync Mar 25 18:30:57 katarynka sudo[24176]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 25 18:30:57 katarynka sudo[24176]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 18:30:57 katarynka volumio[23922]: info: Starting Shairport Sync Mar 25 18:30:57 katarynka sudo[24179]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 25 18:30:57 katarynka sudo[24179]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 18:30:57 katarynka go-librespot[24157]: time="2026-03-25T18:30:57+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 18:30:57 katarynka systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Mar 25 18:30:57 katarynka systemd[1]: shairport-sync.service: Deactivated successfully. Mar 25 18:30:57 katarynka systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 25 18:30:57 katarynka systemd[1]: shairport-sync.service: Consumed 2.406s CPU time. Mar 25 18:30:57 katarynka go-librespot[24157]: time="2026-03-25T18:30:57+01:00" level=debug msg="connected to ap-gew4.spotify.com:443" Mar 25 18:30:57 katarynka sudo[24181]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 25 18:30:57 katarynka sudo[24181]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 18:30:57 katarynka systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 25 18:30:57 katarynka go-librespot[24157]: time="2026-03-25T18:30:57+01:00" level=debug msg="completed keyexchange" Mar 25 18:30:57 katarynka go-librespot[24157]: time="2026-03-25T18:30:57+01:00" level=debug msg="completed challenge" Mar 25 18:30:57 katarynka sudo[24176]: pam_unix(sudo:session): session closed for user root Mar 25 18:30:58 katarynka systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Mar 25 18:30:58 katarynka go-librespot[24157]: time="2026-03-25T18:30:58+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 25 18:30:58 katarynka systemd[1]: shairport-sync.service: Deactivated successfully. Mar 25 18:30:58 katarynka systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 25 18:30:58 katarynka sudo[24186]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Mar 25 18:30:58 katarynka sudo[24186]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 18:30:58 katarynka systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 25 18:30:58 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 18:30:58 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 18:30:58 katarynka sudo[24179]: pam_unix(sudo:session): session closed for user root Mar 25 18:30:58 katarynka sudo[24186]: pam_unix(sudo:session): session closed for user root Mar 25 18:30:58 katarynka systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Mar 25 18:30:58 katarynka systemd[1]: shairport-sync.service: Deactivated successfully. Mar 25 18:30:58 katarynka systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 25 18:30:58 katarynka systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 25 18:30:58 katarynka sudo[24181]: pam_unix(sudo:session): session closed for user root Mar 25 18:30:58 katarynka volumio[23922]: info: Upmpdcli Daemon Started Mar 25 18:30:58 katarynka volumio[23922]: info: Shairport-Sync Started Mar 25 18:30:58 katarynka volumio[23922]: Error adding Membership: Error: addMembership EINVAL Mar 25 18:30:58 katarynka volumio[23922]: info: Shairport-Sync Started Mar 25 18:30:58 katarynka volumio[23922]: info: An error occurred while refreshing Spotify Token Error: Bad Request Mar 25 18:30:58 katarynka volumio[23922]: info: Shairport-Sync Started Mar 25 18:30:58 katarynka volumio[23922]: info: CoreCommandRouter::volumioGetState Mar 25 18:30:58 katarynka volumio[23922]: info: CorePlayQueue::getTrack 0 Mar 25 18:30:59 katarynka upmpdcli[1473]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Timeout Mar 25 18:30:59 katarynka upmpdcli[1473]: :2:../src/mpdcli.cxx:396::MPDCli::updStatus: connection failed Mar 25 18:30:59 katarynka upmpdcli[1473]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Mar 25 18:31:00 katarynka volumio[23922]: info: go-librespot daemon successfully initialized Mar 25 18:31:01 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Mar 25 18:31:01 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 18:31:01 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 18:31:01 katarynka go-librespot[24236]: go-librespot daemon starting... Mar 25 18:31:01 katarynka go-librespot[24237]: time="2026-03-25T18:31:01+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 18:31:01 katarynka go-librespot[24237]: time="2026-03-25T18:31:01+01:00" level=debug msg="app state loaded" Mar 25 18:31:01 katarynka go-librespot[24237]: time="2026-03-25T18:31:01+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 18:31:01 katarynka go-librespot[24237]: time="2026-03-25T18:31:01+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 25 18:31:01 katarynka go-librespot[24237]: time="2026-03-25T18:31:01+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 18:31:01 katarynka go-librespot[24237]: time="2026-03-25T18:31:01+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 18:31:01 katarynka go-librespot[24237]: time="2026-03-25T18:31:01+01:00" level=info msg="zeroconf server listening on port 40453" Mar 25 18:31:01 katarynka go-librespot[24237]: time="2026-03-25T18:31:01+01:00" level=debug msg="obtained new client token: AAALF0pq6i9KBpzeoaXvYTm393NOa2Tehu/foqn0NoQZi0ysNXQqjTk5llY9rZ9c7NHpNjUHjONN3Wkocd4hBzkpjU/ugME5SG8yXdpBmnyxjj6+KkgzMWIZWQtPCLlQqsFW8U83Oe9ubQhKWioc64V3iCZ04N4WJugs2UjxK+Up6DzKPNSCTxyh+5gMQKY5zZcaoPJWuMG3NGWE+KuzDNAvcyXC0laezaHU2fgnV3bb/3s+zp7zMdEn2Qg=" Mar 25 18:31:01 katarynka go-librespot[24237]: time="2026-03-25T18:31:01+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 18:31:02 katarynka mpd[24120]: 2026-03-25T18:31:02 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Mar 25 18:31:02 katarynka systemd[1]: Started mpd.service - Music Player Daemon. Mar 25 18:31:02 katarynka sudo[24081]: pam_unix(sudo:session): session closed for user root Mar 25 18:31:02 katarynka sudo[24091]: pam_unix(sudo:session): session closed for user root Mar 25 18:31:02 katarynka go-librespot[24237]: time="2026-03-25T18:31:02+01:00" level=debug msg="completed keyexchange" Mar 25 18:31:02 katarynka go-librespot[24237]: time="2026-03-25T18:31:02+01:00" level=debug msg="completed challenge" Mar 25 18:31:02 katarynka upmpdcli[1473]: :3:../src/mpdcli.cxx:148::MPDCli::startEventLoop: already started Mar 25 18:31:02 katarynka volumio[23922]: info: Completed starting Core Plugins Mar 25 18:31:02 katarynka volumio[23922]: info: ------------------------------------------- Mar 25 18:31:02 katarynka volumio[23922]: info: ----- MyVolumio plugins startup ---- Mar 25 18:31:02 katarynka volumio[23922]: info: ------------------------------------------- Mar 25 18:31:02 katarynka volumio[23922]: info: [MyVolumio PluginManager] Fetching plans data.... Mar 25 18:31:02 katarynka go-librespot[24237]: time="2026-03-25T18:31:02+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 18:31:02 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 18:31:02 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 18:31:02 katarynka volumio[23922]: error: MPD error: The expression evaluated to a falsy value: Mar 25 18:31:02 katarynka volumio[23922]: assert.ok(self.idling) Mar 25 18:31:02 katarynka volumio[23922]: error: The expression evaluated to a falsy value: Mar 25 18:31:02 katarynka volumio[23922]: assert.ok(self.idling) Mar 25 18:31:02 katarynka volumio[23922]: info: MPD running with PID24120 Mar 25 18:31:02 katarynka volumio[23922]: ,establishing connection Mar 25 18:31:02 katarynka volumio[23922]: error: updateQueue error: null Mar 25 18:31:02 katarynka volumio[23922]: error: updateQueue error: null Mar 25 18:31:03 katarynka volumio[23922]: info: Initializing connection to go-librespot Websocket Mar 25 18:31:03 katarynka volumio[23922]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 25 18:31:05 katarynka sudo[24268]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Mar 25 18:31:05 katarynka sudo[24268]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 18:31:05 katarynka sudo[24270]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Mar 25 18:31:05 katarynka sudo[24270]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 18:31:05 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Mar 25 18:31:05 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 18:31:05 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 18:31:05 katarynka go-librespot[24273]: go-librespot daemon starting... Mar 25 18:31:05 katarynka systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Mar 25 18:31:05 katarynka systemd[1]: mpd_monitor.service: Deactivated successfully. Mar 25 18:31:05 katarynka systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Mar 25 18:31:05 katarynka systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Mar 25 18:31:05 katarynka go-librespot[24274]: time="2026-03-25T18:31:05+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 18:31:05 katarynka sudo[24268]: pam_unix(sudo:session): session closed for user root Mar 25 18:31:05 katarynka go-librespot[24274]: time="2026-03-25T18:31:05+01:00" level=debug msg="app state loaded" Mar 25 18:31:05 katarynka sudo[24270]: pam_unix(sudo:session): session closed for user root Mar 25 18:31:05 katarynka go-librespot[24274]: time="2026-03-25T18:31:05+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 18:31:05 katarynka volumio[23922]: info: Successfully started MPD Monitor Mar 25 18:31:05 katarynka mpd_monitor.sh[24280]: MPD Monitor Service: Starting MPD Monitor Service Mar 25 18:31:05 katarynka volumio[23922]: info: Successfully started MPD Monitor Mar 25 18:31:05 katarynka go-librespot[24274]: time="2026-03-25T18:31:05+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 25 18:31:05 katarynka go-librespot[24274]: time="2026-03-25T18:31:05+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 25 18:31:05 katarynka go-librespot[24274]: time="2026-03-25T18:31:05+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 25 18:31:05 katarynka go-librespot[24274]: time="2026-03-25T18:31:05+01:00" level=info msg="zeroconf server listening on port 38791" Mar 25 18:31:05 katarynka go-librespot[24274]: time="2026-03-25T18:31:05+01:00" level=debug msg="obtained new client token: AABv0rbfKBs5TTAfHOLYUwkufpkeR/sylItwC/fZeg8rVyBzuQR3VB/bppo7OK6pKJA8IR+xVHeVrVHWlV18aLTP0Hg34VAaoGHcie1SO4e6yRv/oYKRSbNaJkZf+j5Mx+VLyJHmG9++YEKn5G21yYqZLcKfEfekyBUDf3s+xLcsSuoNDEbghP6wVCtRNgZ1i+/gP9k9zuTJEN7MhxCn54GlqgvEjI2/fWsX/3gwVvcT3xkwH0PVuih3zbo=" Mar 25 18:31:05 katarynka go-librespot[24274]: time="2026-03-25T18:31:05+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 18:31:06 katarynka go-librespot[24274]: time="2026-03-25T18:31:06+01:00" level=debug msg="connected to ap-gew4.spotify.com:443" Mar 25 18:31:06 katarynka go-librespot[24274]: time="2026-03-25T18:31:06+01:00" level=debug msg="completed keyexchange" Mar 25 18:31:06 katarynka go-librespot[24274]: time="2026-03-25T18:31:06+01:00" level=debug msg="completed challenge" Mar 25 18:31:06 katarynka go-librespot[24274]: time="2026-03-25T18:31:06+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 25 18:31:06 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 18:31:06 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 18:31:06 katarynka volumio[23922]: info: Initializing connection to go-librespot Websocket Mar 25 18:31:06 katarynka volumio[23922]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 25 18:31:07 katarynka volumio[23922]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Mar 25 18:31:09 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Mar 25 18:31:09 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 18:31:09 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 18:31:09 katarynka go-librespot[24286]: go-librespot daemon starting... Mar 25 18:31:09 katarynka go-librespot[24287]: time="2026-03-25T18:31:09+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 18:31:09 katarynka go-librespot[24287]: time="2026-03-25T18:31:09+01:00" level=debug msg="app state loaded" Mar 25 18:31:09 katarynka go-librespot[24287]: time="2026-03-25T18:31:09+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 18:31:09 katarynka volumio[23922]: info: Initializing connection to go-librespot Websocket Mar 25 18:31:09 katarynka go-librespot[24287]: time="2026-03-25T18:31:09+01:00" level=debug msg="new websocket client" Mar 25 18:31:09 katarynka volumio[23922]: info: Connection to go-librespot Websocket established Mar 25 18:31:09 katarynka go-librespot[24287]: time="2026-03-25T18:31:09+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 18:31:09 katarynka go-librespot[24287]: time="2026-03-25T18:31:09+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 18:31:09 katarynka go-librespot[24287]: time="2026-03-25T18:31:09+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 18:31:09 katarynka go-librespot[24287]: time="2026-03-25T18:31:09+01:00" level=info msg="zeroconf server listening on port 35579" Mar 25 18:31:09 katarynka go-librespot[24287]: time="2026-03-25T18:31:09+01:00" level=debug msg="obtained new client token: AACDzMWMDbGcOF30dQ1WjstcCd2KChYPSLuI+n/koK+HHrZLL20xsNhb8ExbM3Netx0mHH7qoetT1iCefPES2oADtexwskGsg86uu0oAI7eppYg3H+ZNdcFzhJp1GtX4nQ7LyMYiwgnWI+V/XRArcFHlSBc8tJIgGf/eHl/eDyk+fEvTXmZa9l+fiUpPG/9//maRBRq6gFrJgjtfzexKdPqNn4+v0KRu2tIVEpI2+MwsWWo25gS+AlczPkk=" Mar 25 18:31:09 katarynka go-librespot[24287]: time="2026-03-25T18:31:09+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 18:31:09 katarynka go-librespot[24287]: time="2026-03-25T18:31:09+01:00" level=debug msg="completed keyexchange" Mar 25 18:31:09 katarynka go-librespot[24287]: time="2026-03-25T18:31:09+01:00" level=debug msg="completed challenge" Mar 25 18:31:10 katarynka go-librespot[24287]: time="2026-03-25T18:31:10+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 25 18:31:10 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 18:31:10 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 18:31:10 katarynka volumio[23922]: info: Connection to go-librespot Websocket closed Mar 25 18:31:10 katarynka volumio[23922]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Mar 25 18:31:10 katarynka volumio[23922]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Mar 25 18:31:10 katarynka volumio[23922]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Mar 25 18:31:10 katarynka volumio[23922]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Mar 25 18:31:10 katarynka volumio[23922]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Mar 25 18:31:10 katarynka volumio[23922]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Mar 25 18:31:10 katarynka volumio[23922]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Mar 25 18:31:10 katarynka volumio[23922]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Mar 25 18:31:10 katarynka volumio[23922]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Mar 25 18:31:10 katarynka volumio[23922]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Mar 25 18:31:10 katarynka volumio[23922]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Mar 25 18:31:10 katarynka volumio[23922]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Mar 25 18:31:10 katarynka volumio[23922]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Mar 25 18:31:10 katarynka volumio[23922]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Mar 25 18:31:10 katarynka volumio[23922]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Mar 25 18:31:10 katarynka volumio[23922]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Mar 25 18:31:10 katarynka volumio[23922]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Mar 25 18:31:10 katarynka volumio[23922]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Mar 25 18:31:10 katarynka volumio[23922]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Mar 25 18:31:10 katarynka volumio[23922]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Mar 25 18:31:10 katarynka volumio[23922]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Mar 25 18:31:10 katarynka volumio[23922]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Mar 25 18:31:10 katarynka volumio[23922]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Mar 25 18:31:10 katarynka volumio[23922]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Mar 25 18:31:10 katarynka volumio[23922]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Mar 25 18:31:10 katarynka volumio[23922]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Mar 25 18:31:10 katarynka volumio[23922]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Mar 25 18:31:10 katarynka volumio[23922]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Mar 25 18:31:10 katarynka volumio[23922]: info: Adding plugin bluetooth to MyMusic Plugins Mar 25 18:31:10 katarynka volumio[23922]: info: Adding plugin multiroom to MyMusic Plugins Mar 25 18:31:10 katarynka volumio[23922]: info: Adding plugin metavolumio to MyMusic Plugins Mar 25 18:31:10 katarynka volumio[23922]: info: Adding plugin cd_controller to MyMusic Plugins Mar 25 18:31:10 katarynka volumio[23922]: info: Adding plugin qobuzconnect to MyMusic Plugins Mar 25 18:31:10 katarynka volumio[23922]: info: Adding plugin smart_inputs to MyMusic Plugins Mar 25 18:31:10 katarynka volumio[23922]: info: Adding plugin tidalconnect to MyMusic Plugins Mar 25 18:31:10 katarynka volumio[23922]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Mar 25 18:31:12 katarynka volumio[23922]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Mar 25 18:31:12 katarynka volumio[23922]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Mar 25 18:31:12 katarynka volumio[23922]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 18:31:12 katarynka volumio[23922]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 18:31:12 katarynka volumio[23922]: info: Starting MyVolumio Remote Streaming Endpoints Mar 25 18:31:12 katarynka volumio[23922]: info: MyVolumio login type: Token Mar 25 18:31:12 katarynka volumio[23922]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Mar 25 18:31:12 katarynka volumio[23922]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Mar 25 18:31:13 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Mar 25 18:31:13 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 18:31:13 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 18:31:13 katarynka go-librespot[24294]: go-librespot daemon starting... Mar 25 18:31:13 katarynka go-librespot[24295]: time="2026-03-25T18:31:13+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 18:31:13 katarynka go-librespot[24295]: time="2026-03-25T18:31:13+01:00" level=debug msg="app state loaded" Mar 25 18:31:13 katarynka go-librespot[24295]: time="2026-03-25T18:31:13+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 18:31:13 katarynka go-librespot[24295]: time="2026-03-25T18:31:13+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 25 18:31:13 katarynka go-librespot[24295]: time="2026-03-25T18:31:13+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 18:31:13 katarynka go-librespot[24295]: time="2026-03-25T18:31:13+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 18:31:13 katarynka go-librespot[24295]: time="2026-03-25T18:31:13+01:00" level=info msg="zeroconf server listening on port 34257" Mar 25 18:31:13 katarynka go-librespot[24295]: time="2026-03-25T18:31:13+01:00" level=debug msg="obtained new client token: AADMIWOuRVZskKXKMpaUCmlAKDa4UidnbewdfDURNq0xpTVFm3lHCiviZbogrE8U5dlbqRDr7dxBGLmd/oeeXQWfrwV18IZKfQ1b2Ht0Yt0ccmXuNjAr63Mk+i5t/d785fcLxqQSoLBDJ2AUgxGacc8ipRQjwCULayq9p/NZiz4QrLMuwCghpDi4H5fWzxBR8Q3gSAVMmuSmyLjtg7RRIk9ZYuHqAiIz37je0LjgkMhibk1BlWy2ao03INw=" Mar 25 18:31:14 katarynka go-librespot[24295]: time="2026-03-25T18:31:14+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 18:31:14 katarynka volumio[23922]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Mar 25 18:31:14 katarynka volumio[23922]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Mar 25 18:31:14 katarynka volumio[23922]: info: Streaming services startup Mar 25 18:31:14 katarynka volumio[23922]: info: Starting Streaming Daemon Mar 25 18:31:14 katarynka sudo[24303]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Mar 25 18:31:14 katarynka sudo[24303]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 18:31:14 katarynka volumio[23922]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Mar 25 18:31:14 katarynka sudo[24303]: pam_unix(sudo:session): session closed for user root Mar 25 18:31:14 katarynka go-librespot[24295]: time="2026-03-25T18:31:14+01:00" level=debug msg="completed keyexchange" Mar 25 18:31:14 katarynka go-librespot[24295]: time="2026-03-25T18:31:14+01:00" level=debug msg="completed challenge" Mar 25 18:31:14 katarynka volumio[23922]: info: Getting Spotify volume Mar 25 18:31:14 katarynka volumio[23922]: info: Initializing connection to go-librespot Websocket Mar 25 18:31:14 katarynka volumio[23922]: error: Cannot start Volumio Streaming Daemon Mar 25 18:31:14 katarynka volumio[23922]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Mar 25 18:31:14 katarynka volumio[23922]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Mar 25 18:31:14 katarynka go-librespot[24295]: time="2026-03-25T18:31:14+01:00" level=debug msg="new websocket client" Mar 25 18:31:14 katarynka volumio[23922]: 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 18:31:14 katarynka volumio[23922]: info: Connection to go-librespot Websocket established Mar 25 18:31:14 katarynka go-librespot[24295]: time="2026-03-25T18:31:14+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 25 18:31:14 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 18:31:14 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 18:31:14 katarynka volumio[23922]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 25 18:31:14 katarynka volumio[23922]: Error: socket hang up Mar 25 18:31:14 katarynka volumio[23922]: at connResetException (node:internal/errors:720:14) Mar 25 18:31:14 katarynka volumio[23922]: at Socket.socketOnEnd (node:_http_client:519:23) Mar 25 18:31:14 katarynka volumio[23922]: at Socket.emit (node:events:526:35) Mar 25 18:31:14 katarynka volumio[23922]: at endReadableNT (node:internal/streams/readable:1376:12) Mar 25 18:31:14 katarynka volumio[23922]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Mar 25 18:31:14 katarynka volumio[23922]: code: 'ECONNRESET', Mar 25 18:31:14 katarynka volumio[23922]: response: undefined Mar 25 18:31:14 katarynka volumio[23922]: } Mar 25 18:31:14 katarynka volumio[23922]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 25 18:31:16 katarynka sudo[24337]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-03-25 18:30' Mar 25 18:31:16 katarynka sudo[24337]: 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"