Mar 25 07:44:02 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 15. Mar 25 07:44:02 katarynka volumio[12164]: info: Starting UPNP Browser Mar 25 07:44:02 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 07:44:02 katarynka volumio[12164]: info: Loading plugin "alarm-clock"... Mar 25 07:44:02 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 07:44:02 katarynka go-librespot[12243]: go-librespot daemon starting... Mar 25 07:44:02 katarynka go-librespot[12244]: time="2026-03-25T07:44:02+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 07:44:02 katarynka go-librespot[12244]: time="2026-03-25T07:44:02+01:00" level=debug msg="app state loaded" Mar 25 07:44:02 katarynka go-librespot[12244]: time="2026-03-25T07:44:02+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 07:44:03 katarynka volumio[12164]: info: Loading plugin "airplay_emulation"... Mar 25 07:44:03 katarynka volumio[12164]: info: Starting Shairport Sync Mar 25 07:44:03 katarynka volumio[12164]: info: Loading plugin "last_100"... Mar 25 07:44:03 katarynka volumio[12164]: info: Loading plugin "webradio"... Mar 25 07:44:03 katarynka go-librespot[12244]: time="2026-03-25T07:44:03+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 25 07:44:03 katarynka go-librespot[12244]: time="2026-03-25T07:44:03+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 25 07:44:03 katarynka go-librespot[12244]: time="2026-03-25T07:44:03+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 25 07:44:03 katarynka go-librespot[12244]: time="2026-03-25T07:44:03+01:00" level=info msg="zeroconf server listening on port 34739" Mar 25 07:44:03 katarynka volumio[12164]: info: Loading plugin "i2s_dacs"... Mar 25 07:44:03 katarynka volumio[12164]: info: Loading plugin "volumiodiscovery"... Mar 25 07:44:03 katarynka volumio[12164]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Mar 25 07:44:03 katarynka volumio[12164]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 25 07:44:03 katarynka volumio[12164]: *** WARNING *** For more information see Mar 25 07:44:03 katarynka volumio[12164]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Mar 25 07:44:03 katarynka volumio[12164]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 25 07:44:03 katarynka volumio[12164]: *** WARNING *** For more information see Mar 25 07:44:03 katarynka node[12164]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Mar 25 07:44:03 katarynka node[12164]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 25 07:44:03 katarynka node[12164]: *** WARNING *** For more information see Mar 25 07:44:03 katarynka node[12164]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Mar 25 07:44:03 katarynka node[12164]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 25 07:44:03 katarynka node[12164]: *** WARNING *** For more information see Mar 25 07:44:03 katarynka volumio[12164]: info: Applying required configuration parameters for plugin volumiodiscovery Mar 25 07:44:03 katarynka go-librespot[12244]: time="2026-03-25T07:44:03+01:00" level=debug msg="obtained new client token: AAAr4+7CtRqAemI8r+n6/ahp7SipjYGH5sgrNPf8tm5x6Za/j1MYQy8ejZHVO6uCRfQsi6OVIA3oF0sgOPb7q8o4GIZHmBps3QBuQ4TxmwS7HijN/VZY9mPz6BiW2vKYa2SCstO3GNRZVqE6hEc+lJ0rcCXsMgxfEQ09Mq2/qNMDVyXZOSfM/M9AO29k8CbkF0ai87PNfaw1CEUhFs2aySnwfhl0NkMP/+PZ/woH5vzAPGdMMQC3a3ilrV0=" Mar 25 07:44:03 katarynka volumio[12164]: info: Discovery: Started advertising with name: katarynka Mar 25 07:44:03 katarynka go-librespot[12244]: time="2026-03-25T07:44:03+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 07:44:03 katarynka volumio[12164]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 25 07:44:03 katarynka volumio[12164]: info: Loading plugin "spop"... Mar 25 07:44:03 katarynka go-librespot[12244]: time="2026-03-25T07:44:03+01:00" level=debug msg="completed keyexchange" Mar 25 07:44:03 katarynka go-librespot[12244]: time="2026-03-25T07:44:03+01:00" level=debug msg="completed challenge" Mar 25 07:44:03 katarynka go-librespot[12244]: time="2026-03-25T07:44:03+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 25 07:44:03 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 07:44:03 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 07:44:05 katarynka volumio[12164]: info: Loading plugin "outputs"... Mar 25 07:44:05 katarynka volumio[12164]: info: Loading plugin "albumart"... Mar 25 07:44:05 katarynka volumio[12164]: info: Plugin example_plugin is not enabled Mar 25 07:44:05 katarynka volumio[12164]: info: Loading plugin "inputs"... Mar 25 07:44:05 katarynka volumio[12164]: info: Loading plugin "updater_comm"... Mar 25 07:44:05 katarynka volumio[12164]: info: Plugin mpdemulation is not enabled Mar 25 07:44:05 katarynka volumio[12164]: info: Loading plugin "rest_api"... Mar 25 07:44:05 katarynka volumio[12164]: info: Loading plugin "websocket"... Mar 25 07:44:05 katarynka volumio[12164]: info: Starting Socket.io Server version 1.7.4 Mar 25 07:44:05 katarynka volumio[12164]: info: Loading i18n strings for locale pl Mar 25 07:44:05 katarynka volumio[12164]: Updating browse sources language Mar 25 07:44:05 katarynka volumio[12164]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 25 07:44:06 katarynka volumio[12164]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 25 07:44:06 katarynka volumio[12164]: info: CoreCommandRouter::initPlayerControls Mar 25 07:44:06 katarynka volumio[12164]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 07:44:06 katarynka volumio[12164]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 07:44:06 katarynka volumio[12164]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 07:44:06 katarynka volumio[12164]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 07:44:06 katarynka volumio[12164]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 07:44:06 katarynka volumio[12164]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 07:44:06 katarynka volumio[12164]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 07:44:06 katarynka volumio[12164]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 07:44:06 katarynka volumio[12164]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 25 07:44:06 katarynka volumio[12164]: Express server listening on port 3000 Mar 25 07:44:06 katarynka volumio[12164]: [Metrics] WebUI: 12s 623.19ms Mar 25 07:44:06 katarynka volumio[12164]: info: CoreStateMachine::resetVolumioState Mar 25 07:44:06 katarynka volumio[12164]: info: CoreStateMachine::getcurrentVolume Mar 25 07:44:06 katarynka volumio[12164]: info: CoreCommandRouter::volumioRetrievevolume Mar 25 07:44:06 katarynka volumio[12164]: info: Cannot read play queue from file Mar 25 07:44:06 katarynka volumio[12164]: info: Volumio Network Manager: Network status updated: 2 Mar 25 07:44:06 katarynka volumio[12257]: Forking 3 albumart workers Mar 25 07:44:06 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 16. Mar 25 07:44:06 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 07:44:06 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 07:44:06 katarynka volumio[12164]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 07:44:06 katarynka go-librespot[12278]: go-librespot daemon starting... Mar 25 07:44:06 katarynka volumio[12164]: info: Setting Device type: Raspberry PI Mar 25 07:44:06 katarynka volumio[12164]: info: CoreStateMachine::setRepeat null single undefined Mar 25 07:44:06 katarynka volumio[12164]: info: CoreStateMachine::pushState Mar 25 07:44:06 katarynka volumio[12164]: info: CorePlayQueue::getTrack 0 Mar 25 07:44:06 katarynka volumio[12164]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 25 07:44:06 katarynka volumio[12164]: info: CoreCommandRouter::volumioPushState Mar 25 07:44:06 katarynka volumio[12164]: info: CoreStateMachine::setRandom null Mar 25 07:44:06 katarynka volumio[12164]: info: CoreStateMachine::pushState Mar 25 07:44:06 katarynka volumio[12164]: info: CorePlayQueue::getTrack 0 Mar 25 07:44:06 katarynka go-librespot[12281]: time="2026-03-25T07:44:06+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 07:44:06 katarynka go-librespot[12281]: time="2026-03-25T07:44:06+01:00" level=debug msg="app state loaded" Mar 25 07:44:06 katarynka go-librespot[12281]: time="2026-03-25T07:44:06+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 07:44:06 katarynka volumio[12164]: info: CoreCommandRouter::volumioPushState Mar 25 07:44:06 katarynka volumio[12164]: info: Completed loading Core Plugins Mar 25 07:44:06 katarynka volumio[12164]: info: Preparing to generate the ALSA configuration file Mar 25 07:44:06 katarynka volumio[12164]: info: VolumeController:: Volume=96 Mute =false Mar 25 07:44:06 katarynka volumio[12164]: info: CoreStateMachine::pushState Mar 25 07:44:06 katarynka volumio[12164]: info: CorePlayQueue::getTrack 0 Mar 25 07:44:06 katarynka volumio[12164]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 25 07:44:06 katarynka volumio[12164]: info: CoreCommandRouter::volumioPushState Mar 25 07:44:07 katarynka volumio[12164]: info: CoreStateMachine::updateTrackBlock Mar 25 07:44:07 katarynka volumio[12164]: info: CorePlayQueue::getTrackBlock Mar 25 07:44:07 katarynka volumio[12164]: info: CoreCommandRouter::volumioRetrievevolume Mar 25 07:44:07 katarynka volumio[12164]: info: Asound.conf file unchanged, so no further update is needed Mar 25 07:44:07 katarynka volumio[12164]: info: Output device has changed, restarting MPD Mar 25 07:44:07 katarynka go-librespot[12281]: time="2026-03-25T07:44:07+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 25 07:44:07 katarynka go-librespot[12281]: time="2026-03-25T07:44:07+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 07:44:07 katarynka go-librespot[12281]: time="2026-03-25T07:44:07+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 07:44:07 katarynka volumio[12164]: info: Output device has changed, restarting Shairport Sync Mar 25 07:44:07 katarynka volumio[12164]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 07:44:07 katarynka volumio[12164]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 07:44:07 katarynka sudo[12321]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 25 07:44:07 katarynka sudo[12321]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 07:44:07 katarynka go-librespot[12281]: time="2026-03-25T07:44:07+01:00" level=info msg="zeroconf server listening on port 46591" Mar 25 07:44:07 katarynka sudo[12321]: pam_unix(sudo:session): session closed for user root Mar 25 07:44:07 katarynka sudo[12323]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 25 07:44:07 katarynka sudo[12323]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 07:44:07 katarynka volumio[12164]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 25 07:44:07 katarynka volumio[12164]: info: ___________ START PLUGINS ___________ Mar 25 07:44:07 katarynka volumio[12164]: info: ControllerMpd::onStart: Initializing MPD Mar 25 07:44:07 katarynka volumio[12164]: info: Creating MPD Configuration file Mar 25 07:44:07 katarynka go-librespot[12281]: time="2026-03-25T07:44:07+01:00" level=debug msg="obtained new client token: AACVPx120a0f77nIMh74QhrLSTloFFF54ri/aDgqmJlzRxahZJgaRBfoQHHUKUbR3PvLWEgWIm7AODAPyRJ8+qY9f3eJ3J/fJuh8AN6MqlY4I1FiYBIREIfgY4pLzBsulBC3JNWBxI+YqIIF+8Slp6G4QnJBNN214AXH5vED/KlUyPJ1R1eHbxFed0wKcyJ4BlCdedNrdi7nfiOOjIUYx+Z1G3yliKtZcOpDO2Xw9Wf5FGAQhlywPlnAJi4=" Mar 25 07:44:07 katarynka sudo[12331]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 25 07:44:07 katarynka volumio[12164]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 25 07:44:07 katarynka sudo[12331]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 07:44:07 katarynka volumio[12164]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 25 07:44:07 katarynka sudo[12331]: pam_unix(sudo:session): session closed for user root Mar 25 07:44:07 katarynka systemd[1]: Stopping mpd.service - Music Player Daemon... Mar 25 07:44:07 katarynka volumio[12164]: info: [1774421047669] CoreMusicLibrary::Adding element Serwery Mediów Mar 25 07:44:07 katarynka volumio[12164]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 25 07:44:07 katarynka volumio[12164]: info: UPNP Browser: Client initialized successfully Mar 25 07:44:07 katarynka sudo[12333]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 25 07:44:07 katarynka sudo[12333]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 07:44:07 katarynka volumio[12164]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 07:44:07 katarynka volumio[12164]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 07:44:07 katarynka systemd[1]: mpd.service: Deactivated successfully. Mar 25 07:44:07 katarynka systemd[1]: Stopped mpd.service - Music Player Daemon. Mar 25 07:44:07 katarynka systemd[1]: mpd.service: Consumed 7.683s CPU time. Mar 25 07:44:07 katarynka systemd[1]: mpd.socket: Deactivated successfully. Mar 25 07:44:07 katarynka systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Mar 25 07:44:07 katarynka systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Mar 25 07:44:07 katarynka volumio[12164]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 25 07:44:07 katarynka volumio[12164]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 07:44:07 katarynka volumio[12164]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 07:44:07 katarynka systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Mar 25 07:44:07 katarynka go-librespot[12281]: time="2026-03-25T07:44:07+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 07:44:07 katarynka systemd[1]: Starting mpd.service - Music Player Daemon... Mar 25 07:44:08 katarynka volumio[12164]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 25 07:44:08 katarynka volumio[12164]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 25 07:44:08 katarynka volumio[12164]: info: [1774421048012] CoreMusicLibrary::Adding element Last_100 Mar 25 07:44:08 katarynka volumio[12164]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 25 07:44:08 katarynka volumio[12164]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 25 07:44:08 katarynka volumio[12164]: info: [1774421048036] CoreMusicLibrary::Adding element Webradio Mar 25 07:44:08 katarynka volumio[12164]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 25 07:44:08 katarynka volumio[12164]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 25 07:44:08 katarynka volumio[12164]: info: Initializing BBC Radios Mar 25 07:44:08 katarynka volumio-remote-updater[622]: [2026-03-25 07:44:08] [connect] Successful connection Mar 25 07:44:08 katarynka go-librespot[12281]: time="2026-03-25T07:44:08+01:00" level=debug msg="completed keyexchange" Mar 25 07:44:08 katarynka go-librespot[12281]: time="2026-03-25T07:44:08+01:00" level=debug msg="completed challenge" Mar 25 07:44:08 katarynka volumio[12164]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 25 07:44:08 katarynka volumio[12164]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 07:44:08 katarynka volumio[12164]: info: Creating Spotify config file Mar 25 07:44:08 katarynka volumio[12164]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 07:44:08 katarynka sudo[12343]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Mar 25 07:44:08 katarynka sudo[12343]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Mar 25 07:44:08 katarynka sudo[12343]: pam_unix(sudo:session): session closed for user root Mar 25 07:44:08 katarynka go-librespot[12281]: time="2026-03-25T07:44:08+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 25 07:44:08 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 07:44:08 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 07:44:09 katarynka volumio[12164]: info: Volumio Calling Home Mar 25 07:44:10 katarynka volumio[12273]: Starting albumart workers Mar 25 07:44:10 katarynka volumio[12279]: Starting albumart workers Mar 25 07:44:10 katarynka volumio[12164]: info: Discovery: adding 4d616d77-6a8c-4da2-85a4-840d70f98e51 Mar 25 07:44:10 katarynka volumio[12164]: info: Discovery: Found device katarynka Mar 25 07:44:10 katarynka volumio[12164]: info: CoreCommandRouter::volumioGetState Mar 25 07:44:10 katarynka volumio[12164]: info: CorePlayQueue::getTrack 0 Mar 25 07:44:10 katarynka sudo[12381]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 25 07:44:10 katarynka sudo[12381]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 07:44:10 katarynka sudo[12381]: pam_unix(sudo:session): session closed for user root Mar 25 07:44:10 katarynka sudo[12379]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 25 07:44:10 katarynka sudo[12379]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 07:44:10 katarynka volumio[12276]: Starting albumart workers Mar 25 07:44:10 katarynka sudo[12379]: pam_unix(sudo:session): session closed for user root Mar 25 07:44:10 katarynka volumio[12164]: info: MPD Permissions set Mar 25 07:44:10 katarynka volumio[12164]: info: MPD Permissions set Mar 25 07:44:10 katarynka volumio[12164]: info: VolumeController:: Volume=96 Mute =false Mar 25 07:44:10 katarynka volumio[12164]: info: CoreStateMachine::pushState Mar 25 07:44:10 katarynka volumio[12164]: info: CorePlayQueue::getTrack 0 Mar 25 07:44:10 katarynka volumio[12164]: info: CoreCommandRouter::volumioPushState Mar 25 07:44:10 katarynka volumio-remote-updater[622]: [2026-03-25 07:44:10] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1774421048 101 Mar 25 07:44:11 katarynka volumio[12164]: 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 07:44:11 katarynka volumio[12164]: info: Spotify config file written Mar 25 07:44:11 katarynka volumio[12164]: info: Discovery: this is already registered, 4d616d77-6a8c-4da2-85a4-840d70f98e51 Mar 25 07:44:11 katarynka volumio[12164]: info: Discovery: Found device katarynka Mar 25 07:44:11 katarynka volumio[12164]: info: CoreCommandRouter::volumioGetState Mar 25 07:44:11 katarynka volumio[12164]: info: CorePlayQueue::getTrack 0 Mar 25 07:44:11 katarynka sudo[12385]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Mar 25 07:44:11 katarynka sudo[12385]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 07:44:11 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 07:44:11 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 07:44:11 katarynka go-librespot[12387]: go-librespot daemon starting... Mar 25 07:44:11 katarynka sudo[12385]: pam_unix(sudo:session): session closed for user root Mar 25 07:44:11 katarynka go-librespot[12388]: time="2026-03-25T07:44:11+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 07:44:11 katarynka go-librespot[12388]: time="2026-03-25T07:44:11+01:00" level=debug msg="app state loaded" Mar 25 07:44:11 katarynka go-librespot[12388]: time="2026-03-25T07:44:11+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 07:44:11 katarynka volumio[12164]: 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 07:44:11 katarynka volumio[12164]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 07:44:11 katarynka volumio[12164]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 07:44:11 katarynka volumio[12164]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 07:44:11 katarynka volumio[12164]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 07:44:11 katarynka volumio[12164]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 07:44:11 katarynka volumio[12164]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 07:44:11 katarynka volumio[12164]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 07:44:11 katarynka volumio[12164]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 07:44:11 katarynka volumio[12164]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 07:44:11 katarynka volumio[12164]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 07:44:11 katarynka volumio[12164]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 07:44:11 katarynka volumio[12164]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 07:44:11 katarynka volumio[12164]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 07:44:11 katarynka volumio[12164]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 07:44:11 katarynka volumio[12164]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 07:44:11 katarynka volumio[12164]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 07:44:11 katarynka volumio[12164]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 07:44:11 katarynka volumio[12164]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 07:44:12 katarynka volumio[12164]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 07:44:12 katarynka volumio[12164]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 07:44:12 katarynka volumio[12164]: info: No need to fix Spotify hosts Mar 25 07:44:12 katarynka go-librespot[12388]: time="2026-03-25T07:44:12+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 25 07:44:12 katarynka go-librespot[12388]: time="2026-03-25T07:44:12+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 25 07:44:12 katarynka go-librespot[12388]: time="2026-03-25T07:44:12+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 25 07:44:12 katarynka go-librespot[12388]: time="2026-03-25T07:44:12+01:00" level=info msg="zeroconf server listening on port 43419" Mar 25 07:44:12 katarynka volumio[12164]: info: Volumio called home Mar 25 07:44:12 katarynka go-librespot[12388]: time="2026-03-25T07:44:12+01:00" level=debug msg="obtained new client token: AADLiMVUdJG2+iJanmUEAqtEVYyQWzIs9tjiEAWGYB9CpiUuAQogDNU6zSvNOxpB1ST3TuTSp/3nf57sz/iz4D5U1TcXANmRNisuIyW9MaGcq6ODze6VvNX8NPcg6rzB0hWlRRh5Qu70tg1E4sLZ6iV+egsthFgLX4NHledDEti7bPGmES3hkCjkFJMv2VS4TfyY99KMrcg/IFNCnIkxclAEgFpvy3V09YZya+bo5FE+chfQ/d3McvdKi1M=" Mar 25 07:44:12 katarynka go-librespot[12388]: time="2026-03-25T07:44:12+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 07:44:12 katarynka go-librespot[12388]: time="2026-03-25T07:44:12+01:00" level=debug msg="completed keyexchange" Mar 25 07:44:12 katarynka go-librespot[12388]: time="2026-03-25T07:44:12+01:00" level=debug msg="completed challenge" Mar 25 07:44:12 katarynka volumio[12164]: info: Starting Shairport Sync Mar 25 07:44:12 katarynka go-librespot[12388]: time="2026-03-25T07:44:12+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 25 07:44:12 katarynka volumio[12164]: info: Starting Shairport Sync Mar 25 07:44:12 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 07:44:12 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 07:44:12 katarynka volumio[12164]: info: Starting Shairport Sync Mar 25 07:44:12 katarynka sudo[12420]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 25 07:44:12 katarynka sudo[12420]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 07:44:12 katarynka sudo[12413]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 25 07:44:12 katarynka sudo[12413]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 07:44:12 katarynka sudo[12423]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 25 07:44:12 katarynka sudo[12423]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 07:44:13 katarynka sudo[12426]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Mar 25 07:44:13 katarynka sudo[12426]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 07:44:13 katarynka systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Mar 25 07:44:13 katarynka sudo[12426]: pam_unix(sudo:session): session closed for user root Mar 25 07:44:13 katarynka systemd[1]: shairport-sync.service: Deactivated successfully. Mar 25 07:44:13 katarynka systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 25 07:44:13 katarynka systemd[1]: shairport-sync.service: Consumed 2.253s CPU time. Mar 25 07:44:13 katarynka volumio[12164]: info: An error occurred while refreshing Spotify Token Error: Bad Request Mar 25 07:44:13 katarynka volumio[12164]: info: Upmpdcli Daemon Started Mar 25 07:44:13 katarynka volumio[12164]: info: CoreCommandRouter::volumioGetState Mar 25 07:44:13 katarynka volumio[12164]: info: CorePlayQueue::getTrack 0 Mar 25 07:44:13 katarynka systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 25 07:44:13 katarynka sudo[12413]: pam_unix(sudo:session): session closed for user root Mar 25 07:44:13 katarynka sudo[12420]: pam_unix(sudo:session): session closed for user root Mar 25 07:44:13 katarynka sudo[12423]: pam_unix(sudo:session): session closed for user root Mar 25 07:44:13 katarynka volumio[12164]: info: Shairport-Sync Started Mar 25 07:44:13 katarynka volumio[12164]: Error adding Membership: Error: addMembership EINVAL Mar 25 07:44:13 katarynka volumio[12164]: info: Shairport-Sync Started Mar 25 07:44:13 katarynka volumio[12164]: info: Shairport-Sync Started Mar 25 07:44:15 katarynka volumio[12164]: info: go-librespot daemon successfully initialized Mar 25 07:44:15 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 17. Mar 25 07:44:15 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 07:44:15 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 07:44:15 katarynka go-librespot[12451]: go-librespot daemon starting... Mar 25 07:44:16 katarynka mpd[12360]: 2026-03-25T07:44:15 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Mar 25 07:44:16 katarynka systemd[1]: Started mpd.service - Music Player Daemon. Mar 25 07:44:16 katarynka sudo[12323]: pam_unix(sudo:session): session closed for user root Mar 25 07:44:16 katarynka sudo[12333]: pam_unix(sudo:session): session closed for user root Mar 25 07:44:16 katarynka go-librespot[12452]: time="2026-03-25T07:44:16+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 07:44:16 katarynka go-librespot[12452]: time="2026-03-25T07:44:16+01:00" level=debug msg="app state loaded" Mar 25 07:44:16 katarynka go-librespot[12452]: time="2026-03-25T07:44:16+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 07:44:16 katarynka volumio[12164]: info: Completed starting Core Plugins Mar 25 07:44:16 katarynka volumio[12164]: info: ------------------------------------------- Mar 25 07:44:16 katarynka volumio[12164]: info: ----- MyVolumio plugins startup ---- Mar 25 07:44:16 katarynka volumio[12164]: info: ------------------------------------------- Mar 25 07:44:16 katarynka volumio[12164]: info: [MyVolumio PluginManager] Fetching plans data.... Mar 25 07:44:16 katarynka volumio[12164]: error: MPD error: The expression evaluated to a falsy value: Mar 25 07:44:16 katarynka volumio[12164]: assert.ok(self.idling) Mar 25 07:44:16 katarynka volumio[12164]: error: The expression evaluated to a falsy value: Mar 25 07:44:16 katarynka volumio[12164]: assert.ok(self.idling) Mar 25 07:44:16 katarynka volumio[12164]: info: MPD running with PID12360 Mar 25 07:44:16 katarynka volumio[12164]: ,establishing connection Mar 25 07:44:16 katarynka volumio[12164]: error: updateQueue error: null Mar 25 07:44:16 katarynka volumio[12164]: error: updateQueue error: null Mar 25 07:44:16 katarynka go-librespot[12452]: time="2026-03-25T07:44:16+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 25 07:44:16 katarynka go-librespot[12452]: time="2026-03-25T07:44:16+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 07:44:16 katarynka go-librespot[12452]: time="2026-03-25T07:44:16+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 07:44:16 katarynka go-librespot[12452]: time="2026-03-25T07:44:16+01:00" level=info msg="zeroconf server listening on port 37435" Mar 25 07:44:16 katarynka go-librespot[12452]: time="2026-03-25T07:44:16+01:00" level=debug msg="obtained new client token: AAA+OrQ5VdpWgU0/yf4O2inPnl07LZls5a/9CS/MWC2QvDKJ2HVVvIibpbJ3ImJYsjZsY8cKDqzMu7ZudrSzRa4owc2CoGqXwCP+/ARghRJz70CcK9HxSvS07CRsQCkaZpw+oLVBhGKub6Njy6WPXrG87pImNU4J8oO2ZCAgq0wQt11e9jLVODomzhK0aPU0lOOo3hyJTjxiZSM1jrjF0Mf/U1lgMojDVHIL59a7dnUvKigGP+reVfmz8b8=" Mar 25 07:44:16 katarynka go-librespot[12452]: time="2026-03-25T07:44:16+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 07:44:16 katarynka go-librespot[12452]: time="2026-03-25T07:44:16+01:00" level=debug msg="completed keyexchange" Mar 25 07:44:16 katarynka go-librespot[12452]: time="2026-03-25T07:44:16+01:00" level=debug msg="completed challenge" Mar 25 07:44:16 katarynka go-librespot[12452]: time="2026-03-25T07:44:16+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 25 07:44:16 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 07:44:16 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 07:44:18 katarynka volumio[12164]: info: Initializing connection to go-librespot Websocket Mar 25 07:44:18 katarynka volumio[12164]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 25 07:44:19 katarynka sudo[12478]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Mar 25 07:44:19 katarynka sudo[12478]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 07:44:19 katarynka sudo[12481]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Mar 25 07:44:19 katarynka sudo[12481]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 07:44:19 katarynka systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Mar 25 07:44:19 katarynka systemd[1]: mpd_monitor.service: Deactivated successfully. Mar 25 07:44:19 katarynka systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Mar 25 07:44:19 katarynka systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Mar 25 07:44:19 katarynka sudo[12478]: pam_unix(sudo:session): session closed for user root Mar 25 07:44:19 katarynka mpd_monitor.sh[12483]: MPD Monitor Service: Starting MPD Monitor Service Mar 25 07:44:19 katarynka volumio[12164]: info: Successfully started MPD Monitor Mar 25 07:44:19 katarynka systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Mar 25 07:44:19 katarynka systemd[1]: mpd_monitor.service: Deactivated successfully. Mar 25 07:44:19 katarynka systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Mar 25 07:44:19 katarynka systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Mar 25 07:44:19 katarynka sudo[12481]: pam_unix(sudo:session): session closed for user root Mar 25 07:44:19 katarynka mpd_monitor.sh[12486]: MPD Monitor Service: Starting MPD Monitor Service Mar 25 07:44:19 katarynka volumio[12164]: info: Successfully started MPD Monitor Mar 25 07:44:19 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 18. Mar 25 07:44:19 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 07:44:19 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 07:44:19 katarynka go-librespot[12491]: go-librespot daemon starting... Mar 25 07:44:20 katarynka go-librespot[12492]: time="2026-03-25T07:44:20+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 07:44:20 katarynka go-librespot[12492]: time="2026-03-25T07:44:20+01:00" level=debug msg="app state loaded" Mar 25 07:44:20 katarynka go-librespot[12492]: time="2026-03-25T07:44:20+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 07:44:20 katarynka go-librespot[12492]: time="2026-03-25T07:44:20+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 07:44:20 katarynka go-librespot[12492]: time="2026-03-25T07:44:20+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 07:44:20 katarynka go-librespot[12492]: time="2026-03-25T07:44:20+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 07:44:20 katarynka go-librespot[12492]: time="2026-03-25T07:44:20+01:00" level=info msg="zeroconf server listening on port 43889" Mar 25 07:44:20 katarynka go-librespot[12492]: time="2026-03-25T07:44:20+01:00" level=debug msg="obtained new client token: AABy0TtbGSPwoBjNPVii5QS7nanSm1+4rB8w/gkWglmblM/uol/AfNg3QABe+nn5LeJRGlDNgbYW5GBZ/fy34RfvX1OL/Y4ILt5d0/3nMlS0hRrj2YTT0C/TAW5Bp3t22tGd07Nw9BEfkWotcS2grGpZ1HbJZGpB4B3Y1h9xNh60osyozfVYA8sNPRSqhoAFXY3eC2fLHP3NQu7/eofINY6jvE5ZqJp9BtmEF7K63esOiOQ5w/0vuwUlLOE=" Mar 25 07:44:20 katarynka go-librespot[12492]: time="2026-03-25T07:44:20+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 07:44:20 katarynka go-librespot[12492]: time="2026-03-25T07:44:20+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 07:44:20 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 07:44:20 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 07:44:21 katarynka volumio[12164]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Mar 25 07:44:21 katarynka volumio[12164]: info: Initializing connection to go-librespot Websocket Mar 25 07:44:21 katarynka volumio[12164]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 25 07:44:23 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 19. Mar 25 07:44:23 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 07:44:23 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 07:44:23 katarynka go-librespot[12499]: go-librespot daemon starting... Mar 25 07:44:24 katarynka go-librespot[12500]: time="2026-03-25T07:44:24+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 07:44:24 katarynka go-librespot[12500]: time="2026-03-25T07:44:24+01:00" level=debug msg="app state loaded" Mar 25 07:44:24 katarynka go-librespot[12500]: time="2026-03-25T07:44:24+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 07:44:24 katarynka volumio[12164]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Mar 25 07:44:24 katarynka go-librespot[12500]: time="2026-03-25T07:44:24+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 25 07:44:24 katarynka volumio[12164]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Mar 25 07:44:24 katarynka volumio[12164]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Mar 25 07:44:24 katarynka volumio[12164]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Mar 25 07:44:24 katarynka volumio[12164]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Mar 25 07:44:24 katarynka volumio[12164]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Mar 25 07:44:24 katarynka volumio[12164]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Mar 25 07:44:24 katarynka volumio[12164]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Mar 25 07:44:24 katarynka volumio[12164]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Mar 25 07:44:24 katarynka volumio[12164]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Mar 25 07:44:24 katarynka volumio[12164]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Mar 25 07:44:24 katarynka volumio[12164]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Mar 25 07:44:24 katarynka volumio[12164]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Mar 25 07:44:24 katarynka volumio[12164]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Mar 25 07:44:24 katarynka volumio[12164]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Mar 25 07:44:24 katarynka volumio[12164]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Mar 25 07:44:24 katarynka go-librespot[12500]: time="2026-03-25T07:44:24+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 07:44:24 katarynka go-librespot[12500]: time="2026-03-25T07:44:24+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 07:44:24 katarynka volumio[12164]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Mar 25 07:44:24 katarynka volumio[12164]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Mar 25 07:44:24 katarynka volumio[12164]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Mar 25 07:44:24 katarynka volumio[12164]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Mar 25 07:44:24 katarynka volumio[12164]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Mar 25 07:44:24 katarynka volumio[12164]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Mar 25 07:44:24 katarynka volumio[12164]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Mar 25 07:44:24 katarynka volumio[12164]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Mar 25 07:44:24 katarynka volumio[12164]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Mar 25 07:44:24 katarynka volumio[12164]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Mar 25 07:44:24 katarynka volumio[12164]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Mar 25 07:44:24 katarynka volumio[12164]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Mar 25 07:44:24 katarynka volumio[12164]: info: Adding plugin bluetooth to MyMusic Plugins Mar 25 07:44:24 katarynka volumio[12164]: info: Adding plugin multiroom to MyMusic Plugins Mar 25 07:44:24 katarynka volumio[12164]: info: Adding plugin metavolumio to MyMusic Plugins Mar 25 07:44:24 katarynka volumio[12164]: info: Adding plugin cd_controller to MyMusic Plugins Mar 25 07:44:24 katarynka volumio[12164]: info: Adding plugin qobuzconnect to MyMusic Plugins Mar 25 07:44:24 katarynka volumio[12164]: info: Adding plugin smart_inputs to MyMusic Plugins Mar 25 07:44:24 katarynka volumio[12164]: info: Adding plugin tidalconnect to MyMusic Plugins Mar 25 07:44:24 katarynka go-librespot[12500]: time="2026-03-25T07:44:24+01:00" level=info msg="zeroconf server listening on port 33903" Mar 25 07:44:24 katarynka volumio[12164]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Mar 25 07:44:24 katarynka go-librespot[12500]: time="2026-03-25T07:44:24+01:00" level=debug msg="obtained new client token: AAAMzIBC2XKP6Kryxu5Sc4khkDkuBEKrOjAuFXs9g9bFCLVrE+SumZ/4L0rxkA7LoQIFe2DTwKVcnmeqrYk1bMMmHh76r4G1A4AEFzgwOyApXLKUj+7ePz0JRZQA+jNrNa1Ge8CKQtHWpglzJMK1tpTTCbXXhwEN6so5Bb77kpVA5xXh25Zb+t+HQHisI8AQ2O5Sp484Tt/lXrDJjthrvCY41Y3wHg5VTuvvXCrZBYsKd/JpqfF0gDkutbQ=" Mar 25 07:44:24 katarynka go-librespot[12500]: time="2026-03-25T07:44:24+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 07:44:24 katarynka go-librespot[12500]: time="2026-03-25T07:44:24+01:00" level=debug msg="completed keyexchange" Mar 25 07:44:24 katarynka go-librespot[12500]: time="2026-03-25T07:44:24+01:00" level=debug msg="completed challenge" Mar 25 07:44:24 katarynka go-librespot[12500]: time="2026-03-25T07:44:24+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 25 07:44:24 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 07:44:24 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 07:44:26 katarynka volumio[12164]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Mar 25 07:44:26 katarynka volumio[12164]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Mar 25 07:44:26 katarynka volumio[12164]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 07:44:26 katarynka volumio[12164]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 07:44:26 katarynka volumio[12164]: info: Starting MyVolumio Remote Streaming Endpoints Mar 25 07:44:26 katarynka volumio[12164]: info: MyVolumio login type: Token Mar 25 07:44:26 katarynka volumio[12164]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Mar 25 07:44:26 katarynka volumio[12164]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Mar 25 07:44:27 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 20. Mar 25 07:44:27 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 07:44:27 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 07:44:27 katarynka go-librespot[12507]: go-librespot daemon starting... Mar 25 07:44:28 katarynka go-librespot[12508]: time="2026-03-25T07:44:28+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 07:44:28 katarynka go-librespot[12508]: time="2026-03-25T07:44:28+01:00" level=debug msg="app state loaded" Mar 25 07:44:28 katarynka go-librespot[12508]: time="2026-03-25T07:44:28+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 07:44:28 katarynka volumio[12164]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Mar 25 07:44:28 katarynka volumio[12164]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Mar 25 07:44:28 katarynka volumio[12164]: info: Streaming services startup Mar 25 07:44:28 katarynka go-librespot[12508]: time="2026-03-25T07:44:28+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 25 07:44:28 katarynka go-librespot[12508]: time="2026-03-25T07:44:28+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 25 07:44:28 katarynka go-librespot[12508]: time="2026-03-25T07:44:28+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 25 07:44:28 katarynka volumio[12164]: info: Starting Streaming Daemon Mar 25 07:44:28 katarynka go-librespot[12508]: time="2026-03-25T07:44:28+01:00" level=info msg="zeroconf server listening on port 43535" Mar 25 07:44:28 katarynka sudo[12517]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Mar 25 07:44:28 katarynka volumio[12164]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Mar 25 07:44:28 katarynka sudo[12517]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 07:44:28 katarynka sudo[12517]: pam_unix(sudo:session): session closed for user root Mar 25 07:44:28 katarynka go-librespot[12508]: time="2026-03-25T07:44:28+01:00" level=debug msg="obtained new client token: AABXNgnwd8se6cw71oBS43bPTPCLvGYVc7hZ9LwHPtG/K2nJWt70ch2t4YyQ5VDL3xwtI374GGK5avetvhwOTvB+Pht4tF9LYFBGNxJ3jvUywzUv3K624sjs+DFUT43OzEPiGGL0Q+lhHi3Pr3WIwNc16Do0pKfnU9cY9ipPSbz4szcPdzUs86SgO9QDO2RPOCrtCTMON+o8ydClFXm5oiFJSm91BcpYSNhZfPQ+t8fvHQrdQX/g7qt3hLk=" Mar 25 07:44:28 katarynka volumio[12164]: info: Initializing connection to go-librespot Websocket Mar 25 07:44:28 katarynka go-librespot[12508]: time="2026-03-25T07:44:28+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 07:44:28 katarynka volumio[12164]: error: Cannot start Volumio Streaming Daemon Mar 25 07:44:28 katarynka volumio[12164]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Mar 25 07:44:28 katarynka volumio[12164]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Mar 25 07:44:28 katarynka go-librespot[12508]: time="2026-03-25T07:44:28+01:00" level=debug msg="new websocket client" Mar 25 07:44:28 katarynka volumio[12164]: info: Connection to go-librespot Websocket established Mar 25 07:44:28 katarynka go-librespot[12508]: time="2026-03-25T07:44:28+01:00" level=debug msg="completed keyexchange" Mar 25 07:44:28 katarynka go-librespot[12508]: time="2026-03-25T07:44:28+01:00" level=debug msg="completed challenge" Mar 25 07:44:28 katarynka go-librespot[12508]: time="2026-03-25T07:44:28+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 25 07:44:28 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 07:44:28 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 07:44:28 katarynka volumio[12164]: info: Connection to go-librespot Websocket closed Mar 25 07:44:29 katarynka volumio[12164]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Mar 25 07:44:29 katarynka volumio[12164]: info: MyVolumio token set successfully Mar 25 07:44:29 katarynka volumio[12164]: info: MYVOLUMIO: Adding device Mar 25 07:44:29 katarynka volumio[12164]: info: MYVOLUMIO: Evaluating Server Mar 25 07:44:30 katarynka volumio[12164]: info: MyVolumio status changed Mar 25 07:44:30 katarynka volumio[12164]: info: Streaming services startup Mar 25 07:44:30 katarynka volumio[12164]: info: Starting Streaming Daemon Mar 25 07:44:30 katarynka volumio[12164]: info: Removing browser output: myVolumio user plan is not superstar Mar 25 07:44:30 katarynka volumio[12164]: info: Removing audio output: Mar 25 07:44:30 katarynka volumio[12164]: info: Stoppping Tunnel 1 Mar 25 07:44:30 katarynka sudo[12558]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Mar 25 07:44:30 katarynka sudo[12558]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 07:44:30 katarynka sudo[12560]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Mar 25 07:44:30 katarynka sudo[12560]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 07:44:30 katarynka sudo[12558]: pam_unix(sudo:session): session closed for user root Mar 25 07:44:30 katarynka volumio[12164]: error: Cannot start Volumio Streaming Daemon Mar 25 07:44:30 katarynka volumio[12164]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Mar 25 07:44:30 katarynka volumio[12164]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Mar 25 07:44:30 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 07:44:30 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 07:44:30 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 07:44:30 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 07:44:30 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 07:44:30 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 07:44:30 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 07:44:30 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 07:44:30 katarynka sudo[12560]: pam_unix(sudo:session): session closed for user root Mar 25 07:44:30 katarynka volumio[12164]: info: Remote SSH Stopped Mar 25 07:44:30 katarynka volumio[12164]: info: Setting Geolocation for MyVolumio to eu7 Mar 25 07:44:30 katarynka volumio[12164]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 07:44:30 katarynka volumio[12164]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 07:44:30 katarynka volumio[12164]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 07:44:31 katarynka volumio[12164]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Mar 25 07:44:31 katarynka volumio[12164]: info: Getting Spotify volume Mar 25 07:44:31 katarynka volumio[12164]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 25 07:44:31 katarynka volumio[12164]: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 25 07:44:31 katarynka volumio[12164]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Mar 25 07:44:31 katarynka volumio[12164]: errno: -111, Mar 25 07:44:31 katarynka volumio[12164]: code: 'ECONNREFUSED', Mar 25 07:44:31 katarynka volumio[12164]: syscall: 'connect', Mar 25 07:44:31 katarynka volumio[12164]: address: '127.0.0.1', Mar 25 07:44:31 katarynka volumio[12164]: port: 9879, Mar 25 07:44:31 katarynka volumio[12164]: response: undefined Mar 25 07:44:31 katarynka volumio[12164]: } Mar 25 07:44:31 katarynka volumio[12164]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 25 07:44:31 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 21. Mar 25 07:44:31 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 07:44:32 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 07:44:32 katarynka go-librespot[12566]: go-librespot daemon starting... Mar 25 07:44:32 katarynka go-librespot[12575]: time="2026-03-25T07:44:32+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 07:44:32 katarynka go-librespot[12575]: time="2026-03-25T07:44:32+01:00" level=debug msg="app state loaded" Mar 25 07:44:32 katarynka go-librespot[12575]: time="2026-03-25T07:44:32+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 07:44:32 katarynka go-librespot[12575]: time="2026-03-25T07:44:32+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 25 07:44:32 katarynka go-librespot[12575]: time="2026-03-25T07:44:32+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 07:44:32 katarynka go-librespot[12575]: time="2026-03-25T07:44:32+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 07:44:32 katarynka go-librespot[12575]: time="2026-03-25T07:44:32+01:00" level=info msg="zeroconf server listening on port 42779" Mar 25 07:44:32 katarynka go-librespot[12575]: time="2026-03-25T07:44:32+01:00" level=debug msg="obtained new client token: AAB+51tf6faTq5ENdUg8gQHkDNUBtkHkKJaC85npy7N/fiCGGD1WE4OMD+EMppJsuGATRxLRJyGm2rrg5X5YPFyvS+nOD7qImSrIZpy3YlFAx/28LYYDnm2A8EJNoGn3ULNZD1S0dwYgx1h4SEqE+JwGmVcS6zEQa21eyNBhfs/Izk/C9O2S17mICOk2+lA2+PECfwh6BVRbGY+Zzvw9XA5CEgKz+XtAj/JGFJ/7/VnwBEBgRTeJYQkhXGU=" Mar 25 07:44:32 katarynka go-librespot[12575]: time="2026-03-25T07:44:32+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 07:44:33 katarynka go-librespot[12575]: time="2026-03-25T07:44:33+01:00" level=debug msg="completed keyexchange" Mar 25 07:44:33 katarynka go-librespot[12575]: time="2026-03-25T07:44:33+01:00" level=debug msg="completed challenge" Mar 25 07:44:33 katarynka sudo[12585]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-03-25 07:43' Mar 25 07:44:33 katarynka sudo[12585]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 07:44:33 katarynka go-librespot[12575]: time="2026-03-25T07:44:33+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 25 07:44:33 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 07:44:33 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 07:44:33 katarynka sudo[12585]: pam_unix(sudo:session): session closed for user root Mar 25 07:44:33 katarynka volumio-remote-updater[622]: [2026-03-25 07:44:33] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Mar 25 07:44:33 katarynka volumio-remote-updater[622]: [2026-03-25 07:44:33] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Mar 25 07:44:33 katarynka systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Mar 25 07:44:33 katarynka systemd[1]: volumio.service: Failed with result 'exit-code'. Mar 25 07:44:33 katarynka systemd[1]: volumio.service: Consumed 50.491s CPU time. Mar 25 07:44:34 katarynka systemd[1]: Started dynamicswap.service - dynamicswap service. Mar 25 07:44:34 katarynka systemd[1]: dynamicswap.service: Deactivated successfully. Mar 25 07:44:34 katarynka systemd[1]: volumio.service: Scheduled restart job, restart counter is at 26103. Mar 25 07:44:34 katarynka systemd[1]: Started dynamicswap.service - dynamicswap service. Mar 25 07:44:34 katarynka systemd[1]: Stopped volumio.service - Volumio Backend Module. Mar 25 07:44:34 katarynka systemd[1]: volumio.service: Consumed 50.491s CPU time. Mar 25 07:44:34 katarynka systemd[1]: Started volumio.service - Volumio Backend Module. Mar 25 07:44:34 katarynka systemd[1]: dynamicswap.service: Deactivated successfully. Mar 25 07:44:36 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 22. Mar 25 07:44:36 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 07:44:36 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 07:44:36 katarynka go-librespot[12615]: go-librespot daemon starting... Mar 25 07:44:36 katarynka go-librespot[12616]: time="2026-03-25T07:44:36+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 07:44:36 katarynka go-librespot[12616]: time="2026-03-25T07:44:36+01:00" level=debug msg="app state loaded" Mar 25 07:44:36 katarynka go-librespot[12616]: time="2026-03-25T07:44:36+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 07:44:37 katarynka go-librespot[12616]: time="2026-03-25T07:44:37+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 25 07:44:37 katarynka go-librespot[12616]: time="2026-03-25T07:44:37+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 25 07:44:37 katarynka go-librespot[12616]: time="2026-03-25T07:44:37+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 25 07:44:37 katarynka go-librespot[12616]: time="2026-03-25T07:44:37+01:00" level=info msg="zeroconf server listening on port 38169" Mar 25 07:44:37 katarynka go-librespot[12616]: time="2026-03-25T07:44:37+01:00" level=debug msg="obtained new client token: AAAD8ys9lLGbyX/8IrkQ30HiDnhEb8zMtohIhogVNaPZi5h7YG3XylqRoKOkkNk1CQodETcklC/wbJ/N52ATfLSh5mBZBZ8wlkDEGA1zUINVoIxJNUQ61GYNHBr/uVhHj5xP3KNa03fJn5jaN6g7w2zN+7NdowgHJQLyuaclVdsmsjQnJVwGlm/6VkF3zhDKdDD1vdvpO2nNiuP8wTLZk7+6rhfvojcvoYuligKDuj5hRARlXEOghcUZ6ko=" Mar 25 07:44:37 katarynka go-librespot[12616]: time="2026-03-25T07:44:37+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 07:44:37 katarynka go-librespot[12616]: time="2026-03-25T07:44:37+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: read tcp 192.168.100.107:38584->34.158.1.133:4070: read: connection reset by peer" Mar 25 07:44:37 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 07:44:37 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 07:44:37 katarynka volumio[12600]: info: ------------------------------------------- Mar 25 07:44:37 katarynka volumio[12600]: info: ----- Volumio3 ---- Mar 25 07:44:37 katarynka volumio[12600]: info: ------------------------------------------- Mar 25 07:44:37 katarynka volumio[12600]: info: ----- System startup ---- Mar 25 07:44:37 katarynka volumio[12600]: info: ------------------------------------------- Mar 25 07:44:38 katarynka volumio-remote-updater[622]: [2026-03-25 07:44:38] [connect] Successful connection Mar 25 07:44:39 katarynka volumio[12600]: info: MYVOLUMIO Environment detected Mar 25 07:44:39 katarynka volumio[12600]: info: Plugin folders cleanup Mar 25 07:44:39 katarynka volumio[12600]: info: Scanning into folder /volumio/app/plugins/ Mar 25 07:44:39 katarynka volumio[12600]: info: Scanning category audio_interface Mar 25 07:44:39 katarynka volumio[12600]: info: Scanning category miscellanea Mar 25 07:44:39 katarynka volumio[12600]: info: Scanning category music_service Mar 25 07:44:39 katarynka volumio[12600]: info: Scanning category plugins.json Mar 25 07:44:39 katarynka volumio[12600]: info: Scanning category system_controller Mar 25 07:44:39 katarynka volumio[12600]: info: Scanning category user_interface Mar 25 07:44:39 katarynka volumio[12600]: info: Scanning into folder /data/plugins/ Mar 25 07:44:39 katarynka volumio[12600]: info: Scanning category music_service Mar 25 07:44:39 katarynka volumio[12600]: info: Plugin folders cleanup completed Mar 25 07:44:39 katarynka volumio[12600]: info: ------------------------------------------- Mar 25 07:44:39 katarynka volumio[12600]: info: ----- Core plugins startup ---- Mar 25 07:44:39 katarynka volumio[12600]: info: ------------------------------------------- Mar 25 07:44:39 katarynka volumio[12600]: info: Loading plugins from folder /volumio/app/plugins/ Mar 25 07:44:39 katarynka volumio[12600]: info: Adding plugin upnp to MyMusic Plugins Mar 25 07:44:39 katarynka volumio[12600]: info: Adding plugin airplay_emulation to MyMusic Plugins Mar 25 07:44:39 katarynka volumio[12600]: info: Adding plugin upnp_browser to MyMusic Plugins Mar 25 07:44:39 katarynka volumio[12600]: info: Loading plugins from folder /data/plugins/ Mar 25 07:44:39 katarynka volumio[12600]: info: Loading plugin "system"... Mar 25 07:44:39 katarynka volumio[12600]: info: Loading plugin "appearance"... Mar 25 07:44:40 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 23. Mar 25 07:44:40 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 07:44:40 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 07:44:40 katarynka go-librespot[12639]: go-librespot daemon starting... Mar 25 07:44:41 katarynka go-librespot[12640]: time="2026-03-25T07:44:41+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 07:44:41 katarynka go-librespot[12640]: time="2026-03-25T07:44:41+01:00" level=debug msg="app state loaded" Mar 25 07:44:41 katarynka go-librespot[12640]: time="2026-03-25T07:44:41+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 07:44:41 katarynka go-librespot[12640]: time="2026-03-25T07:44:41+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 25 07:44:41 katarynka go-librespot[12640]: time="2026-03-25T07:44:41+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 07:44:41 katarynka go-librespot[12640]: time="2026-03-25T07:44:41+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 07:44:41 katarynka go-librespot[12640]: time="2026-03-25T07:44:41+01:00" level=info msg="zeroconf server listening on port 44753" Mar 25 07:44:41 katarynka go-librespot[12640]: time="2026-03-25T07:44:41+01:00" level=debug msg="obtained new client token: AADqk+oMjE16/O0bUdsV+C2aC3lzpYUpP8+rGEUSUIIQsF+nBAIZrtLHAl/260GfzNF9hdyN0w+JkLEXVmdGRBmix1/gEQQwqwF5FO+gu7CQR81q1weDMFiqDxxSVSl9ZI/K37xHAr2QQ4poPpCIGgmNVrG15ae7ouf7Bl6z7hn7q8PhuEaX3uE6y+b8nDNnGmlSuILHzJadzX743MLbcKFxRBwdtW1WjtXROrc9Gp5ErwkFo6e/D+4Sib0=" Mar 25 07:44:41 katarynka volumio[12600]: info: Loading plugin "network"... Mar 25 07:44:41 katarynka go-librespot[12640]: time="2026-03-25T07:44:41+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 07:44:41 katarynka volumio[12600]: info: Refreshing Cached IP Addresses Mar 25 07:44:41 katarynka sudo[12649]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 25 07:44:41 katarynka go-librespot[12640]: time="2026-03-25T07:44:41+01:00" level=debug msg="completed keyexchange" Mar 25 07:44:41 katarynka go-librespot[12640]: time="2026-03-25T07:44:41+01:00" level=debug msg="completed challenge" Mar 25 07:44:41 katarynka sudo[12649]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 07:44:41 katarynka sudo[12651]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 25 07:44:41 katarynka sudo[12651]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 07:44:41 katarynka volumio[12600]: info: Loading plugin "services"... Mar 25 07:44:41 katarynka volumio[12600]: info: Loading plugin "alsa_controller"... Mar 25 07:44:41 katarynka sudo[12651]: pam_unix(sudo:session): session closed for user root Mar 25 07:44:41 katarynka sudo[12649]: pam_unix(sudo:session): session closed for user root Mar 25 07:44:41 katarynka go-librespot[12640]: time="2026-03-25T07:44:41+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 07:44:41 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 07:44:41 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 07:44:41 katarynka sudo[12659]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Mar 25 07:44:41 katarynka sudo[12659]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 07:44:42 katarynka volumio[12600]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 25 07:44:42 katarynka volumio[12600]: info: Loading plugin "wizard"... Mar 25 07:44:42 katarynka volumio[12600]: info: Loading plugin "networkfs"... Mar 25 07:44:42 katarynka volumio[12600]: info: Starting Udev Watcher for removable devices Mar 25 07:44:42 katarynka volumio[12600]: info: Ignoring mount for partition: boot Mar 25 07:44:42 katarynka volumio[12600]: info: Ignoring mount for partition: volumio Mar 25 07:44:42 katarynka volumio[12600]: info: Ignoring mount for partition: volumio_data Mar 25 07:44:42 katarynka volumio[12600]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 25 07:44:42 katarynka volumio[12600]: info: Loading plugin "volumio_command_line_client"... Mar 25 07:44:42 katarynka volumio[12600]: info: Loading plugin "upnp"... Mar 25 07:44:42 katarynka volumio[12600]: info: [1774421082163] Starting Upmpd Daemon Mar 25 07:44:42 katarynka volumio[12600]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 25 07:44:42 katarynka volumio[12600]: info: Loading plugin "my_music"... Mar 25 07:44:42 katarynka volumio[12600]: info: Loading plugin "mpd"... Mar 25 07:44:42 katarynka sudo[12659]: pam_unix(sudo:session): session closed for user root Mar 25 07:44:42 katarynka volumio[12600]: info: Loading plugin "upnp_browser"... Mar 25 07:44:44 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 24. Mar 25 07:44:44 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 07:44:44 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 07:44:44 katarynka go-librespot[12682]: go-librespot daemon starting... Mar 25 07:44:45 katarynka go-librespot[12683]: time="2026-03-25T07:44:45+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 07:44:45 katarynka go-librespot[12683]: time="2026-03-25T07:44:45+01:00" level=debug msg="app state loaded" Mar 25 07:44:45 katarynka go-librespot[12683]: time="2026-03-25T07:44:45+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 07:44:45 katarynka go-librespot[12683]: time="2026-03-25T07:44:45+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 25 07:44:45 katarynka go-librespot[12683]: time="2026-03-25T07:44:45+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 07:44:45 katarynka go-librespot[12683]: time="2026-03-25T07:44:45+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 07:44:45 katarynka go-librespot[12683]: time="2026-03-25T07:44:45+01:00" level=info msg="zeroconf server listening on port 36715" Mar 25 07:44:45 katarynka go-librespot[12683]: time="2026-03-25T07:44:45+01:00" level=debug msg="obtained new client token: AADfGwsX8qyRLZAS1J9910ULmCTYx9CanlVgR77TwhjhAxRI+xIwjR/rmgNcp9KeuDcvewBXfJpXBF3IzUg8Hpt8kkQEiJoFvMFB/pKtTGqWczxqHnB6tpIFU8LQgTme3UuxQzbB8k4AOSZg9J9PNBJoCQyomaHxAKB9K6+9+2/OKiUfXlt+3s2fz6cH8rRiOUkoLPRaXJqvypAtJ08kJcMemLFfvkyQuelRpy2FZ69Ue6LFTeB8qdSTZW8=" Mar 25 07:44:45 katarynka go-librespot[12683]: time="2026-03-25T07:44:45+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 07:44:45 katarynka go-librespot[12683]: time="2026-03-25T07:44:45+01:00" level=debug msg="completed keyexchange" Mar 25 07:44:45 katarynka go-librespot[12683]: time="2026-03-25T07:44:45+01:00" level=debug msg="completed challenge" Mar 25 07:44:45 katarynka go-librespot[12683]: time="2026-03-25T07:44:45+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 25 07:44:45 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 07:44:45 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 07:44:45 katarynka volumio[12600]: info: Starting UPNP Browser Mar 25 07:44:45 katarynka volumio[12600]: info: Loading plugin "alarm-clock"... Mar 25 07:44:46 katarynka volumio[12600]: info: Loading plugin "airplay_emulation"... Mar 25 07:44:46 katarynka volumio[12600]: info: Starting Shairport Sync Mar 25 07:44:46 katarynka volumio[12600]: info: Loading plugin "last_100"... Mar 25 07:44:46 katarynka volumio[12600]: info: Loading plugin "webradio"... Mar 25 07:44:46 katarynka volumio[12600]: info: Loading plugin "i2s_dacs"... Mar 25 07:44:46 katarynka volumio[12600]: info: Loading plugin "volumiodiscovery"... Mar 25 07:44:46 katarynka volumio[12600]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Mar 25 07:44:46 katarynka volumio[12600]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 25 07:44:46 katarynka node[12600]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Mar 25 07:44:46 katarynka volumio[12600]: *** WARNING *** For more information see Mar 25 07:44:46 katarynka volumio[12600]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Mar 25 07:44:46 katarynka volumio[12600]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 25 07:44:46 katarynka volumio[12600]: *** WARNING *** For more information see Mar 25 07:44:46 katarynka node[12600]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 25 07:44:46 katarynka node[12600]: *** WARNING *** For more information see Mar 25 07:44:46 katarynka node[12600]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Mar 25 07:44:46 katarynka node[12600]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 25 07:44:46 katarynka node[12600]: *** WARNING *** For more information see Mar 25 07:44:46 katarynka volumio[12600]: info: Applying required configuration parameters for plugin volumiodiscovery Mar 25 07:44:46 katarynka volumio[12600]: info: Discovery: Started advertising with name: katarynka Mar 25 07:44:46 katarynka volumio[12600]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 25 07:44:46 katarynka volumio[12600]: info: Loading plugin "spop"... Mar 25 07:44:48 katarynka volumio[12600]: info: Loading plugin "outputs"... Mar 25 07:44:48 katarynka volumio[12600]: info: Loading plugin "albumart"... Mar 25 07:44:48 katarynka volumio[12600]: info: Plugin example_plugin is not enabled Mar 25 07:44:48 katarynka volumio[12600]: info: Loading plugin "inputs"... Mar 25 07:44:48 katarynka volumio[12600]: info: Loading plugin "updater_comm"... Mar 25 07:44:48 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 25. Mar 25 07:44:48 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 07:44:48 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 07:44:48 katarynka go-librespot[12701]: go-librespot daemon starting... Mar 25 07:44:48 katarynka volumio[12600]: info: Plugin mpdemulation is not enabled Mar 25 07:44:48 katarynka volumio[12600]: info: Loading plugin "rest_api"... Mar 25 07:44:49 katarynka volumio[12600]: info: Loading plugin "websocket"... Mar 25 07:44:49 katarynka go-librespot[12703]: time="2026-03-25T07:44:49+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 07:44:49 katarynka go-librespot[12703]: time="2026-03-25T07:44:49+01:00" level=debug msg="app state loaded" Mar 25 07:44:49 katarynka go-librespot[12703]: time="2026-03-25T07:44:49+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 07:44:49 katarynka volumio[12600]: info: Starting Socket.io Server version 1.7.4 Mar 25 07:44:49 katarynka volumio[12600]: info: Loading i18n strings for locale pl Mar 25 07:44:49 katarynka volumio[12600]: Updating browse sources language Mar 25 07:44:49 katarynka volumio[12600]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 25 07:44:49 katarynka volumio[12600]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 25 07:44:49 katarynka volumio[12600]: info: CoreCommandRouter::initPlayerControls Mar 25 07:44:49 katarynka volumio[12600]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 07:44:49 katarynka volumio[12600]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 07:44:49 katarynka volumio[12600]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 07:44:49 katarynka volumio[12600]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 07:44:49 katarynka volumio[12600]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 07:44:49 katarynka volumio[12600]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 07:44:49 katarynka volumio[12600]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 07:44:49 katarynka volumio[12600]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 07:44:49 katarynka volumio[12600]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 25 07:44:49 katarynka volumio[12600]: Express server listening on port 3000 Mar 25 07:44:49 katarynka volumio[12600]: [Metrics] WebUI: 12s 627.87ms Mar 25 07:44:49 katarynka go-librespot[12703]: time="2026-03-25T07:44:49+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Mar 25 07:44:49 katarynka go-librespot[12703]: time="2026-03-25T07:44:49+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Mar 25 07:44:49 katarynka go-librespot[12703]: time="2026-03-25T07:44:49+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Mar 25 07:44:49 katarynka volumio[12600]: info: CoreStateMachine::resetVolumioState Mar 25 07:44:49 katarynka volumio[12600]: info: CoreStateMachine::getcurrentVolume Mar 25 07:44:49 katarynka volumio[12600]: info: CoreCommandRouter::volumioRetrievevolume Mar 25 07:44:49 katarynka go-librespot[12703]: time="2026-03-25T07:44:49+01:00" level=info msg="zeroconf server listening on port 45523" Mar 25 07:44:49 katarynka volumio[12600]: info: Cannot read play queue from file Mar 25 07:44:49 katarynka volumio[12600]: info: Volumio Network Manager: Network status updated: 2 Mar 25 07:44:49 katarynka go-librespot[12703]: time="2026-03-25T07:44:49+01:00" level=debug msg="obtained new client token: AAA+UjgxqSfuutnFQBsRodfXVGogAvAoNp1gUY9d9xOahD0yEzMkPYyjTs91DF87FGpaBD1UE3VvM5pBP46z7dvAjeWkLgAIWZhgZVGAmqaNu64a7bOvGQepdpjuV3pSwVLnJzuqe/9z20adlMEKUd4vQAzrtEbtcxE2jQYIGetbjHjbtAqI/fe6ppUZrS1op9Nttvu3yCQm5g9UGaUcS12dqlUp9n9TQYZaRCQqUCWcjmNbfzn1a5IZviY=" Mar 25 07:44:49 katarynka go-librespot[12703]: time="2026-03-25T07:44:49+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 07:44:49 katarynka volumio[12692]: Forking 3 albumart workers Mar 25 07:44:49 katarynka go-librespot[12703]: time="2026-03-25T07:44:49+01:00" level=debug msg="completed keyexchange" Mar 25 07:44:49 katarynka go-librespot[12703]: time="2026-03-25T07:44:49+01:00" level=debug msg="completed challenge" Mar 25 07:44:49 katarynka go-librespot[12703]: time="2026-03-25T07:44:49+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 25 07:44:49 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 07:44:49 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 07:44:50 katarynka volumio[12600]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 07:44:50 katarynka volumio[12600]: info: CoreStateMachine::setRepeat null single undefined Mar 25 07:44:50 katarynka volumio[12600]: info: CoreStateMachine::pushState Mar 25 07:44:50 katarynka volumio[12600]: info: CorePlayQueue::getTrack 0 Mar 25 07:44:50 katarynka volumio[12600]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 25 07:44:50 katarynka volumio[12600]: info: CoreCommandRouter::volumioPushState Mar 25 07:44:50 katarynka volumio[12600]: info: CoreStateMachine::setRandom null Mar 25 07:44:50 katarynka volumio[12600]: info: CoreStateMachine::pushState Mar 25 07:44:50 katarynka volumio[12600]: info: CorePlayQueue::getTrack 0 Mar 25 07:44:50 katarynka volumio[12600]: info: CoreCommandRouter::volumioPushState Mar 25 07:44:50 katarynka volumio[12600]: info: Setting Device type: Raspberry PI Mar 25 07:44:50 katarynka volumio[12600]: info: Completed loading Core Plugins Mar 25 07:44:50 katarynka volumio[12600]: info: Preparing to generate the ALSA configuration file Mar 25 07:44:50 katarynka volumio[12600]: info: VolumeController:: Volume=96 Mute =false Mar 25 07:44:50 katarynka volumio[12600]: info: CoreStateMachine::pushState Mar 25 07:44:50 katarynka volumio[12600]: info: CorePlayQueue::getTrack 0 Mar 25 07:44:50 katarynka volumio[12600]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 25 07:44:50 katarynka volumio[12600]: info: CoreCommandRouter::volumioPushState Mar 25 07:44:50 katarynka volumio[12600]: info: CoreStateMachine::updateTrackBlock Mar 25 07:44:50 katarynka volumio[12600]: info: CorePlayQueue::getTrackBlock Mar 25 07:44:50 katarynka volumio[12600]: info: CoreCommandRouter::volumioRetrievevolume Mar 25 07:44:50 katarynka volumio[12600]: info: Asound.conf file unchanged, so no further update is needed Mar 25 07:44:50 katarynka volumio[12600]: info: Output device has changed, restarting MPD Mar 25 07:44:50 katarynka volumio[12600]: info: Output device has changed, restarting Shairport Sync Mar 25 07:44:50 katarynka volumio[12600]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 07:44:50 katarynka volumio[12600]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 07:44:50 katarynka sudo[12755]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 25 07:44:50 katarynka sudo[12755]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 07:44:50 katarynka sudo[12755]: pam_unix(sudo:session): session closed for user root Mar 25 07:44:50 katarynka sudo[12757]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 25 07:44:50 katarynka sudo[12757]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 07:44:50 katarynka volumio[12600]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 25 07:44:50 katarynka volumio[12600]: info: ___________ START PLUGINS ___________ Mar 25 07:44:50 katarynka volumio[12600]: info: ControllerMpd::onStart: Initializing MPD Mar 25 07:44:50 katarynka volumio[12600]: info: Creating MPD Configuration file Mar 25 07:44:50 katarynka systemd[1]: Stopping mpd.service - Music Player Daemon... Mar 25 07:44:50 katarynka volumio[12600]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 25 07:44:50 katarynka volumio[12600]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 25 07:44:50 katarynka volumio[12600]: info: [1774421090782] CoreMusicLibrary::Adding element Serwery Mediów Mar 25 07:44:50 katarynka volumio[12600]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 25 07:44:50 katarynka systemd[1]: mpd.service: Deactivated successfully. Mar 25 07:44:50 katarynka systemd[1]: Stopped mpd.service - Music Player Daemon. Mar 25 07:44:50 katarynka systemd[1]: mpd.service: Consumed 7.661s CPU time. Mar 25 07:44:50 katarynka volumio[12600]: info: UPNP Browser: Client initialized successfully Mar 25 07:44:50 katarynka systemd[1]: mpd.socket: Deactivated successfully. Mar 25 07:44:50 katarynka systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Mar 25 07:44:50 katarynka sudo[12765]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 25 07:44:50 katarynka systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Mar 25 07:44:50 katarynka sudo[12765]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 07:44:50 katarynka sudo[12765]: pam_unix(sudo:session): session closed for user root Mar 25 07:44:50 katarynka sudo[12767]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 25 07:44:50 katarynka sudo[12767]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 07:44:50 katarynka volumio[12600]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 07:44:50 katarynka volumio[12600]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 07:44:50 katarynka systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Mar 25 07:44:50 katarynka systemd[1]: Starting mpd.service - Music Player Daemon... Mar 25 07:44:50 katarynka volumio[12600]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 25 07:44:51 katarynka volumio[12600]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 07:44:51 katarynka volumio[12600]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 07:44:51 katarynka systemd[1]: mpd.service: Deactivated successfully. Mar 25 07:44:51 katarynka systemd[1]: Stopped mpd.service - Music Player Daemon. Mar 25 07:44:51 katarynka systemd[1]: mpd.socket: Deactivated successfully. Mar 25 07:44:51 katarynka systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Mar 25 07:44:51 katarynka systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Mar 25 07:44:51 katarynka volumio[12600]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 25 07:44:51 katarynka volumio[12600]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 25 07:44:51 katarynka volumio[12600]: info: [1774421091101] CoreMusicLibrary::Adding element Last_100 Mar 25 07:44:51 katarynka volumio[12600]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 25 07:44:51 katarynka volumio[12600]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 25 07:44:51 katarynka volumio[12600]: info: [1774421091110] CoreMusicLibrary::Adding element Webradio Mar 25 07:44:51 katarynka volumio[12600]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 25 07:44:51 katarynka volumio[12600]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 25 07:44:51 katarynka systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Mar 25 07:44:51 katarynka volumio[12600]: info: Initializing BBC Radios Mar 25 07:44:51 katarynka systemd[1]: Starting mpd.service - Music Player Daemon... Mar 25 07:44:51 katarynka volumio[12600]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 25 07:44:51 katarynka volumio[12600]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 07:44:51 katarynka volumio[12600]: info: Creating Spotify config file Mar 25 07:44:51 katarynka volumio[12600]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 07:44:51 katarynka volumio-remote-updater[622]: [2026-03-25 07:44:51] [connect] Successful connection Mar 25 07:44:51 katarynka sudo[12781]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Mar 25 07:44:51 katarynka sudo[12781]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Mar 25 07:44:51 katarynka sudo[12781]: pam_unix(sudo:session): session closed for user root Mar 25 07:44:52 katarynka volumio[12600]: info: Volumio Calling Home Mar 25 07:44:53 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 26. Mar 25 07:44:53 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 07:44:53 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 07:44:53 katarynka go-librespot[12814]: go-librespot daemon starting... Mar 25 07:44:53 katarynka go-librespot[12815]: time="2026-03-25T07:44:53+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 07:44:53 katarynka volumio[12716]: Starting albumart workers Mar 25 07:44:53 katarynka volumio[12715]: Starting albumart workers Mar 25 07:44:53 katarynka volumio[12600]: info: Discovery: adding 4d616d77-6a8c-4da2-85a4-840d70f98e51 Mar 25 07:44:53 katarynka volumio[12600]: info: Discovery: Found device katarynka Mar 25 07:44:53 katarynka volumio[12600]: info: CoreCommandRouter::volumioGetState Mar 25 07:44:53 katarynka volumio[12600]: info: CorePlayQueue::getTrack 0 Mar 25 07:44:53 katarynka sudo[12824]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 25 07:44:53 katarynka sudo[12824]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 07:44:53 katarynka sudo[12824]: pam_unix(sudo:session): session closed for user root Mar 25 07:44:53 katarynka volumio[12600]: info: MPD Permissions set Mar 25 07:44:53 katarynka volumio[12600]: info: MPD Permissions set Mar 25 07:44:53 katarynka volumio[12600]: info: VolumeController:: Volume=96 Mute =false Mar 25 07:44:53 katarynka volumio[12600]: info: CoreStateMachine::pushState Mar 25 07:44:53 katarynka volumio[12600]: info: CorePlayQueue::getTrack 0 Mar 25 07:44:53 katarynka volumio[12600]: info: CoreCommandRouter::volumioPushState Mar 25 07:44:53 katarynka sudo[12822]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 25 07:44:53 katarynka sudo[12822]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 07:44:53 katarynka sudo[12822]: pam_unix(sudo:session): session closed for user root Mar 25 07:44:53 katarynka volumio-remote-updater[622]: [2026-03-25 07:44:53] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1774421091 101 Mar 25 07:44:54 katarynka volumio[12600]: 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 07:44:54 katarynka go-librespot[12815]: time="2026-03-25T07:44:54+01:00" level=info msg="zeroconf server listening on port 46175" Mar 25 07:44:54 katarynka volumio[12718]: Starting albumart workers Mar 25 07:44:54 katarynka volumio[12600]: info: Volumio called home Mar 25 07:44:54 katarynka volumio[12600]: info: Spotify config file written Mar 25 07:44:54 katarynka volumio[12600]: info: Discovery: this is already registered, 4d616d77-6a8c-4da2-85a4-840d70f98e51 Mar 25 07:44:54 katarynka volumio[12600]: info: Discovery: Found device katarynka Mar 25 07:44:54 katarynka volumio[12600]: info: CoreCommandRouter::volumioGetState Mar 25 07:44:54 katarynka volumio[12600]: info: CorePlayQueue::getTrack 0 Mar 25 07:44:54 katarynka sudo[12830]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Mar 25 07:44:54 katarynka sudo[12830]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 07:44:54 katarynka systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Mar 25 07:44:54 katarynka systemd[1]: go-librespot-daemon.service: Deactivated successfully. Mar 25 07:44:54 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 07:44:54 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 07:44:54 katarynka go-librespot[12832]: go-librespot daemon starting... Mar 25 07:44:54 katarynka sudo[12830]: pam_unix(sudo:session): session closed for user root Mar 25 07:44:54 katarynka go-librespot[12833]: time="2026-03-25T07:44:54+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 07:44:54 katarynka go-librespot[12833]: time="2026-03-25T07:44:54+01:00" level=debug msg="app state loaded" Mar 25 07:44:54 katarynka go-librespot[12833]: time="2026-03-25T07:44:54+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 07:44:54 katarynka volumio[12600]: 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 07:44:54 katarynka volumio[12600]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 07:44:54 katarynka volumio[12600]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 07:44:54 katarynka volumio[12600]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 07:44:54 katarynka volumio[12600]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 07:44:54 katarynka volumio[12600]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 07:44:54 katarynka volumio[12600]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 07:44:54 katarynka volumio[12600]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 07:44:54 katarynka volumio[12600]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 07:44:54 katarynka volumio[12600]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 07:44:54 katarynka volumio[12600]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 07:44:55 katarynka volumio[12600]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 07:44:55 katarynka volumio[12600]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 07:44:55 katarynka volumio[12600]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 07:44:55 katarynka volumio[12600]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 07:44:55 katarynka volumio[12600]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 07:44:55 katarynka volumio[12600]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 07:44:55 katarynka volumio[12600]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 07:44:55 katarynka volumio[12600]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 07:44:55 katarynka volumio[12600]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 07:44:55 katarynka volumio[12600]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 07:44:55 katarynka volumio[12600]: info: No need to fix Spotify hosts Mar 25 07:44:55 katarynka go-librespot[12833]: time="2026-03-25T07:44:55+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 25 07:44:55 katarynka go-librespot[12833]: time="2026-03-25T07:44:55+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 25 07:44:55 katarynka go-librespot[12833]: time="2026-03-25T07:44:55+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 25 07:44:55 katarynka go-librespot[12833]: time="2026-03-25T07:44:55+01:00" level=info msg="zeroconf server listening on port 35545" Mar 25 07:44:55 katarynka go-librespot[12833]: time="2026-03-25T07:44:55+01:00" level=debug msg="obtained new client token: AADefDvLjNA+f5D43BNOlXupDE1fHcT3X+EHwlqbYwxw5RlCUex/MD/Crwt8m2BTJaV+PPAQdDdG+9BGNGCDztASBfnRcrbUkNLtZIlclfuAVgPgYARw1MFdbFxkMgXWwEAzfPs9LGGpchCU/fDe/XHMLtE6nniD3TSBu/o7eHfDlZrsGPp2oMHemFxeaxDBdRY2AmqVfZ4ij7rSIMo0hGitf0L1eqBI6ZsIg8K0gHOWLZt30Jiwekuj/LU=" Mar 25 07:44:55 katarynka go-librespot[12833]: time="2026-03-25T07:44:55+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 07:44:55 katarynka go-librespot[12833]: time="2026-03-25T07:44:55+01:00" level=debug msg="completed keyexchange" Mar 25 07:44:55 katarynka go-librespot[12833]: time="2026-03-25T07:44:55+01:00" level=debug msg="completed challenge" Mar 25 07:44:55 katarynka volumio[12600]: info: Starting Shairport Sync Mar 25 07:44:55 katarynka go-librespot[12833]: time="2026-03-25T07:44:55+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 07:44:55 katarynka volumio[12600]: info: Starting Shairport Sync Mar 25 07:44:55 katarynka volumio[12600]: info: Starting Shairport Sync Mar 25 07:44:55 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 07:44:55 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 07:44:55 katarynka sudo[12853]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 25 07:44:55 katarynka sudo[12853]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 07:44:55 katarynka sudo[12855]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 25 07:44:55 katarynka sudo[12855]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 07:44:55 katarynka sudo[12857]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Mar 25 07:44:55 katarynka sudo[12857]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 07:44:56 katarynka sudo[12851]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 25 07:44:56 katarynka sudo[12851]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 07:44:56 katarynka sudo[12857]: pam_unix(sudo:session): session closed for user root Mar 25 07:44:56 katarynka systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Mar 25 07:44:56 katarynka systemd[1]: shairport-sync.service: Deactivated successfully. Mar 25 07:44:56 katarynka systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 25 07:44:56 katarynka systemd[1]: shairport-sync.service: Consumed 2.472s CPU time. Mar 25 07:44:56 katarynka volumio[12600]: info: An error occurred while refreshing Spotify Token Error: Bad Request Mar 25 07:44:56 katarynka volumio[12600]: info: CoreCommandRouter::volumioGetState Mar 25 07:44:56 katarynka volumio[12600]: info: CorePlayQueue::getTrack 0 Mar 25 07:44:56 katarynka systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 25 07:44:56 katarynka sudo[12851]: pam_unix(sudo:session): session closed for user root Mar 25 07:44:56 katarynka sudo[12855]: pam_unix(sudo:session): session closed for user root Mar 25 07:44:56 katarynka sudo[12853]: pam_unix(sudo:session): session closed for user root Mar 25 07:44:56 katarynka volumio[12600]: info: Upmpdcli Daemon Started Mar 25 07:44:56 katarynka volumio[12600]: info: Shairport-Sync Started Mar 25 07:44:56 katarynka volumio[12600]: Error adding Membership: Error: addMembership EINVAL Mar 25 07:44:56 katarynka volumio[12600]: info: Shairport-Sync Started Mar 25 07:44:56 katarynka volumio[12600]: info: Shairport-Sync Started Mar 25 07:44:58 katarynka volumio[12600]: info: go-librespot daemon successfully initialized Mar 25 07:44:58 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Mar 25 07:44:58 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 07:44:58 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 07:44:58 katarynka go-librespot[12896]: go-librespot daemon starting... Mar 25 07:44:59 katarynka go-librespot[12897]: time="2026-03-25T07:44:59+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 07:44:59 katarynka go-librespot[12897]: time="2026-03-25T07:44:59+01:00" level=debug msg="app state loaded" Mar 25 07:44:59 katarynka go-librespot[12897]: time="2026-03-25T07:44:59+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 07:44:59 katarynka mpd[12796]: 2026-03-25T07:44:59 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Mar 25 07:44:59 katarynka systemd[1]: Started mpd.service - Music Player Daemon. Mar 25 07:44:59 katarynka sudo[12767]: pam_unix(sudo:session): session closed for user root Mar 25 07:44:59 katarynka sudo[12757]: pam_unix(sudo:session): session closed for user root Mar 25 07:44:59 katarynka volumio[12600]: info: Completed starting Core Plugins Mar 25 07:44:59 katarynka volumio[12600]: info: ------------------------------------------- Mar 25 07:44:59 katarynka volumio[12600]: info: ----- MyVolumio plugins startup ---- Mar 25 07:44:59 katarynka volumio[12600]: info: ------------------------------------------- Mar 25 07:44:59 katarynka volumio[12600]: info: [MyVolumio PluginManager] Fetching plans data.... Mar 25 07:44:59 katarynka go-librespot[12897]: time="2026-03-25T07:44:59+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 25 07:44:59 katarynka go-librespot[12897]: time="2026-03-25T07:44:59+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 07:44:59 katarynka go-librespot[12897]: time="2026-03-25T07:44:59+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 07:44:59 katarynka volumio[12600]: error: MPD error: The expression evaluated to a falsy value: Mar 25 07:44:59 katarynka volumio[12600]: assert.ok(self.idling) Mar 25 07:44:59 katarynka volumio[12600]: error: The expression evaluated to a falsy value: Mar 25 07:44:59 katarynka volumio[12600]: assert.ok(self.idling) Mar 25 07:44:59 katarynka volumio[12600]: error: updateQueue error: null Mar 25 07:44:59 katarynka go-librespot[12897]: time="2026-03-25T07:44:59+01:00" level=info msg="zeroconf server listening on port 44287" Mar 25 07:44:59 katarynka volumio[12600]: info: MPD running with PID12796 Mar 25 07:44:59 katarynka volumio[12600]: ,establishing connection Mar 25 07:44:59 katarynka volumio[12600]: error: updateQueue error: null Mar 25 07:44:59 katarynka go-librespot[12897]: time="2026-03-25T07:44:59+01:00" level=debug msg="obtained new client token: AAAZPoqtZnt/YUoj2vZXaxAqIlv0XaXPstOfJABLDhjyyPNtuHMK/Q9kclYmSS43Tj7uXhLok04Pnt+IO7SaWz2WeP5J1UZrC4pSNnRGGLhISBRiDaqlHC8dFNoFT/cdxHpkXfmehZnZ0Qi/BP1z8uEsg0KAK8CY/MnmsePnGgyPBxZqNKuUpXR005cOuXjEgfyH6bW/RQ5EZepEW1zLcNC/9bzZn4mUGEZ4nOp4aLtCToG7swDfuiBYDFo=" Mar 25 07:44:59 katarynka go-librespot[12897]: time="2026-03-25T07:44:59+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 07:44:59 katarynka go-librespot[12897]: time="2026-03-25T07:44:59+01:00" level=debug msg="completed keyexchange" Mar 25 07:44:59 katarynka go-librespot[12897]: time="2026-03-25T07:44:59+01:00" level=debug msg="completed challenge" Mar 25 07:44:59 katarynka go-librespot[12897]: time="2026-03-25T07:44:59+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 07:44:59 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 07:44:59 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 07:45:01 katarynka volumio[12600]: info: Initializing connection to go-librespot Websocket Mar 25 07:45:01 katarynka volumio[12600]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 25 07:45:02 katarynka sudo[12927]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Mar 25 07:45:02 katarynka sudo[12927]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 07:45:02 katarynka sudo[12929]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Mar 25 07:45:02 katarynka sudo[12929]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 07:45:02 katarynka systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Mar 25 07:45:02 katarynka systemd[1]: mpd_monitor.service: Deactivated successfully. Mar 25 07:45:02 katarynka systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Mar 25 07:45:02 katarynka systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Mar 25 07:45:02 katarynka sudo[12929]: pam_unix(sudo:session): session closed for user root Mar 25 07:45:02 katarynka sudo[12927]: pam_unix(sudo:session): session closed for user root Mar 25 07:45:02 katarynka mpd_monitor.sh[12932]: MPD Monitor Service: Starting MPD Monitor Service Mar 25 07:45:02 katarynka volumio[12600]: info: Successfully started MPD Monitor Mar 25 07:45:02 katarynka volumio[12600]: info: Successfully started MPD Monitor Mar 25 07:45:02 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Mar 25 07:45:02 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 07:45:02 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 07:45:02 katarynka go-librespot[12936]: go-librespot daemon starting... Mar 25 07:45:03 katarynka go-librespot[12937]: time="2026-03-25T07:45:03+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 07:45:03 katarynka go-librespot[12937]: time="2026-03-25T07:45:03+01:00" level=debug msg="app state loaded" Mar 25 07:45:03 katarynka go-librespot[12937]: time="2026-03-25T07:45:03+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 07:45:03 katarynka go-librespot[12937]: time="2026-03-25T07:45:03+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 25 07:45:03 katarynka go-librespot[12937]: time="2026-03-25T07:45:03+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 07:45:03 katarynka go-librespot[12937]: time="2026-03-25T07:45:03+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 07:45:03 katarynka go-librespot[12937]: time="2026-03-25T07:45:03+01:00" level=info msg="zeroconf server listening on port 35871" Mar 25 07:45:03 katarynka go-librespot[12937]: time="2026-03-25T07:45:03+01:00" level=debug msg="obtained new client token: AADwhO5J7/C/QfkejyRpce/j0Il3Xad3ps3+NGk9wiINR2TgiFWua8hbdnVn1cSHm16VjT/Nj7YZD2evDOHV8voVM+g3SjatidVVjoGUffjNffjye2pZFaa4Sj5gKQu+lhvr8jBYVkeOJQvqU738ahhcUwmwgRBGpoWUKQiSe8OhcuYO346rET374DyW72hzyg3jmodjnXnbXKgWplU8SQ/xt9oohQ8/Pgued4C/rKzVr1yHD/hzG3g/X4k=" Mar 25 07:45:03 katarynka go-librespot[12937]: time="2026-03-25T07:45:03+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 07:45:03 katarynka go-librespot[12937]: time="2026-03-25T07:45:03+01:00" level=debug msg="connected to ap-gew4.spotify.com:443" Mar 25 07:45:03 katarynka go-librespot[12937]: time="2026-03-25T07:45:03+01:00" level=debug msg="completed keyexchange" Mar 25 07:45:03 katarynka go-librespot[12937]: time="2026-03-25T07:45:03+01:00" level=debug msg="completed challenge" Mar 25 07:45:03 katarynka go-librespot[12937]: time="2026-03-25T07:45:03+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 25 07:45:03 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 07:45:03 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 07:45:04 katarynka volumio[12600]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Mar 25 07:45:04 katarynka volumio[12600]: info: Initializing connection to go-librespot Websocket Mar 25 07:45:04 katarynka volumio[12600]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 25 07:45:06 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Mar 25 07:45:06 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 07:45:06 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 07:45:06 katarynka go-librespot[12944]: go-librespot daemon starting... Mar 25 07:45:07 katarynka go-librespot[12945]: time="2026-03-25T07:45:07+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 07:45:07 katarynka go-librespot[12945]: time="2026-03-25T07:45:07+01:00" level=debug msg="app state loaded" Mar 25 07:45:07 katarynka go-librespot[12945]: time="2026-03-25T07:45:07+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 07:45:07 katarynka go-librespot[12945]: time="2026-03-25T07:45:07+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 25 07:45:07 katarynka go-librespot[12945]: time="2026-03-25T07:45:07+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 07:45:07 katarynka go-librespot[12945]: time="2026-03-25T07:45:07+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 07:45:07 katarynka go-librespot[12945]: time="2026-03-25T07:45:07+01:00" level=info msg="zeroconf server listening on port 35681" Mar 25 07:45:07 katarynka go-librespot[12945]: time="2026-03-25T07:45:07+01:00" level=debug msg="obtained new client token: AADe89YgBoslP2+//VQ+5l170T5Ue+HrTxKXGZAR9E+waTuKPmUYV/q85o+lSnOR1DdhP7Nv7Wdko9xyJzSozsOkg+q9YxEIawO9ODitd4on4zqzwNre5vsN64txpyTf7fQvo4EtrDrqKfH+i6oeyost4AU8rbJuVtfPvPz0BGUNE3t4MCayTiy3klJ1JX6yd6BS9HApj/JUZCH5UyE2/6D+u7ziSw8GyjDe0pNudCr6T1jHyNlLhg2iXSU=" Mar 25 07:45:07 katarynka go-librespot[12945]: time="2026-03-25T07:45:07+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 07:45:07 katarynka volumio[12600]: info: Initializing connection to go-librespot Websocket Mar 25 07:45:07 katarynka go-librespot[12945]: time="2026-03-25T07:45:07+01:00" level=debug msg="new websocket client" Mar 25 07:45:07 katarynka go-librespot[12945]: time="2026-03-25T07:45:07+01:00" level=debug msg="completed keyexchange" Mar 25 07:45:07 katarynka go-librespot[12945]: time="2026-03-25T07:45:07+01:00" level=debug msg="completed challenge" Mar 25 07:45:07 katarynka volumio[12600]: info: Connection to go-librespot Websocket established Mar 25 07:45:07 katarynka go-librespot[12945]: time="2026-03-25T07:45:07+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 25 07:45:07 katarynka volumio[12600]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Mar 25 07:45:07 katarynka volumio[12600]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Mar 25 07:45:07 katarynka volumio[12600]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Mar 25 07:45:07 katarynka volumio[12600]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Mar 25 07:45:07 katarynka volumio[12600]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Mar 25 07:45:07 katarynka volumio[12600]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Mar 25 07:45:07 katarynka volumio[12600]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Mar 25 07:45:07 katarynka volumio[12600]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Mar 25 07:45:07 katarynka volumio[12600]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Mar 25 07:45:07 katarynka volumio[12600]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Mar 25 07:45:07 katarynka volumio[12600]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Mar 25 07:45:07 katarynka volumio[12600]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Mar 25 07:45:07 katarynka volumio[12600]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Mar 25 07:45:07 katarynka volumio[12600]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Mar 25 07:45:07 katarynka volumio[12600]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Mar 25 07:45:07 katarynka volumio[12600]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Mar 25 07:45:07 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 07:45:07 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 07:45:07 katarynka volumio[12600]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Mar 25 07:45:07 katarynka volumio[12600]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Mar 25 07:45:07 katarynka volumio[12600]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Mar 25 07:45:07 katarynka volumio[12600]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Mar 25 07:45:07 katarynka volumio[12600]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Mar 25 07:45:07 katarynka volumio[12600]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Mar 25 07:45:07 katarynka volumio[12600]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Mar 25 07:45:07 katarynka volumio[12600]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Mar 25 07:45:07 katarynka volumio[12600]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Mar 25 07:45:07 katarynka volumio[12600]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Mar 25 07:45:07 katarynka volumio[12600]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Mar 25 07:45:07 katarynka volumio[12600]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Mar 25 07:45:07 katarynka volumio[12600]: info: Adding plugin bluetooth to MyMusic Plugins Mar 25 07:45:07 katarynka volumio[12600]: info: Adding plugin multiroom to MyMusic Plugins Mar 25 07:45:07 katarynka volumio[12600]: info: Adding plugin metavolumio to MyMusic Plugins Mar 25 07:45:07 katarynka volumio[12600]: info: Adding plugin cd_controller to MyMusic Plugins Mar 25 07:45:07 katarynka volumio[12600]: info: Adding plugin qobuzconnect to MyMusic Plugins Mar 25 07:45:07 katarynka volumio[12600]: info: Adding plugin smart_inputs to MyMusic Plugins Mar 25 07:45:07 katarynka volumio[12600]: info: Adding plugin tidalconnect to MyMusic Plugins Mar 25 07:45:07 katarynka volumio[12600]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Mar 25 07:45:09 katarynka volumio[12600]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Mar 25 07:45:09 katarynka volumio[12600]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Mar 25 07:45:09 katarynka volumio[12600]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 07:45:09 katarynka volumio[12600]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 07:45:09 katarynka volumio[12600]: info: Starting MyVolumio Remote Streaming Endpoints Mar 25 07:45:09 katarynka volumio[12600]: info: MyVolumio login type: Token Mar 25 07:45:09 katarynka volumio[12600]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Mar 25 07:45:09 katarynka volumio[12600]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Mar 25 07:45:10 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Mar 25 07:45:10 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 07:45:10 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 07:45:10 katarynka go-librespot[12952]: go-librespot daemon starting... Mar 25 07:45:11 katarynka go-librespot[12953]: time="2026-03-25T07:45:11+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 07:45:11 katarynka go-librespot[12953]: time="2026-03-25T07:45:11+01:00" level=debug msg="app state loaded" Mar 25 07:45:11 katarynka go-librespot[12953]: time="2026-03-25T07:45:11+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 07:45:11 katarynka go-librespot[12953]: time="2026-03-25T07:45:11+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 25 07:45:11 katarynka go-librespot[12953]: time="2026-03-25T07:45:11+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 07:45:11 katarynka go-librespot[12953]: time="2026-03-25T07:45:11+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 07:45:11 katarynka go-librespot[12953]: time="2026-03-25T07:45:11+01:00" level=info msg="zeroconf server listening on port 46017" Mar 25 07:45:11 katarynka go-librespot[12953]: time="2026-03-25T07:45:11+01:00" level=debug msg="obtained new client token: AAC7P8s9T6AmLxiuFKZ1ayvUwipxXc7RDCTiTL5NI/cl26WJ+fFg1jM50VQWFzSbiRpgoduBo/4zul4K931HbMQX5MPC3+VS1XvLUh/wkcvWtRsLGVkEFhGbIYdZ+znOH/xQarLVqbHaIWn/fPcpgQa4RaNYz9qPypYx1pxv3B+ZkVcMExVZvUStbEMfCPfc2AauiBoxDgtsUGqwIPLkJiHVOuir0e9/G54GSYC+RCRQC5Fj/U3GiVyrLhs=" Mar 25 07:45:11 katarynka volumio[12600]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Mar 25 07:45:11 katarynka volumio[12600]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Mar 25 07:45:11 katarynka volumio[12600]: info: Streaming services startup Mar 25 07:45:11 katarynka volumio[12600]: info: Starting Streaming Daemon Mar 25 07:45:11 katarynka go-librespot[12953]: time="2026-03-25T07:45:11+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 07:45:11 katarynka sudo[12961]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Mar 25 07:45:11 katarynka sudo[12961]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 07:45:11 katarynka volumio[12600]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Mar 25 07:45:11 katarynka go-librespot[12953]: time="2026-03-25T07:45:11+01:00" level=debug msg="completed keyexchange" Mar 25 07:45:11 katarynka go-librespot[12953]: time="2026-03-25T07:45:11+01:00" level=debug msg="completed challenge" Mar 25 07:45:11 katarynka sudo[12961]: pam_unix(sudo:session): session closed for user root Mar 25 07:45:11 katarynka go-librespot[12953]: time="2026-03-25T07:45: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 07:45:11 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 07:45:11 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 07:45:11 katarynka volumio[12600]: info: Getting Spotify volume Mar 25 07:45:11 katarynka volumio[12600]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 25 07:45:11 katarynka volumio[12600]: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 25 07:45:11 katarynka volumio[12600]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Mar 25 07:45:11 katarynka volumio[12600]: errno: -111, Mar 25 07:45:11 katarynka volumio[12600]: code: 'ECONNREFUSED', Mar 25 07:45:11 katarynka volumio[12600]: syscall: 'connect', Mar 25 07:45:11 katarynka volumio[12600]: address: '127.0.0.1', Mar 25 07:45:11 katarynka volumio[12600]: port: 9879, Mar 25 07:45:11 katarynka volumio[12600]: response: undefined Mar 25 07:45:11 katarynka volumio[12600]: } Mar 25 07:45:11 katarynka volumio[12600]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 25 07:45:13 katarynka sudo[12995]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-03-25 07:44' Mar 25 07:45:13 katarynka sudo[12995]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 07:45:13 katarynka sudo[12995]: pam_unix(sudo:session): session closed for user root Mar 25 07:45:13 katarynka volumio-remote-updater[622]: [2026-03-25 07:45:13] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Mar 25 07:45:13 katarynka volumio-remote-updater[622]: [2026-03-25 07:45:13] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Mar 25 07:45:13 katarynka systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Mar 25 07:45:13 katarynka systemd[1]: volumio.service: Failed with result 'exit-code'. Mar 25 07:45:13 katarynka systemd[1]: volumio.service: Consumed 48.494s CPU time. Mar 25 07:45:14 katarynka systemd[1]: Started dynamicswap.service - dynamicswap service. Mar 25 07:45:14 katarynka systemd[1]: dynamicswap.service: Deactivated successfully. Mar 25 07:45:14 katarynka systemd[1]: volumio.service: Scheduled restart job, restart counter is at 26104. Mar 25 07:45:14 katarynka systemd[1]: Started dynamicswap.service - dynamicswap service. Mar 25 07:45:14 katarynka systemd[1]: Stopped volumio.service - Volumio Backend Module. Mar 25 07:45:14 katarynka systemd[1]: volumio.service: Consumed 48.494s CPU time. Mar 25 07:45:14 katarynka systemd[1]: Started volumio.service - Volumio Backend Module. Mar 25 07:45:14 katarynka systemd[1]: dynamicswap.service: Deactivated successfully. Mar 25 07:45:14 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Mar 25 07:45:14 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 07:45:15 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 07:45:15 katarynka go-librespot[13022]: go-librespot daemon starting... Mar 25 07:45:15 katarynka go-librespot[13023]: time="2026-03-25T07:45:15+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 07:45:15 katarynka go-librespot[13023]: time="2026-03-25T07:45:15+01:00" level=debug msg="app state loaded" Mar 25 07:45:15 katarynka go-librespot[13023]: time="2026-03-25T07:45:15+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 07:45:15 katarynka go-librespot[13023]: time="2026-03-25T07:45:15+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 25 07:45:15 katarynka go-librespot[13023]: time="2026-03-25T07:45:15+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 25 07:45:15 katarynka go-librespot[13023]: time="2026-03-25T07:45:15+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 25 07:45:15 katarynka go-librespot[13023]: time="2026-03-25T07:45:15+01:00" level=info msg="zeroconf server listening on port 39729" Mar 25 07:45:15 katarynka go-librespot[13023]: time="2026-03-25T07:45:15+01:00" level=debug msg="obtained new client token: AACOl5RhLL7Qp4j9O3Th89IFF9TvzKeP2r5NpOI2sQmYOg+DZjRt4PLx9IfIO166Kn+2tJ+2SNDD84JiSyIGES4CZ+Zjax1WajH8gKi1afMZ+NKGePgasgSytKznOu0GCTdtzCBTdnuvc8JtI2uwbw8tIRVFv6ysLto182y264jjncpar+ISr38oUHLa91zKftEE4JDo35l/LKvabbr/vhrL/3f/ewHRxhXaNjNPTSg7ZDNyMOzErCZ2dDI=" Mar 25 07:45:15 katarynka go-librespot[13023]: time="2026-03-25T07:45:15+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 07:45:16 katarynka go-librespot[13023]: time="2026-03-25T07:45:16+01:00" level=debug msg="completed keyexchange" Mar 25 07:45:16 katarynka go-librespot[13023]: time="2026-03-25T07:45:16+01:00" level=debug msg="completed challenge" Mar 25 07:45:16 katarynka go-librespot[13023]: time="2026-03-25T07:45:16+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 25 07:45:16 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 07:45:16 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 07:45:17 katarynka volumio[13007]: info: ------------------------------------------- Mar 25 07:45:17 katarynka volumio[13007]: info: ----- Volumio3 ---- Mar 25 07:45:17 katarynka volumio[13007]: info: ------------------------------------------- Mar 25 07:45:17 katarynka volumio[13007]: info: ----- System startup ---- Mar 25 07:45:17 katarynka volumio[13007]: info: ------------------------------------------- Mar 25 07:45:18 katarynka volumio-remote-updater[622]: [2026-03-25 07:45:18] [connect] Successful connection Mar 25 07:45:19 katarynka volumio[13007]: info: MYVOLUMIO Environment detected Mar 25 07:45:19 katarynka volumio[13007]: info: Plugin folders cleanup Mar 25 07:45:19 katarynka volumio[13007]: info: Scanning into folder /volumio/app/plugins/ Mar 25 07:45:19 katarynka volumio[13007]: info: Scanning category audio_interface Mar 25 07:45:19 katarynka volumio[13007]: info: Scanning category miscellanea Mar 25 07:45:19 katarynka volumio[13007]: info: Scanning category music_service Mar 25 07:45:19 katarynka volumio[13007]: info: Scanning category plugins.json Mar 25 07:45:19 katarynka volumio[13007]: info: Scanning category system_controller Mar 25 07:45:19 katarynka volumio[13007]: info: Scanning category user_interface Mar 25 07:45:19 katarynka volumio[13007]: info: Scanning into folder /data/plugins/ Mar 25 07:45:19 katarynka volumio[13007]: info: Scanning category music_service Mar 25 07:45:19 katarynka volumio[13007]: info: Plugin folders cleanup completed Mar 25 07:45:19 katarynka volumio[13007]: info: ------------------------------------------- Mar 25 07:45:19 katarynka volumio[13007]: info: ----- Core plugins startup ---- Mar 25 07:45:19 katarynka volumio[13007]: info: ------------------------------------------- Mar 25 07:45:19 katarynka volumio[13007]: info: Loading plugins from folder /volumio/app/plugins/ Mar 25 07:45:19 katarynka volumio[13007]: info: Adding plugin upnp to MyMusic Plugins Mar 25 07:45:19 katarynka volumio[13007]: info: Adding plugin airplay_emulation to MyMusic Plugins Mar 25 07:45:19 katarynka volumio[13007]: info: Adding plugin upnp_browser to MyMusic Plugins Mar 25 07:45:19 katarynka volumio[13007]: info: Loading plugins from folder /data/plugins/ Mar 25 07:45:19 katarynka volumio[13007]: info: Loading plugin "system"... Mar 25 07:45:19 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Mar 25 07:45:19 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 07:45:19 katarynka volumio[13007]: info: Loading plugin "appearance"... Mar 25 07:45:19 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 07:45:19 katarynka go-librespot[13040]: go-librespot daemon starting... Mar 25 07:45:19 katarynka go-librespot[13044]: time="2026-03-25T07:45:19+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 07:45:19 katarynka go-librespot[13044]: time="2026-03-25T07:45:19+01:00" level=debug msg="app state loaded" Mar 25 07:45:19 katarynka go-librespot[13044]: time="2026-03-25T07:45:19+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 07:45:20 katarynka go-librespot[13044]: time="2026-03-25T07:45:20+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 07:45:20 katarynka go-librespot[13044]: time="2026-03-25T07:45:20+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 07:45:20 katarynka go-librespot[13044]: time="2026-03-25T07:45:20+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 07:45:20 katarynka go-librespot[13044]: time="2026-03-25T07:45:20+01:00" level=info msg="zeroconf server listening on port 37713" Mar 25 07:45:20 katarynka go-librespot[13044]: time="2026-03-25T07:45:20+01:00" level=debug msg="obtained new client token: AACU/F+7X5fwOSSRNk6E7vxINZXyPqqXfovg22v4vxzNdloQLxYG/jd3MDtOfdl8t9NPXNU4kcaWUet70iNj7fLLCGg9B/nl59cUAMveTBM5ztl+KUzalSnGE7AO3Xe4ezY9HtdAmYuRWU7T3TEE8tAT8GWLVwJ4ySA/OQVbijFEdKv8t7KVDfK2xWBP62kNaJVRT1p+9egqUtb1gGQrSGYvCOG603cbHs5uxJW8D1EMazbj5xS4fkgHJuc=" Mar 25 07:45:20 katarynka go-librespot[13044]: time="2026-03-25T07:45:20+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 07:45:20 katarynka go-librespot[13044]: time="2026-03-25T07:45:20+01:00" level=debug msg="completed keyexchange" Mar 25 07:45:20 katarynka go-librespot[13044]: time="2026-03-25T07:45:20+01:00" level=debug msg="completed challenge" Mar 25 07:45:20 katarynka go-librespot[13044]: time="2026-03-25T07:45:20+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 25 07:45:20 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 07:45:20 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 07:45:21 katarynka volumio[13007]: info: Loading plugin "network"... Mar 25 07:45:21 katarynka volumio[13007]: info: Refreshing Cached IP Addresses Mar 25 07:45:21 katarynka sudo[13052]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 25 07:45:21 katarynka sudo[13052]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 07:45:21 katarynka sudo[13052]: pam_unix(sudo:session): session closed for user root Mar 25 07:45:21 katarynka volumio[13007]: info: Loading plugin "services"... Mar 25 07:45:21 katarynka sudo[13054]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 25 07:45:21 katarynka sudo[13054]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 07:45:21 katarynka volumio[13007]: info: Loading plugin "alsa_controller"... Mar 25 07:45:21 katarynka sudo[13054]: pam_unix(sudo:session): session closed for user root Mar 25 07:45:21 katarynka sudo[13062]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Mar 25 07:45:21 katarynka sudo[13062]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 07:45:22 katarynka volumio[13007]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 25 07:45:22 katarynka volumio[13007]: info: Loading plugin "wizard"... Mar 25 07:45:22 katarynka volumio[13007]: info: Loading plugin "networkfs"... Mar 25 07:45:22 katarynka volumio[13007]: info: Starting Udev Watcher for removable devices Mar 25 07:45:22 katarynka volumio[13007]: info: Ignoring mount for partition: boot Mar 25 07:45:22 katarynka volumio[13007]: info: Ignoring mount for partition: volumio Mar 25 07:45:22 katarynka volumio[13007]: info: Ignoring mount for partition: volumio_data Mar 25 07:45:22 katarynka volumio[13007]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 25 07:45:22 katarynka volumio[13007]: info: Loading plugin "volumio_command_line_client"... Mar 25 07:45:22 katarynka volumio[13007]: info: Loading plugin "upnp"... Mar 25 07:45:22 katarynka volumio[13007]: info: [1774421122255] Starting Upmpd Daemon Mar 25 07:45:22 katarynka volumio[13007]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 25 07:45:22 katarynka volumio[13007]: info: Loading plugin "my_music"... Mar 25 07:45:22 katarynka volumio[13007]: info: Loading plugin "mpd"... Mar 25 07:45:22 katarynka sudo[13062]: pam_unix(sudo:session): session closed for user root Mar 25 07:45:22 katarynka volumio[13007]: info: Loading plugin "upnp_browser"... Mar 25 07:45:23 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Mar 25 07:45:23 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 07:45:23 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 07:45:23 katarynka go-librespot[13088]: go-librespot daemon starting... Mar 25 07:45:23 katarynka go-librespot[13089]: time="2026-03-25T07:45:23+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 07:45:23 katarynka go-librespot[13089]: time="2026-03-25T07:45:23+01:00" level=debug msg="app state loaded" Mar 25 07:45:23 katarynka go-librespot[13089]: time="2026-03-25T07:45:23+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 07:45:24 katarynka go-librespot[13089]: time="2026-03-25T07:45:24+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 25 07:45:24 katarynka go-librespot[13089]: time="2026-03-25T07:45:24+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 07:45:24 katarynka go-librespot[13089]: time="2026-03-25T07:45:24+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 07:45:24 katarynka go-librespot[13089]: time="2026-03-25T07:45:24+01:00" level=info msg="zeroconf server listening on port 39061" Mar 25 07:45:24 katarynka go-librespot[13089]: time="2026-03-25T07:45:24+01:00" level=debug msg="obtained new client token: AAA2sHpCjOpq37bkpGXQ0FgLdIQ7Plf/pwWFMaST7cpqyVRuzJW9sYB6q7GAJysUulTX9pXoWoWtnKLKjX8Ec4R22vksA4E9xKbjCrOOQ5WOzG0a6SF32uU/MF8nMNvGHypoo+rNhz0TIO+MayKPkmZ4+DP9knzFti4fSzWwF/wWrH77vV0I/425317ikbynoCZaUXGwkvj0Ri5uxOC4eyiDOTSN9uWh2HRfIZOKUORcLQnSQQxmteHkFTc=" Mar 25 07:45:24 katarynka go-librespot[13089]: time="2026-03-25T07:45:24+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 07:45:24 katarynka go-librespot[13089]: time="2026-03-25T07:45:24+01:00" level=debug msg="completed keyexchange" Mar 25 07:45:24 katarynka go-librespot[13089]: time="2026-03-25T07:45:24+01:00" level=debug msg="completed challenge" Mar 25 07:45:24 katarynka go-librespot[13089]: time="2026-03-25T07:45:24+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 25 07:45:24 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 07:45:24 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 07:45:26 katarynka volumio[13007]: info: Starting UPNP Browser Mar 25 07:45:26 katarynka volumio[13007]: info: Loading plugin "alarm-clock"... Mar 25 07:45:26 katarynka volumio[13007]: info: Loading plugin "airplay_emulation"... Mar 25 07:45:26 katarynka volumio[13007]: info: Starting Shairport Sync Mar 25 07:45:26 katarynka volumio[13007]: info: Loading plugin "last_100"... Mar 25 07:45:26 katarynka volumio[13007]: info: Loading plugin "webradio"... Mar 25 07:45:26 katarynka volumio[13007]: info: Loading plugin "i2s_dacs"... Mar 25 07:45:26 katarynka volumio[13007]: info: Loading plugin "volumiodiscovery"... Mar 25 07:45:26 katarynka volumio[13007]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Mar 25 07:45:26 katarynka volumio[13007]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 25 07:45:26 katarynka volumio[13007]: *** WARNING *** For more information see Mar 25 07:45:26 katarynka volumio[13007]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Mar 25 07:45:26 katarynka volumio[13007]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 25 07:45:26 katarynka volumio[13007]: *** WARNING *** For more information see Mar 25 07:45:26 katarynka node[13007]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Mar 25 07:45:26 katarynka node[13007]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 25 07:45:26 katarynka node[13007]: *** WARNING *** For more information see Mar 25 07:45:26 katarynka node[13007]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Mar 25 07:45:26 katarynka node[13007]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 25 07:45:26 katarynka node[13007]: *** WARNING *** For more information see Mar 25 07:45:26 katarynka volumio[13007]: info: Applying required configuration parameters for plugin volumiodiscovery Mar 25 07:45:26 katarynka volumio[13007]: info: Discovery: Started advertising with name: katarynka Mar 25 07:45:26 katarynka volumio[13007]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 25 07:45:26 katarynka volumio[13007]: info: Loading plugin "spop"... Mar 25 07:45:27 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Mar 25 07:45:27 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 07:45:27 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 07:45:27 katarynka go-librespot[13098]: go-librespot daemon starting... Mar 25 07:45:27 katarynka go-librespot[13099]: time="2026-03-25T07:45:27+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 07:45:27 katarynka go-librespot[13099]: time="2026-03-25T07:45:27+01:00" level=debug msg="app state loaded" Mar 25 07:45:27 katarynka go-librespot[13099]: time="2026-03-25T07:45:27+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 07:45:28 katarynka go-librespot[13099]: time="2026-03-25T07:45:28+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 25 07:45:28 katarynka go-librespot[13099]: time="2026-03-25T07:45:28+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 25 07:45:28 katarynka go-librespot[13099]: time="2026-03-25T07:45:28+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 25 07:45:28 katarynka go-librespot[13099]: time="2026-03-25T07:45:28+01:00" level=info msg="zeroconf server listening on port 42485" Mar 25 07:45:28 katarynka go-librespot[13099]: time="2026-03-25T07:45:28+01:00" level=debug msg="obtained new client token: AACdyHQMIH5FTNXupMS7zEOBtoIIM/Vd5ej2uvFHd6lTErCQpzXmJ6I9Ieq5ogFVaO3t/Z2jLaimh0V/dbruSv9mEWSXheuYHNLGwPzBpuutUZn5tUBSKAOWTqrGVtDJZ9djPSNp3LiAAmtftLgv2Xvfv4kIkAcRkPwfHj98qmGwWsRttFlDXnsGw1uv454SYXMIe97siwKXPHAqyl8lX63198O0dt5THpgi09xscf3OkbP+X061L3nZqg4=" Mar 25 07:45:28 katarynka go-librespot[13099]: time="2026-03-25T07:45:28+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 07:45:28 katarynka go-librespot[13099]: time="2026-03-25T07:45:28+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: read tcp 192.168.100.107:38046->34.158.1.133:4070: read: connection reset by peer" Mar 25 07:45:28 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 07:45:28 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 07:45:28 katarynka volumio[13007]: info: Loading plugin "outputs"... Mar 25 07:45:28 katarynka volumio[13007]: info: Loading plugin "albumart"... Mar 25 07:45:28 katarynka volumio[13007]: info: Plugin example_plugin is not enabled Mar 25 07:45:28 katarynka volumio[13007]: info: Loading plugin "inputs"... Mar 25 07:45:29 katarynka volumio[13007]: info: Loading plugin "updater_comm"... Mar 25 07:45:29 katarynka volumio[13007]: info: Plugin mpdemulation is not enabled Mar 25 07:45:29 katarynka volumio[13007]: info: Loading plugin "rest_api"... Mar 25 07:45:29 katarynka volumio[13007]: info: Loading plugin "websocket"... Mar 25 07:45:29 katarynka volumio[13007]: info: Starting Socket.io Server version 1.7.4 Mar 25 07:45:29 katarynka volumio[13007]: info: Loading i18n strings for locale pl Mar 25 07:45:29 katarynka volumio[13007]: Updating browse sources language Mar 25 07:45:29 katarynka volumio[13007]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 25 07:45:29 katarynka volumio[13007]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 25 07:45:29 katarynka volumio[13007]: info: CoreCommandRouter::initPlayerControls Mar 25 07:45:29 katarynka volumio[13007]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 07:45:29 katarynka volumio[13007]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 07:45:29 katarynka volumio[13007]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 07:45:29 katarynka volumio[13007]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 07:45:29 katarynka volumio[13007]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 07:45:29 katarynka volumio[13007]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 07:45:29 katarynka volumio[13007]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 07:45:29 katarynka volumio[13007]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 07:45:29 katarynka volumio[13007]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 25 07:45:29 katarynka volumio[13007]: Express server listening on port 3000 Mar 25 07:45:29 katarynka volumio[13007]: [Metrics] WebUI: 12s 683.44ms Mar 25 07:45:29 katarynka volumio[13007]: info: CoreStateMachine::resetVolumioState Mar 25 07:45:29 katarynka volumio[13007]: info: CoreStateMachine::getcurrentVolume Mar 25 07:45:29 katarynka volumio[13007]: info: CoreCommandRouter::volumioRetrievevolume Mar 25 07:45:29 katarynka volumio[13007]: info: Cannot read play queue from file Mar 25 07:45:29 katarynka volumio[13007]: info: Volumio Network Manager: Network status updated: 2 Mar 25 07:45:30 katarynka volumio[13106]: Forking 3 albumart workers Mar 25 07:45:30 katarynka volumio[13007]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 07:45:30 katarynka volumio[13007]: info: Setting Device type: Raspberry PI Mar 25 07:45:30 katarynka volumio[13007]: info: CoreStateMachine::setRepeat null single undefined Mar 25 07:45:30 katarynka volumio[13007]: info: CoreStateMachine::pushState Mar 25 07:45:30 katarynka volumio[13007]: info: CorePlayQueue::getTrack 0 Mar 25 07:45:30 katarynka volumio[13007]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 25 07:45:30 katarynka volumio[13007]: info: CoreCommandRouter::volumioPushState Mar 25 07:45:30 katarynka volumio[13007]: info: CoreStateMachine::setRandom null Mar 25 07:45:30 katarynka volumio[13007]: info: CoreStateMachine::pushState Mar 25 07:45:30 katarynka volumio[13007]: info: CorePlayQueue::getTrack 0 Mar 25 07:45:30 katarynka volumio[13007]: info: CoreCommandRouter::volumioPushState Mar 25 07:45:30 katarynka volumio[13007]: info: Completed loading Core Plugins Mar 25 07:45:30 katarynka volumio[13007]: info: Preparing to generate the ALSA configuration file Mar 25 07:45:30 katarynka volumio[13007]: info: VolumeController:: Volume=96 Mute =false Mar 25 07:45:30 katarynka volumio[13007]: info: CoreStateMachine::pushState Mar 25 07:45:30 katarynka volumio[13007]: info: CorePlayQueue::getTrack 0 Mar 25 07:45:30 katarynka volumio[13007]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 25 07:45:30 katarynka volumio[13007]: info: CoreCommandRouter::volumioPushState Mar 25 07:45:30 katarynka volumio[13007]: info: CoreStateMachine::updateTrackBlock Mar 25 07:45:30 katarynka volumio[13007]: info: CorePlayQueue::getTrackBlock Mar 25 07:45:30 katarynka volumio[13007]: info: CoreCommandRouter::volumioRetrievevolume Mar 25 07:45:30 katarynka volumio[13007]: info: Asound.conf file unchanged, so no further update is needed Mar 25 07:45:30 katarynka volumio[13007]: info: Output device has changed, restarting MPD Mar 25 07:45:30 katarynka volumio[13007]: info: Output device has changed, restarting Shairport Sync Mar 25 07:45:30 katarynka volumio[13007]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 07:45:30 katarynka volumio[13007]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 07:45:30 katarynka sudo[13161]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 25 07:45:30 katarynka sudo[13161]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 07:45:30 katarynka sudo[13161]: pam_unix(sudo:session): session closed for user root Mar 25 07:45:30 katarynka sudo[13163]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 25 07:45:30 katarynka sudo[13163]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 07:45:30 katarynka volumio[13007]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 25 07:45:30 katarynka volumio[13007]: info: ___________ START PLUGINS ___________ Mar 25 07:45:30 katarynka volumio[13007]: info: ControllerMpd::onStart: Initializing MPD Mar 25 07:45:30 katarynka volumio[13007]: info: Creating MPD Configuration file Mar 25 07:45:30 katarynka systemd[1]: Stopping mpd.service - Music Player Daemon... Mar 25 07:45:30 katarynka volumio[13007]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 25 07:45:30 katarynka volumio[13007]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 25 07:45:30 katarynka volumio[13007]: info: [1774421130790] CoreMusicLibrary::Adding element Serwery Mediów Mar 25 07:45:30 katarynka volumio[13007]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 25 07:45:30 katarynka sudo[13173]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 25 07:45:30 katarynka sudo[13173]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 07:45:30 katarynka systemd[1]: mpd.service: Deactivated successfully. Mar 25 07:45:30 katarynka systemd[1]: Stopped mpd.service - Music Player Daemon. Mar 25 07:45:30 katarynka systemd[1]: mpd.service: Consumed 7.731s CPU time. Mar 25 07:45:30 katarynka volumio[13007]: info: UPNP Browser: Client initialized successfully Mar 25 07:45:30 katarynka sudo[13171]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 25 07:45:30 katarynka sudo[13171]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 07:45:30 katarynka systemd[1]: mpd.socket: Deactivated successfully. Mar 25 07:45:30 katarynka systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Mar 25 07:45:30 katarynka systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Mar 25 07:45:30 katarynka sudo[13171]: pam_unix(sudo:session): session closed for user root Mar 25 07:45:30 katarynka volumio[13007]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 07:45:30 katarynka volumio[13007]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 07:45:31 katarynka systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Mar 25 07:45:31 katarynka volumio[13007]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 25 07:45:31 katarynka volumio[13007]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 07:45:31 katarynka systemd[1]: Starting mpd.service - Music Player Daemon... Mar 25 07:45:31 katarynka volumio[13007]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 07:45:31 katarynka systemd[1]: mpd.service: Deactivated successfully. Mar 25 07:45:31 katarynka systemd[1]: Stopped mpd.service - Music Player Daemon. Mar 25 07:45:31 katarynka systemd[1]: mpd.socket: Deactivated successfully. Mar 25 07:45:31 katarynka systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Mar 25 07:45:31 katarynka systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Mar 25 07:45:31 katarynka systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Mar 25 07:45:31 katarynka systemd[1]: Starting mpd.service - Music Player Daemon... Mar 25 07:45:31 katarynka volumio[13007]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 25 07:45:31 katarynka volumio[13007]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 25 07:45:31 katarynka volumio[13007]: info: [1774421131219] CoreMusicLibrary::Adding element Last_100 Mar 25 07:45:31 katarynka volumio[13007]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 25 07:45:31 katarynka volumio[13007]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 25 07:45:31 katarynka volumio[13007]: info: [1774421131239] CoreMusicLibrary::Adding element Webradio Mar 25 07:45:31 katarynka volumio[13007]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 25 07:45:31 katarynka volumio[13007]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 25 07:45:31 katarynka volumio[13007]: info: Initializing BBC Radios Mar 25 07:45:31 katarynka volumio-remote-updater[622]: [2026-03-25 07:45:31] [connect] Successful connection Mar 25 07:45:31 katarynka volumio[13007]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 25 07:45:31 katarynka volumio[13007]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 07:45:31 katarynka volumio[13007]: info: Creating Spotify config file Mar 25 07:45:31 katarynka volumio[13007]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 07:45:31 katarynka sudo[13189]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Mar 25 07:45:31 katarynka sudo[13189]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Mar 25 07:45:31 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Mar 25 07:45:31 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 07:45:31 katarynka sudo[13189]: pam_unix(sudo:session): session closed for user root Mar 25 07:45:31 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 07:45:31 katarynka go-librespot[13204]: go-librespot daemon starting... Mar 25 07:45:31 katarynka go-librespot[13205]: time="2026-03-25T07:45:31+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 07:45:32 katarynka go-librespot[13205]: time="2026-03-25T07:45:32+01:00" level=info msg="zeroconf server listening on port 44251" Mar 25 07:45:32 katarynka volumio[13007]: info: Volumio Calling Home Mar 25 07:45:33 katarynka volumio[13007]: info: Discovery: adding 4d616d77-6a8c-4da2-85a4-840d70f98e51 Mar 25 07:45:33 katarynka volumio[13007]: info: Discovery: Found device katarynka Mar 25 07:45:33 katarynka sudo[13231]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 25 07:45:33 katarynka sudo[13231]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 07:45:33 katarynka volumio[13007]: info: CoreCommandRouter::volumioGetState Mar 25 07:45:33 katarynka volumio[13007]: info: CorePlayQueue::getTrack 0 Mar 25 07:45:33 katarynka sudo[13233]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 25 07:45:33 katarynka sudo[13233]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 07:45:34 katarynka sudo[13233]: pam_unix(sudo:session): session closed for user root Mar 25 07:45:34 katarynka sudo[13231]: pam_unix(sudo:session): session closed for user root Mar 25 07:45:34 katarynka volumio[13007]: info: MPD Permissions set Mar 25 07:45:34 katarynka volumio[13007]: info: MPD Permissions set Mar 25 07:45:34 katarynka volumio[13007]: info: VolumeController:: Volume=96 Mute =false Mar 25 07:45:34 katarynka volumio[13007]: info: CoreStateMachine::pushState Mar 25 07:45:34 katarynka volumio[13007]: info: CorePlayQueue::getTrack 0 Mar 25 07:45:34 katarynka volumio[13126]: Starting albumart workers Mar 25 07:45:34 katarynka volumio[13007]: info: CoreCommandRouter::volumioPushState Mar 25 07:45:34 katarynka volumio[13007]: info: Discovery: this is already registered, 4d616d77-6a8c-4da2-85a4-840d70f98e51 Mar 25 07:45:34 katarynka volumio[13007]: info: Discovery: Found device katarynka Mar 25 07:45:34 katarynka volumio[13007]: info: CoreCommandRouter::volumioGetState Mar 25 07:45:34 katarynka volumio[13007]: info: CorePlayQueue::getTrack 0 Mar 25 07:45:34 katarynka volumio-remote-updater[622]: [2026-03-25 07:45:34] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1774421131 101 Mar 25 07:45:34 katarynka volumio[13128]: Starting albumart workers Mar 25 07:45:34 katarynka volumio[13007]: 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 07:45:34 katarynka volumio[13123]: Starting albumart workers Mar 25 07:45:34 katarynka volumio[13007]: info: Volumio called home Mar 25 07:45:34 katarynka volumio[13007]: info: Spotify config file written Mar 25 07:45:34 katarynka sudo[13237]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Mar 25 07:45:34 katarynka sudo[13237]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 07:45:34 katarynka systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Mar 25 07:45:34 katarynka systemd[1]: go-librespot-daemon.service: Deactivated successfully. Mar 25 07:45:34 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 07:45:34 katarynka volumio[13007]: 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 07:45:34 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 07:45:34 katarynka go-librespot[13239]: go-librespot daemon starting... Mar 25 07:45:34 katarynka sudo[13237]: pam_unix(sudo:session): session closed for user root Mar 25 07:45:34 katarynka volumio[13007]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 07:45:34 katarynka go-librespot[13240]: time="2026-03-25T07:45:34+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 07:45:34 katarynka go-librespot[13240]: time="2026-03-25T07:45:34+01:00" level=debug msg="app state loaded" Mar 25 07:45:34 katarynka go-librespot[13240]: time="2026-03-25T07:45:34+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 07:45:34 katarynka volumio[13007]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 07:45:34 katarynka volumio[13007]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 07:45:34 katarynka volumio[13007]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 07:45:34 katarynka volumio[13007]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 07:45:34 katarynka volumio[13007]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 07:45:34 katarynka volumio[13007]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 07:45:34 katarynka volumio[13007]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 07:45:35 katarynka volumio[13007]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 07:45:35 katarynka volumio[13007]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 07:45:35 katarynka volumio[13007]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 07:45:35 katarynka volumio[13007]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 07:45:35 katarynka volumio[13007]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 07:45:35 katarynka volumio[13007]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 07:45:35 katarynka volumio[13007]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 07:45:35 katarynka volumio[13007]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 07:45:35 katarynka volumio[13007]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 07:45:35 katarynka volumio[13007]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 07:45:35 katarynka volumio[13007]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 07:45:35 katarynka volumio[13007]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 07:45:35 katarynka volumio[13007]: info: No need to fix Spotify hosts Mar 25 07:45:35 katarynka go-librespot[13240]: time="2026-03-25T07:45:35+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 25 07:45:35 katarynka go-librespot[13240]: time="2026-03-25T07:45:35+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 25 07:45:35 katarynka go-librespot[13240]: time="2026-03-25T07:45:35+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 25 07:45:35 katarynka go-librespot[13240]: time="2026-03-25T07:45:35+01:00" level=info msg="zeroconf server listening on port 40703" Mar 25 07:45:35 katarynka go-librespot[13240]: time="2026-03-25T07:45:35+01:00" level=debug msg="obtained new client token: AABBbbH5/n3ovpqWQ573V0VVMDAnVWja9+95veq10L9v37ENoCfQWHYKOvsXzJT+30Q0TaYQHkygyiKjovGzcTqkWA7+WS67wg35J96eNFc+xTpJ3yOkONHmhIGzBoSpMrkxsz3XfHGSr0FqQQtKaA+Fw7K+tEkLlzlc81aagGQ0IlDSfYm6S7yYhw5n6qFNGYNc+qAqg2rsovcwJP47phLBsp+DClAXsX/Hl6Q0+sDD+M3ztFIGeY7sY/A=" Mar 25 07:45:35 katarynka go-librespot[13240]: time="2026-03-25T07:45:35+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 07:45:35 katarynka go-librespot[13240]: time="2026-03-25T07:45:35+01:00" level=debug msg="completed keyexchange" Mar 25 07:45:35 katarynka go-librespot[13240]: time="2026-03-25T07:45:35+01:00" level=debug msg="completed challenge" Mar 25 07:45:35 katarynka go-librespot[13240]: time="2026-03-25T07:45:35+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 25 07:45:35 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 07:45:35 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 07:45:35 katarynka volumio[13007]: info: Starting Shairport Sync Mar 25 07:45:35 katarynka volumio[13007]: info: Starting Shairport Sync Mar 25 07:45:36 katarynka volumio[13007]: info: Starting Shairport Sync Mar 25 07:45:36 katarynka sudo[13264]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 25 07:45:36 katarynka sudo[13264]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 07:45:36 katarynka sudo[13268]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 25 07:45:36 katarynka sudo[13268]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 07:45:36 katarynka sudo[13266]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 25 07:45:36 katarynka sudo[13266]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 07:45:36 katarynka sudo[13270]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Mar 25 07:45:36 katarynka sudo[13270]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 07:45:36 katarynka systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Mar 25 07:45:36 katarynka systemd[1]: shairport-sync.service: Deactivated successfully. Mar 25 07:45:36 katarynka systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 25 07:45:36 katarynka systemd[1]: shairport-sync.service: Consumed 2.309s CPU time. Mar 25 07:45:36 katarynka sudo[13270]: pam_unix(sudo:session): session closed for user root Mar 25 07:45:36 katarynka volumio[13007]: info: Upmpdcli Daemon Started Mar 25 07:45:36 katarynka systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 25 07:45:36 katarynka sudo[13264]: pam_unix(sudo:session): session closed for user root Mar 25 07:45:36 katarynka sudo[13266]: pam_unix(sudo:session): session closed for user root Mar 25 07:45:36 katarynka volumio[13007]: info: An error occurred while refreshing Spotify Token Error: Bad Request Mar 25 07:45:36 katarynka volumio[13007]: info: CoreCommandRouter::volumioGetState Mar 25 07:45:36 katarynka volumio[13007]: info: CorePlayQueue::getTrack 0 Mar 25 07:45:36 katarynka sudo[13268]: pam_unix(sudo:session): session closed for user root Mar 25 07:45:36 katarynka volumio[13007]: info: Shairport-Sync Started Mar 25 07:45:36 katarynka volumio[13007]: Error adding Membership: Error: addMembership EINVAL Mar 25 07:45:36 katarynka volumio[13007]: info: Shairport-Sync Started Mar 25 07:45:36 katarynka volumio[13007]: info: Shairport-Sync Started Mar 25 07:45:38 katarynka volumio[13007]: info: go-librespot daemon successfully initialized Mar 25 07:45:39 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Mar 25 07:45:39 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 07:45:39 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 07:45:39 katarynka go-librespot[13303]: go-librespot daemon starting... Mar 25 07:45:39 katarynka go-librespot[13304]: time="2026-03-25T07:45:39+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 07:45:39 katarynka go-librespot[13304]: time="2026-03-25T07:45:39+01:00" level=debug msg="app state loaded" Mar 25 07:45:39 katarynka go-librespot[13304]: time="2026-03-25T07:45:39+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 07:45:39 katarynka mpd[13206]: 2026-03-25T07:45:39 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Mar 25 07:45:39 katarynka systemd[1]: Started mpd.service - Music Player Daemon. Mar 25 07:45:39 katarynka sudo[13163]: pam_unix(sudo:session): session closed for user root Mar 25 07:45:39 katarynka sudo[13173]: pam_unix(sudo:session): session closed for user root Mar 25 07:45:39 katarynka volumio[13007]: info: Completed starting Core Plugins Mar 25 07:45:39 katarynka volumio[13007]: info: ------------------------------------------- Mar 25 07:45:39 katarynka volumio[13007]: info: ----- MyVolumio plugins startup ---- Mar 25 07:45:39 katarynka volumio[13007]: info: ------------------------------------------- Mar 25 07:45:39 katarynka volumio[13007]: info: [MyVolumio PluginManager] Fetching plans data.... Mar 25 07:45:39 katarynka volumio[13007]: error: MPD error: The expression evaluated to a falsy value: Mar 25 07:45:39 katarynka volumio[13007]: assert.ok(self.idling) Mar 25 07:45:39 katarynka volumio[13007]: error: The expression evaluated to a falsy value: Mar 25 07:45:39 katarynka volumio[13007]: assert.ok(self.idling) Mar 25 07:45:39 katarynka volumio[13007]: info: MPD running with PID13206 Mar 25 07:45:39 katarynka volumio[13007]: ,establishing connection Mar 25 07:45:39 katarynka volumio[13007]: error: updateQueue error: null Mar 25 07:45:39 katarynka volumio[13007]: error: updateQueue error: null Mar 25 07:45:39 katarynka go-librespot[13304]: time="2026-03-25T07:45: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-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 25 07:45:39 katarynka go-librespot[13304]: time="2026-03-25T07:45:39+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 07:45:39 katarynka go-librespot[13304]: time="2026-03-25T07:45:39+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 07:45:39 katarynka go-librespot[13304]: time="2026-03-25T07:45:39+01:00" level=info msg="zeroconf server listening on port 41501" Mar 25 07:45:39 katarynka go-librespot[13304]: time="2026-03-25T07:45:39+01:00" level=debug msg="obtained new client token: AAC25WWNESKbR1LGVd/0KCRsWrUPD+VBYFmAUmxHnue/1njuaQa+7/m3bP7s4a80ro6dxVV7HwlCXQL5Ee+7pq+NnVQ6PKKwF3eom1AxGQT1lOtNGNNwroLmQkDo1/D5Bvq0pSScG8C0P6bfScx2Uobafs6OVKo9tpA53akYY3UcunZ6A76qfmjb429WjT/I/7yuVVsXav7EnYBTMZfm4vw+5Zj2NXClJBV/r7widmvCgaiR35jtthfzIsw=" Mar 25 07:45:39 katarynka go-librespot[13304]: time="2026-03-25T07:45:39+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 07:45:40 katarynka go-librespot[13304]: time="2026-03-25T07:45:40+01:00" level=debug msg="completed keyexchange" Mar 25 07:45:40 katarynka go-librespot[13304]: time="2026-03-25T07:45:40+01:00" level=debug msg="completed challenge" Mar 25 07:45:40 katarynka go-librespot[13304]: time="2026-03-25T07:45:40+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 25 07:45:40 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 07:45:40 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 07:45:41 katarynka volumio[13007]: info: Initializing connection to go-librespot Websocket Mar 25 07:45:41 katarynka volumio[13007]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 25 07:45:42 katarynka sudo[13331]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Mar 25 07:45:42 katarynka sudo[13331]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 07:45:42 katarynka sudo[13333]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Mar 25 07:45:42 katarynka sudo[13333]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 07:45:42 katarynka systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Mar 25 07:45:42 katarynka systemd[1]: mpd_monitor.service: Deactivated successfully. Mar 25 07:45:42 katarynka systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Mar 25 07:45:42 katarynka systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Mar 25 07:45:42 katarynka sudo[13331]: pam_unix(sudo:session): session closed for user root Mar 25 07:45:42 katarynka sudo[13333]: pam_unix(sudo:session): session closed for user root Mar 25 07:45:42 katarynka mpd_monitor.sh[13336]: MPD Monitor Service: Starting MPD Monitor Service Mar 25 07:45:42 katarynka volumio[13007]: info: Successfully started MPD Monitor Mar 25 07:45:42 katarynka volumio[13007]: info: Successfully started MPD Monitor Mar 25 07:45:43 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Mar 25 07:45:43 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 07:45:43 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 07:45:43 katarynka go-librespot[13340]: go-librespot daemon starting... Mar 25 07:45:43 katarynka go-librespot[13341]: time="2026-03-25T07:45:43+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 07:45:43 katarynka go-librespot[13341]: time="2026-03-25T07:45:43+01:00" level=debug msg="app state loaded" Mar 25 07:45:43 katarynka go-librespot[13341]: time="2026-03-25T07:45:43+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 07:45:43 katarynka go-librespot[13341]: time="2026-03-25T07:45:43+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 25 07:45:43 katarynka go-librespot[13341]: time="2026-03-25T07:45:43+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 07:45:43 katarynka go-librespot[13341]: time="2026-03-25T07:45:43+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 07:45:43 katarynka go-librespot[13341]: time="2026-03-25T07:45:43+01:00" level=info msg="zeroconf server listening on port 37019" Mar 25 07:45:43 katarynka go-librespot[13341]: time="2026-03-25T07:45:43+01:00" level=debug msg="obtained new client token: AABaMKmQBpBxK9w397/keO4MlgBj0vSoUFmJ9zERiPeDKtdsQBaeqw9dn7MybOqQZ+iYQ4nUnAFWAw1gB6ebwu5eO8AFYTDySNwNX6Kp6BKgXvYomNkMkLES2JAe95AcbG4LOHE3Ek7Ml/jN1jCmklG1oOpjCez53VA48xva5vdgOWYUcI5BjZETPcda5MZYFO2qLR7ajxl4mjBNeBo4XgDutPRdqI8itBBC767lZlTkq5+iybuAgLhBU5M=" Mar 25 07:45:43 katarynka go-librespot[13341]: time="2026-03-25T07:45:43+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 07:45:43 katarynka go-librespot[13341]: time="2026-03-25T07:45:43+01:00" level=debug msg="completed keyexchange" Mar 25 07:45:43 katarynka go-librespot[13341]: time="2026-03-25T07:45:43+01:00" level=debug msg="completed challenge" Mar 25 07:45:43 katarynka go-librespot[13341]: time="2026-03-25T07:45: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 07:45:44 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 07:45:44 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 07:45:44 katarynka volumio[13007]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Mar 25 07:45:44 katarynka volumio[13007]: info: Initializing connection to go-librespot Websocket Mar 25 07:45:44 katarynka volumio[13007]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 25 07:45:47 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Mar 25 07:45:47 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 07:45:47 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 07:45:47 katarynka go-librespot[13348]: go-librespot daemon starting... Mar 25 07:45:47 katarynka go-librespot[13349]: time="2026-03-25T07:45:47+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 07:45:47 katarynka go-librespot[13349]: time="2026-03-25T07:45:47+01:00" level=debug msg="app state loaded" Mar 25 07:45:47 katarynka go-librespot[13349]: time="2026-03-25T07:45:47+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 07:45:47 katarynka go-librespot[13349]: time="2026-03-25T07:45: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-gae2.spotify.com:80]" Mar 25 07:45:47 katarynka go-librespot[13349]: time="2026-03-25T07:45:47+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 07:45:47 katarynka go-librespot[13349]: time="2026-03-25T07:45:47+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 07:45:47 katarynka go-librespot[13349]: time="2026-03-25T07:45:47+01:00" level=info msg="zeroconf server listening on port 37285" Mar 25 07:45:47 katarynka volumio[13007]: info: Initializing connection to go-librespot Websocket Mar 25 07:45:47 katarynka go-librespot[13349]: time="2026-03-25T07:45:47+01:00" level=debug msg="new websocket client" Mar 25 07:45:47 katarynka volumio[13007]: info: Connection to go-librespot Websocket established Mar 25 07:45:47 katarynka volumio[13007]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Mar 25 07:45:47 katarynka volumio[13007]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Mar 25 07:45:47 katarynka volumio[13007]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Mar 25 07:45:47 katarynka volumio[13007]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Mar 25 07:45:47 katarynka volumio[13007]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Mar 25 07:45:47 katarynka volumio[13007]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Mar 25 07:45:47 katarynka volumio[13007]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Mar 25 07:45:47 katarynka volumio[13007]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Mar 25 07:45:47 katarynka volumio[13007]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Mar 25 07:45:47 katarynka volumio[13007]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Mar 25 07:45:47 katarynka volumio[13007]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Mar 25 07:45:47 katarynka volumio[13007]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Mar 25 07:45:47 katarynka volumio[13007]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Mar 25 07:45:47 katarynka volumio[13007]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Mar 25 07:45:47 katarynka volumio[13007]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Mar 25 07:45:47 katarynka volumio[13007]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Mar 25 07:45:47 katarynka volumio[13007]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Mar 25 07:45:47 katarynka volumio[13007]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Mar 25 07:45:47 katarynka volumio[13007]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Mar 25 07:45:47 katarynka volumio[13007]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Mar 25 07:45:47 katarynka volumio[13007]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Mar 25 07:45:47 katarynka volumio[13007]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Mar 25 07:45:47 katarynka volumio[13007]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Mar 25 07:45:47 katarynka volumio[13007]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Mar 25 07:45:47 katarynka volumio[13007]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Mar 25 07:45:47 katarynka volumio[13007]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Mar 25 07:45:47 katarynka volumio[13007]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Mar 25 07:45:47 katarynka volumio[13007]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Mar 25 07:45:47 katarynka go-librespot[13349]: time="2026-03-25T07:45:47+01:00" level=debug msg="obtained new client token: AACh4vlhcHuBb4obXEQLnvEo+s1JeICmsR5uqqVOahFVfy/6xCU0MAiWovLP1mBZmGSyY5axSRNVrZYIRupYy+Sw1k3x4Y0hbBU8TG/d1+xQfCTpf/f3t+Hp4LwusmRYgUQB9U3HqHX7XOdlUUMwQMhOI/t0OjW67gmYck3bppmspzERmtu4aoS1kfiVGZn6t9fLGhSYxF0PUcelDyhovYM8zjcjDCPmaMT9PjbdRty84C9N45L5HynqGdA=" Mar 25 07:45:47 katarynka volumio[13007]: info: Adding plugin bluetooth to MyMusic Plugins Mar 25 07:45:47 katarynka volumio[13007]: info: Adding plugin multiroom to MyMusic Plugins Mar 25 07:45:47 katarynka volumio[13007]: info: Adding plugin metavolumio to MyMusic Plugins Mar 25 07:45:47 katarynka volumio[13007]: info: Adding plugin cd_controller to MyMusic Plugins Mar 25 07:45:47 katarynka volumio[13007]: info: Adding plugin qobuzconnect to MyMusic Plugins Mar 25 07:45:47 katarynka volumio[13007]: info: Adding plugin smart_inputs to MyMusic Plugins Mar 25 07:45:47 katarynka volumio[13007]: info: Adding plugin tidalconnect to MyMusic Plugins Mar 25 07:45:47 katarynka volumio[13007]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Mar 25 07:45:47 katarynka go-librespot[13349]: time="2026-03-25T07:45:47+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 07:45:47 katarynka go-librespot[13349]: time="2026-03-25T07:45:47+01:00" level=debug msg="completed keyexchange" Mar 25 07:45:47 katarynka go-librespot[13349]: time="2026-03-25T07:45:47+01:00" level=debug msg="completed challenge" Mar 25 07:45:48 katarynka go-librespot[13349]: time="2026-03-25T07:45:48+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 25 07:45:48 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 07:45:48 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 07:45:49 katarynka volumio[13007]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Mar 25 07:45:49 katarynka volumio[13007]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Mar 25 07:45:49 katarynka volumio[13007]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 07:45:49 katarynka volumio[13007]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 07:45:49 katarynka volumio[13007]: info: Starting MyVolumio Remote Streaming Endpoints Mar 25 07:45:49 katarynka volumio[13007]: info: MyVolumio login type: Token Mar 25 07:45:50 katarynka volumio[13007]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Mar 25 07:45:50 katarynka volumio[13007]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Mar 25 07:45:51 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Mar 25 07:45:51 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 07:45:51 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 07:45:51 katarynka go-librespot[13357]: go-librespot daemon starting... Mar 25 07:45:51 katarynka go-librespot[13358]: time="2026-03-25T07:45:51+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 07:45:51 katarynka go-librespot[13358]: time="2026-03-25T07:45:51+01:00" level=debug msg="app state loaded" Mar 25 07:45:51 katarynka go-librespot[13358]: time="2026-03-25T07:45:51+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 07:45:51 katarynka go-librespot[13358]: time="2026-03-25T07:45: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 07:45:51 katarynka go-librespot[13358]: time="2026-03-25T07:45: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 07:45:51 katarynka go-librespot[13358]: time="2026-03-25T07:45: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 07:45:51 katarynka go-librespot[13358]: time="2026-03-25T07:45:51+01:00" level=info msg="zeroconf server listening on port 45929" Mar 25 07:45:51 katarynka volumio[13007]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Mar 25 07:45:51 katarynka volumio[13007]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Mar 25 07:45:51 katarynka volumio[13007]: info: Streaming services startup Mar 25 07:45:51 katarynka volumio[13007]: info: Starting Streaming Daemon Mar 25 07:45:51 katarynka sudo[13366]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Mar 25 07:45:51 katarynka go-librespot[13358]: time="2026-03-25T07:45:51+01:00" level=debug msg="obtained new client token: AABWG/tT7R7Ms0mWvp6HtAFBheNQQAqcQ6F1iYXEQKgwigmL2lW02HphD8zf8SPvDj2bAtyuPl76d7FGASAyxWAH0XIC6X0pZEcwtHtnSwuy+vRpxFQhH1/25fF31eR0xNCS8URYhQqyFlPOElcAQbMYHba/ocrPSeMZea0YFjNmblTze6CF97SP/RG2IfUVkYZr32hQlj+RuJE6q5rXxGY0om4HW6Xo4Kqp0GVNDgEn3I8H712cYvf49Ss=" Mar 25 07:45:51 katarynka sudo[13366]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 07:45:51 katarynka volumio[13007]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Mar 25 07:45:51 katarynka go-librespot[13358]: time="2026-03-25T07:45:51+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 07:45:51 katarynka sudo[13366]: pam_unix(sudo:session): session closed for user root Mar 25 07:45:52 katarynka go-librespot[13358]: time="2026-03-25T07:45:52+01:00" level=debug msg="completed keyexchange" Mar 25 07:45:52 katarynka go-librespot[13358]: time="2026-03-25T07:45:52+01:00" level=debug msg="completed challenge" Mar 25 07:45:52 katarynka volumio[13007]: info: Getting Spotify volume Mar 25 07:45:52 katarynka go-librespot[13358]: time="2026-03-25T07:45:52+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 25 07:45:52 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 07:45:52 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 07:45:52 katarynka volumio[13007]: info: Connection to go-librespot Websocket closed Mar 25 07:45:52 katarynka volumio[13007]: error: Cannot start Volumio Streaming Daemon Mar 25 07:45:52 katarynka volumio[13007]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Mar 25 07:45:52 katarynka volumio[13007]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Mar 25 07:45:52 katarynka volumio[13007]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 25 07:45:52 katarynka volumio[13007]: Error: socket hang up Mar 25 07:45:52 katarynka volumio[13007]: at connResetException (node:internal/errors:720:14) Mar 25 07:45:52 katarynka volumio[13007]: at Socket.socketOnEnd (node:_http_client:519:23) Mar 25 07:45:52 katarynka volumio[13007]: at Socket.emit (node:events:526:35) Mar 25 07:45:52 katarynka volumio[13007]: at endReadableNT (node:internal/streams/readable:1376:12) Mar 25 07:45:52 katarynka volumio[13007]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Mar 25 07:45:52 katarynka volumio[13007]: code: 'ECONNRESET', Mar 25 07:45:52 katarynka volumio[13007]: response: undefined Mar 25 07:45:52 katarynka volumio[13007]: } Mar 25 07:45:52 katarynka volumio[13007]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 25 07:45:53 katarynka sudo[13401]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-03-25 07:44' Mar 25 07:45:53 katarynka sudo[13401]: 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"