Mar 25 19:08:00 katarynka volumio[9802]: info: Loading plugin "outputs"... Mar 25 19:08:00 katarynka volumio[9802]: info: Loading plugin "albumart"... Mar 25 19:08:00 katarynka volumio[9802]: info: Plugin example_plugin is not enabled Mar 25 19:08:00 katarynka volumio[9802]: info: Loading plugin "inputs"... Mar 25 19:08:00 katarynka volumio[9802]: info: Loading plugin "updater_comm"... Mar 25 19:08:00 katarynka volumio[9802]: info: Plugin mpdemulation is not enabled Mar 25 19:08:00 katarynka volumio[9802]: info: Loading plugin "rest_api"... Mar 25 19:08:00 katarynka volumio[9802]: info: Loading plugin "websocket"... Mar 25 19:08:00 katarynka volumio[9802]: info: Starting Socket.io Server version 1.7.4 Mar 25 19:08:00 katarynka volumio[9802]: info: Loading i18n strings for locale pl Mar 25 19:08:00 katarynka volumio[9802]: Updating browse sources language Mar 25 19:08:00 katarynka volumio[9802]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 25 19:08:00 katarynka volumio[9802]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 25 19:08:00 katarynka volumio[9802]: info: CoreCommandRouter::initPlayerControls Mar 25 19:08:00 katarynka volumio[9802]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 19:08:00 katarynka volumio[9802]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 19:08:00 katarynka volumio[9802]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 19:08:00 katarynka volumio[9802]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 19:08:00 katarynka volumio[9802]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 19:08:00 katarynka volumio[9802]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 19:08:00 katarynka volumio[9802]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 19:08:00 katarynka volumio[9802]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 19:08:00 katarynka volumio[9802]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 25 19:08:00 katarynka volumio[9802]: Express server listening on port 3000 Mar 25 19:08:00 katarynka volumio[9802]: [Metrics] WebUI: 12s 476.67ms Mar 25 19:08:00 katarynka volumio[9802]: info: CoreStateMachine::resetVolumioState Mar 25 19:08:00 katarynka volumio[9802]: info: CoreStateMachine::getcurrentVolume Mar 25 19:08:00 katarynka volumio[9802]: info: CoreCommandRouter::volumioRetrievevolume Mar 25 19:08:00 katarynka volumio[9802]: info: Cannot read play queue from file Mar 25 19:08:01 katarynka volumio[9802]: info: Volumio Network Manager: Network status updated: 2 Mar 25 19:08:01 katarynka volumio[9802]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 19:08:01 katarynka volumio[9896]: Forking 3 albumart workers Mar 25 19:08:01 katarynka volumio[9802]: info: CoreStateMachine::setRepeat null single undefined Mar 25 19:08:01 katarynka volumio[9802]: info: CoreStateMachine::pushState Mar 25 19:08:01 katarynka volumio[9802]: info: CorePlayQueue::getTrack 0 Mar 25 19:08:01 katarynka volumio[9802]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 25 19:08:01 katarynka volumio[9802]: info: CoreCommandRouter::volumioPushState Mar 25 19:08:01 katarynka volumio[9802]: info: CoreStateMachine::setRandom null Mar 25 19:08:01 katarynka volumio[9802]: info: CoreStateMachine::pushState Mar 25 19:08:01 katarynka volumio[9802]: info: CorePlayQueue::getTrack 0 Mar 25 19:08:01 katarynka volumio[9802]: info: CoreCommandRouter::volumioPushState Mar 25 19:08:01 katarynka volumio[9802]: info: Setting Device type: Raspberry PI Mar 25 19:08:01 katarynka volumio[9802]: info: Completed loading Core Plugins Mar 25 19:08:01 katarynka volumio[9802]: info: Preparing to generate the ALSA configuration file Mar 25 19:08:01 katarynka volumio[9802]: info: VolumeController:: Volume=96 Mute =false Mar 25 19:08:01 katarynka volumio[9802]: info: CoreStateMachine::pushState Mar 25 19:08:01 katarynka volumio[9802]: info: CorePlayQueue::getTrack 0 Mar 25 19:08:01 katarynka volumio[9802]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 25 19:08:01 katarynka volumio[9802]: info: CoreCommandRouter::volumioPushState Mar 25 19:08:01 katarynka volumio[9802]: info: CoreStateMachine::updateTrackBlock Mar 25 19:08:01 katarynka volumio[9802]: info: CorePlayQueue::getTrackBlock Mar 25 19:08:01 katarynka volumio[9802]: info: CoreCommandRouter::volumioRetrievevolume Mar 25 19:08:01 katarynka volumio[9802]: info: Asound.conf file unchanged, so no further update is needed Mar 25 19:08:01 katarynka volumio[9802]: info: Output device has changed, restarting MPD Mar 25 19:08:01 katarynka volumio[9802]: info: Output device has changed, restarting Shairport Sync Mar 25 19:08:01 katarynka volumio[9802]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 19:08:01 katarynka volumio[9802]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 19:08:01 katarynka sudo[9949]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 25 19:08:01 katarynka sudo[9949]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 19:08:01 katarynka volumio[9802]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 25 19:08:01 katarynka volumio[9802]: info: ___________ START PLUGINS ___________ Mar 25 19:08:01 katarynka volumio[9802]: info: ControllerMpd::onStart: Initializing MPD Mar 25 19:08:01 katarynka volumio[9802]: info: Creating MPD Configuration file Mar 25 19:08:01 katarynka sudo[9949]: pam_unix(sudo:session): session closed for user root Mar 25 19:08:01 katarynka sudo[9953]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 25 19:08:01 katarynka sudo[9953]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 19:08:01 katarynka volumio[9802]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 25 19:08:01 katarynka volumio[9802]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 25 19:08:01 katarynka volumio[9802]: info: [1774462081813] CoreMusicLibrary::Adding element Serwery Mediów Mar 25 19:08:01 katarynka volumio[9802]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 25 19:08:01 katarynka volumio[9802]: info: UPNP Browser: Client initialized successfully Mar 25 19:08:01 katarynka volumio[9802]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 19:08:01 katarynka volumio[9802]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 19:08:01 katarynka sudo[9960]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 25 19:08:01 katarynka sudo[9960]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 19:08:01 katarynka sudo[9963]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 25 19:08:01 katarynka sudo[9963]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 19:08:01 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 28. Mar 25 19:08:01 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 19:08:01 katarynka volumio[9802]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 25 19:08:01 katarynka sudo[9960]: pam_unix(sudo:session): session closed for user root Mar 25 19:08:01 katarynka volumio[9802]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 19:08:01 katarynka volumio[9802]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 19:08:02 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 19:08:02 katarynka go-librespot[9970]: go-librespot daemon starting... Mar 25 19:08:02 katarynka upmpdcli[1473]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Mar 25 19:08:02 katarynka systemd[1]: Stopping mpd.service - Music Player Daemon... Mar 25 19:08:02 katarynka go-librespot[9975]: time="2026-03-25T19:08:02+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 19:08:02 katarynka go-librespot[9975]: time="2026-03-25T19:08:02+01:00" level=debug msg="app state loaded" Mar 25 19:08:02 katarynka go-librespot[9975]: time="2026-03-25T19:08:02+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 19:08:02 katarynka volumio[9802]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 25 19:08:02 katarynka volumio[9802]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 25 19:08:02 katarynka volumio[9802]: info: [1774462082151] CoreMusicLibrary::Adding element Last_100 Mar 25 19:08:02 katarynka volumio[9802]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 25 19:08:02 katarynka systemd[1]: mpd.service: Deactivated successfully. Mar 25 19:08:02 katarynka volumio[9802]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 25 19:08:02 katarynka volumio[9802]: info: [1774462082163] CoreMusicLibrary::Adding element Webradio Mar 25 19:08:02 katarynka volumio[9802]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 25 19:08:02 katarynka systemd[1]: Stopped mpd.service - Music Player Daemon. Mar 25 19:08:02 katarynka systemd[1]: mpd.service: Consumed 7.873s CPU time. Mar 25 19:08:02 katarynka systemd[1]: mpd.socket: Deactivated successfully. Mar 25 19:08:02 katarynka systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Mar 25 19:08:02 katarynka systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Mar 25 19:08:02 katarynka volumio[9802]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 25 19:08:02 katarynka volumio[9802]: info: Initializing BBC Radios Mar 25 19:08:02 katarynka systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Mar 25 19:08:02 katarynka systemd[1]: Starting mpd.service - Music Player Daemon... Mar 25 19:08:02 katarynka volumio[9802]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 25 19:08:02 katarynka volumio[9802]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 19:08:02 katarynka volumio[9802]: info: Creating Spotify config file Mar 25 19:08:02 katarynka volumio[9802]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 19:08:02 katarynka sudo[9993]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Mar 25 19:08:02 katarynka sudo[9993]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Mar 25 19:08:02 katarynka sudo[9993]: pam_unix(sudo:session): session closed for user root Mar 25 19:08:02 katarynka volumio-remote-updater[686]: [2026-03-25 19:08:02] [connect] Successful connection Mar 25 19:08:03 katarynka go-librespot[9975]: time="2026-03-25T19:08: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-gew1.spotify.com:80]" Mar 25 19:08:03 katarynka go-librespot[9975]: time="2026-03-25T19:08:03+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 19:08:03 katarynka go-librespot[9975]: time="2026-03-25T19:08:03+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 19:08:03 katarynka go-librespot[9975]: time="2026-03-25T19:08:03+01:00" level=info msg="zeroconf server listening on port 36837" Mar 25 19:08:03 katarynka go-librespot[9975]: time="2026-03-25T19:08:03+01:00" level=debug msg="obtained new client token: AADdKAM79iwOxMdCG1x47oNOksUzBrwRS2/HW8TGfQA7SKPv3b9vnZtZ/YrhujQDcHwVsdba0r+V3aGCRPLLeDxMgDwRQ+bmXkcM27z7cXf8fLomcWNaCGfkqUJq7fAZKsXxH3ohGUKQvGT0rVqKVtxg3h89aSD3hpPjZST88f8EnpXnWVBgHIY7N8Yf8MarmsVz3Loy9s5OTsfFczYlO+bp6LCoLnkC6uPhU14phZE8NyIoxCdKlB1vXW8=" Mar 25 19:08:03 katarynka volumio[9802]: info: Volumio Calling Home Mar 25 19:08:03 katarynka go-librespot[9975]: time="2026-03-25T19:08:03+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 19:08:04 katarynka go-librespot[9975]: time="2026-03-25T19:08:04+01:00" level=debug msg="completed keyexchange" Mar 25 19:08:04 katarynka go-librespot[9975]: time="2026-03-25T19:08:04+01:00" level=debug msg="completed challenge" Mar 25 19:08:04 katarynka go-librespot[9975]: time="2026-03-25T19:08:04+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 25 19:08:04 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 19:08:04 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 19:08:04 katarynka volumio[9802]: info: Discovery: adding 4d616d77-6a8c-4da2-85a4-840d70f98e51 Mar 25 19:08:04 katarynka volumio[9802]: info: Discovery: Found device katarynka Mar 25 19:08:04 katarynka sudo[10021]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 25 19:08:04 katarynka volumio[9802]: info: CoreCommandRouter::volumioGetState Mar 25 19:08:04 katarynka sudo[10021]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 19:08:04 katarynka volumio[9802]: info: CorePlayQueue::getTrack 0 Mar 25 19:08:04 katarynka sudo[10023]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 25 19:08:04 katarynka sudo[10023]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 19:08:04 katarynka sudo[10021]: pam_unix(sudo:session): session closed for user root Mar 25 19:08:04 katarynka volumio[9802]: info: MPD Permissions set Mar 25 19:08:04 katarynka volumio[9802]: info: MPD Permissions set Mar 25 19:08:04 katarynka volumio[9802]: info: VolumeController:: Volume=96 Mute =false Mar 25 19:08:04 katarynka volumio[9802]: info: CoreStateMachine::pushState Mar 25 19:08:04 katarynka volumio[9802]: info: CorePlayQueue::getTrack 0 Mar 25 19:08:04 katarynka volumio[9802]: info: CoreCommandRouter::volumioPushState Mar 25 19:08:04 katarynka sudo[10023]: pam_unix(sudo:session): session closed for user root Mar 25 19:08:04 katarynka volumio[9802]: info: Discovery: this is already registered, 4d616d77-6a8c-4da2-85a4-840d70f98e51 Mar 25 19:08:04 katarynka volumio[9802]: info: Discovery: Found device katarynka Mar 25 19:08:04 katarynka volumio[9802]: info: CoreCommandRouter::volumioGetState Mar 25 19:08:04 katarynka volumio[9802]: info: CorePlayQueue::getTrack 0 Mar 25 19:08:04 katarynka volumio-remote-updater[686]: [2026-03-25 19:08:04] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1774462082 101 Mar 25 19:08:04 katarynka volumio[9802]: 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 19:08:04 katarynka volumio[9802]: info: Volumio called home Mar 25 19:08:04 katarynka volumio[9802]: info: Spotify config file written Mar 25 19:08:04 katarynka volumio[9802]: 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 19:08:04 katarynka sudo[10027]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Mar 25 19:08:04 katarynka sudo[10027]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 19:08:04 katarynka volumio[9802]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 19:08:05 katarynka volumio[9802]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 19:08:05 katarynka volumio[9802]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 19:08:05 katarynka volumio[9802]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 19:08:05 katarynka volumio[9802]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 19:08:05 katarynka volumio[9802]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 19:08:05 katarynka volumio[9802]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 19:08:05 katarynka volumio[9802]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 19:08:05 katarynka volumio[9802]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 19:08:05 katarynka volumio[9802]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 19:08:05 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 19:08:05 katarynka volumio[9802]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 19:08:05 katarynka volumio[9802]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 19:08:05 katarynka volumio[9802]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 19:08:05 katarynka volumio[9802]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 19:08:05 katarynka volumio[9802]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 19:08:05 katarynka volumio[9802]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 19:08:05 katarynka volumio[9802]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 19:08:05 katarynka volumio[9802]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 19:08:05 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 19:08:05 katarynka go-librespot[10034]: go-librespot daemon starting... Mar 25 19:08:05 katarynka sudo[10027]: pam_unix(sudo:session): session closed for user root Mar 25 19:08:05 katarynka volumio[9802]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 19:08:05 katarynka volumio[9802]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 19:08:05 katarynka volumio[9802]: info: No need to fix Spotify hosts Mar 25 19:08:05 katarynka go-librespot[10038]: time="2026-03-25T19:08:05+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 19:08:05 katarynka go-librespot[10038]: time="2026-03-25T19:08:05+01:00" level=debug msg="app state loaded" Mar 25 19:08:05 katarynka go-librespot[10038]: time="2026-03-25T19:08:05+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 19:08:05 katarynka volumio[9917]: Starting albumart workers Mar 25 19:08:05 katarynka go-librespot[10038]: time="2026-03-25T19:08:05+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 25 19:08:05 katarynka go-librespot[10038]: time="2026-03-25T19:08:05+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 25 19:08:05 katarynka go-librespot[10038]: time="2026-03-25T19:08:05+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 25 19:08:05 katarynka go-librespot[10038]: time="2026-03-25T19:08:05+01:00" level=info msg="zeroconf server listening on port 39127" Mar 25 19:08:06 katarynka go-librespot[10038]: time="2026-03-25T19:08:06+01:00" level=debug msg="obtained new client token: AABJkNfQovdKqW1BNRCIpZQPdAj+SdU8IN7xaulv0iobHlcNdt4ikCELXkSYXzrh0X+qPMpxj33piBgUBeM9J+OhF/QDZp+FicM98rRRQ/moYLg6iSdep6WuCQA7akVAtSl8PwuJiQDZvuHKdYc5SeoRb6xju86lfH3R3nCQCgf6EK3hXiq7XZ5WWOf82MH6hpIRQmuztZVUQUuafxc5mJNM8Vs/4+Qp50F6zMWArnng+RNGPDeeMW4H" Mar 25 19:08:06 katarynka go-librespot[10038]: time="2026-03-25T19:08:06+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 19:08:06 katarynka go-librespot[10038]: time="2026-03-25T19:08:06+01:00" level=debug msg="completed keyexchange" Mar 25 19:08:06 katarynka go-librespot[10038]: time="2026-03-25T19:08:06+01:00" level=debug msg="completed challenge" Mar 25 19:08:06 katarynka volumio[9802]: info: Starting Shairport Sync Mar 25 19:08:06 katarynka go-librespot[10038]: time="2026-03-25T19:08:06+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 25 19:08:06 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 19:08:06 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 19:08:06 katarynka volumio[9802]: info: Starting Shairport Sync Mar 25 19:08:06 katarynka volumio[9802]: info: Starting Shairport Sync Mar 25 19:08:06 katarynka sudo[10049]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 25 19:08:06 katarynka sudo[10049]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 19:08:06 katarynka volumio[9918]: Starting albumart workers Mar 25 19:08:06 katarynka sudo[10054]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 25 19:08:06 katarynka sudo[10054]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 19:08:06 katarynka sudo[10051]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 25 19:08:06 katarynka sudo[10051]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 19:08:06 katarynka systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Mar 25 19:08:06 katarynka systemd[1]: shairport-sync.service: Deactivated successfully. Mar 25 19:08:06 katarynka systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 25 19:08:06 katarynka systemd[1]: shairport-sync.service: Consumed 2.214s CPU time. Mar 25 19:08:06 katarynka systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 25 19:08:06 katarynka volumio[9916]: Starting albumart workers Mar 25 19:08:06 katarynka sudo[10049]: pam_unix(sudo:session): session closed for user root Mar 25 19:08:06 katarynka sudo[10056]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Mar 25 19:08:06 katarynka sudo[10056]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 19:08:06 katarynka systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Mar 25 19:08:06 katarynka systemd[1]: shairport-sync.service: Deactivated successfully. Mar 25 19:08:06 katarynka systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 25 19:08:06 katarynka systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 25 19:08:06 katarynka sudo[10051]: pam_unix(sudo:session): session closed for user root Mar 25 19:08:06 katarynka sudo[10054]: pam_unix(sudo:session): session closed for user root Mar 25 19:08:07 katarynka sudo[10056]: pam_unix(sudo:session): session closed for user root Mar 25 19:08:07 katarynka volumio[9802]: info: Shairport-Sync Started Mar 25 19:08:07 katarynka volumio[9802]: Error adding Membership: Error: addMembership EINVAL Mar 25 19:08:07 katarynka volumio[9802]: info: Shairport-Sync Started Mar 25 19:08:07 katarynka volumio[9802]: info: An error occurred while refreshing Spotify Token Error: Bad Request Mar 25 19:08:07 katarynka volumio[9802]: info: Upmpdcli Daemon Started Mar 25 19:08:07 katarynka volumio[9802]: info: Shairport-Sync Started Mar 25 19:08:07 katarynka volumio[9802]: info: CoreCommandRouter::volumioGetState Mar 25 19:08:07 katarynka volumio[9802]: info: CorePlayQueue::getTrack 0 Mar 25 19:08:08 katarynka upmpdcli[1473]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Timeout Mar 25 19:08:08 katarynka upmpdcli[1473]: :2:../src/mpdcli.cxx:396::MPDCli::updStatus: connection failed Mar 25 19:08:08 katarynka upmpdcli[1473]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Mar 25 19:08:09 katarynka volumio[9802]: info: go-librespot daemon successfully initialized Mar 25 19:08:09 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 29. Mar 25 19:08:09 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 19:08:09 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 19:08:09 katarynka go-librespot[10096]: go-librespot daemon starting... Mar 25 19:08:09 katarynka go-librespot[10097]: time="2026-03-25T19:08:09+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 19:08:09 katarynka go-librespot[10097]: time="2026-03-25T19:08:09+01:00" level=debug msg="app state loaded" Mar 25 19:08:09 katarynka go-librespot[10097]: time="2026-03-25T19:08:09+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 19:08:10 katarynka go-librespot[10097]: time="2026-03-25T19:08:10+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 25 19:08:10 katarynka go-librespot[10097]: time="2026-03-25T19:08:10+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 19:08:10 katarynka go-librespot[10097]: time="2026-03-25T19:08:10+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 19:08:10 katarynka go-librespot[10097]: time="2026-03-25T19:08:10+01:00" level=info msg="zeroconf server listening on port 43067" Mar 25 19:08:10 katarynka go-librespot[10097]: time="2026-03-25T19:08:10+01:00" level=debug msg="obtained new client token: AABZtt7Ay5ir+NP6+FM9z/Ke80kehfNx4qECbAUNrmBBOpUyhzwZVX/29QuYZYoK38ENyPF6oKZDzKKxlLqY62AqOUvKTgcUq2sWLvhjx7HMEo9VOu4KUUGjvyZTBT7Pigur6pvol+9Udvi24Vyz3uoEYfDOymbJSLeHreszzZlCxRJmCfPoxGupEt7HuzyF84JR0/Ue4kEzcsgREfvHrp7zjrkSgKviWqvyxmVSwM7m+ThTumSlxu8w" Mar 25 19:08:10 katarynka go-librespot[10097]: time="2026-03-25T19:08:10+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 19:08:10 katarynka go-librespot[10097]: time="2026-03-25T19:08:10+01:00" level=debug msg="completed keyexchange" Mar 25 19:08:10 katarynka go-librespot[10097]: time="2026-03-25T19:08:10+01:00" level=debug msg="completed challenge" Mar 25 19:08:10 katarynka go-librespot[10097]: time="2026-03-25T19:08:10+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 25 19:08:10 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 19:08:10 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 19:08:10 katarynka mpd[10002]: 2026-03-25T19:08:10 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Mar 25 19:08:10 katarynka systemd[1]: Started mpd.service - Music Player Daemon. Mar 25 19:08:10 katarynka upmpdcli[1473]: :3:../src/mpdcli.cxx:148::MPDCli::startEventLoop: already started Mar 25 19:08:10 katarynka sudo[9963]: pam_unix(sudo:session): session closed for user root Mar 25 19:08:10 katarynka sudo[9953]: pam_unix(sudo:session): session closed for user root Mar 25 19:08:10 katarynka volumio[9802]: info: Completed starting Core Plugins Mar 25 19:08:10 katarynka volumio[9802]: info: ------------------------------------------- Mar 25 19:08:10 katarynka volumio[9802]: info: ----- MyVolumio plugins startup ---- Mar 25 19:08:10 katarynka volumio[9802]: info: ------------------------------------------- Mar 25 19:08:10 katarynka volumio[9802]: info: [MyVolumio PluginManager] Fetching plans data.... Mar 25 19:08:10 katarynka volumio[9802]: error: MPD error: The expression evaluated to a falsy value: Mar 25 19:08:10 katarynka volumio[9802]: assert.ok(self.idling) Mar 25 19:08:10 katarynka volumio[9802]: error: The expression evaluated to a falsy value: Mar 25 19:08:10 katarynka volumio[9802]: assert.ok(self.idling) Mar 25 19:08:10 katarynka volumio[9802]: error: updateQueue error: null Mar 25 19:08:10 katarynka volumio[9802]: info: MPD running with PID10002 Mar 25 19:08:10 katarynka volumio[9802]: ,establishing connection Mar 25 19:08:10 katarynka volumio[9802]: error: updateQueue error: null Mar 25 19:08:12 katarynka volumio[9802]: info: Initializing connection to go-librespot Websocket Mar 25 19:08:12 katarynka volumio[9802]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 25 19:08:13 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 30. Mar 25 19:08:13 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 19:08:13 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 19:08:13 katarynka go-librespot[10108]: go-librespot daemon starting... Mar 25 19:08:13 katarynka go-librespot[10122]: time="2026-03-25T19:08:13+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 19:08:13 katarynka go-librespot[10122]: time="2026-03-25T19:08:13+01:00" level=debug msg="app state loaded" Mar 25 19:08:13 katarynka go-librespot[10122]: time="2026-03-25T19:08:13+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 19:08:13 katarynka sudo[10133]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Mar 25 19:08:13 katarynka sudo[10133]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 19:08:13 katarynka sudo[10135]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Mar 25 19:08:13 katarynka sudo[10135]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 19:08:13 katarynka systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Mar 25 19:08:13 katarynka systemd[1]: mpd_monitor.service: Deactivated successfully. Mar 25 19:08:13 katarynka systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Mar 25 19:08:13 katarynka systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Mar 25 19:08:13 katarynka sudo[10135]: pam_unix(sudo:session): session closed for user root Mar 25 19:08:13 katarynka sudo[10133]: pam_unix(sudo:session): session closed for user root Mar 25 19:08:13 katarynka mpd_monitor.sh[10139]: MPD Monitor Service: Starting MPD Monitor Service Mar 25 19:08:13 katarynka volumio[9802]: info: Successfully started MPD Monitor Mar 25 19:08:13 katarynka volumio[9802]: info: Successfully started MPD Monitor Mar 25 19:08:14 katarynka go-librespot[10122]: time="2026-03-25T19:08:14+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 25 19:08:14 katarynka go-librespot[10122]: time="2026-03-25T19:08:14+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 19:08:14 katarynka go-librespot[10122]: time="2026-03-25T19:08:14+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 19:08:14 katarynka go-librespot[10122]: time="2026-03-25T19:08:14+01:00" level=info msg="zeroconf server listening on port 38049" Mar 25 19:08:14 katarynka go-librespot[10122]: time="2026-03-25T19:08:14+01:00" level=debug msg="obtained new client token: AABpSU36jUFtVqOm5Dfd9NgJIKJ8cTs/gaV/u2BT5otr6NmKqktC1pkd5I3x42LarwSAdcBhDERThz+wZaGAPfU9UyKxPHKtufiq/lMJA+SbZ6VgSi7oiCg7g7qcGiv46q1IbkWkZcE1lUDkxYnij+kIl7Q2puvplQ+RddMIyrB3+Efq/5N7GkBUSl/Dx/vZbYWxWIhrOICrwazo8fL9jjbQHGDQJVVMb+pLV6ZaMlso9RDlvxp5vnpX" Mar 25 19:08:14 katarynka go-librespot[10122]: time="2026-03-25T19:08:14+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 19:08:14 katarynka go-librespot[10122]: time="2026-03-25T19:08:14+01:00" level=debug msg="completed keyexchange" Mar 25 19:08:14 katarynka go-librespot[10122]: time="2026-03-25T19:08:14+01:00" level=debug msg="completed challenge" Mar 25 19:08:14 katarynka go-librespot[10122]: time="2026-03-25T19:08:14+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 25 19:08:14 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 19:08:14 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 19:08:15 katarynka volumio[9802]: info: Initializing connection to go-librespot Websocket Mar 25 19:08:15 katarynka volumio[9802]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 25 19:08:15 katarynka volumio[9802]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Mar 25 19:08:17 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 31. Mar 25 19:08:17 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 19:08:17 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 19:08:17 katarynka go-librespot[10144]: go-librespot daemon starting... Mar 25 19:08:17 katarynka go-librespot[10145]: time="2026-03-25T19:08:17+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 19:08:17 katarynka go-librespot[10145]: time="2026-03-25T19:08:17+01:00" level=debug msg="app state loaded" Mar 25 19:08:17 katarynka go-librespot[10145]: time="2026-03-25T19:08:17+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 19:08:17 katarynka go-librespot[10145]: time="2026-03-25T19:08:17+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 19:08:17 katarynka go-librespot[10145]: time="2026-03-25T19:08:17+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 19:08:17 katarynka go-librespot[10145]: time="2026-03-25T19:08:17+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 19:08:17 katarynka go-librespot[10145]: time="2026-03-25T19:08:17+01:00" level=info msg="zeroconf server listening on port 39881" Mar 25 19:08:18 katarynka go-librespot[10145]: time="2026-03-25T19:08:18+01:00" level=debug msg="obtained new client token: AACwi0fp4zjtzOe9D5mxPsou15Bl9nmDwsfVwe5Lr8wmuMftQ3VMgL7pcbABR7UtLRSbtCWT6VSptuD97UUsA2MEZbn9rCEqAplX0VF4PTaMoBilJI8ByOhArPhL6g+5zpRU7hbU9vmYU4xu/kuxG4/CtoFweGyLG0xyfiYSF1jQ0cf1UvF9JbH0dkPsBcWW5s5SwkRzfdtTNwCwSfch6VOUiJmUUl1QQRty+TrL7QUTpK24zNIL3Q2L" Mar 25 19:08:18 katarynka go-librespot[10145]: time="2026-03-25T19:08:18+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 19:08:18 katarynka volumio[9802]: info: Initializing connection to go-librespot Websocket Mar 25 19:08:18 katarynka go-librespot[10145]: time="2026-03-25T19:08:18+01:00" level=debug msg="completed keyexchange" Mar 25 19:08:18 katarynka go-librespot[10145]: time="2026-03-25T19:08:18+01:00" level=debug msg="completed challenge" Mar 25 19:08:18 katarynka go-librespot[10145]: time="2026-03-25T19:08:18+01:00" level=debug msg="new websocket client" Mar 25 19:08:18 katarynka volumio[9802]: info: Connection to go-librespot Websocket established Mar 25 19:08:18 katarynka go-librespot[10145]: time="2026-03-25T19:08:18+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 19:08:18 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 19:08:18 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 19:08:18 katarynka volumio[9802]: info: Connection to go-librespot Websocket closed Mar 25 19:08:19 katarynka volumio[9802]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Mar 25 19:08:19 katarynka volumio[9802]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Mar 25 19:08:19 katarynka volumio[9802]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Mar 25 19:08:19 katarynka volumio[9802]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Mar 25 19:08:19 katarynka volumio[9802]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Mar 25 19:08:19 katarynka volumio[9802]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Mar 25 19:08:19 katarynka volumio[9802]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Mar 25 19:08:19 katarynka volumio[9802]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Mar 25 19:08:19 katarynka volumio[9802]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Mar 25 19:08:19 katarynka volumio[9802]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Mar 25 19:08:19 katarynka volumio[9802]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Mar 25 19:08:19 katarynka volumio[9802]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Mar 25 19:08:19 katarynka volumio[9802]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Mar 25 19:08:19 katarynka volumio[9802]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Mar 25 19:08:19 katarynka volumio[9802]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Mar 25 19:08:19 katarynka volumio[9802]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Mar 25 19:08:19 katarynka volumio[9802]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Mar 25 19:08:19 katarynka volumio[9802]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Mar 25 19:08:19 katarynka volumio[9802]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Mar 25 19:08:19 katarynka volumio[9802]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Mar 25 19:08:19 katarynka volumio[9802]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Mar 25 19:08:19 katarynka volumio[9802]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Mar 25 19:08:19 katarynka volumio[9802]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Mar 25 19:08:19 katarynka volumio[9802]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Mar 25 19:08:19 katarynka volumio[9802]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Mar 25 19:08:19 katarynka volumio[9802]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Mar 25 19:08:19 katarynka volumio[9802]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Mar 25 19:08:19 katarynka volumio[9802]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Mar 25 19:08:19 katarynka volumio[9802]: info: Adding plugin bluetooth to MyMusic Plugins Mar 25 19:08:19 katarynka volumio[9802]: info: Adding plugin multiroom to MyMusic Plugins Mar 25 19:08:19 katarynka volumio[9802]: info: Adding plugin metavolumio to MyMusic Plugins Mar 25 19:08:19 katarynka volumio[9802]: info: Adding plugin cd_controller to MyMusic Plugins Mar 25 19:08:19 katarynka volumio[9802]: info: Adding plugin qobuzconnect to MyMusic Plugins Mar 25 19:08:19 katarynka volumio[9802]: info: Adding plugin smart_inputs to MyMusic Plugins Mar 25 19:08:19 katarynka volumio[9802]: info: Adding plugin tidalconnect to MyMusic Plugins Mar 25 19:08:19 katarynka volumio[9802]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Mar 25 19:08:21 katarynka volumio[9802]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Mar 25 19:08:21 katarynka volumio[9802]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Mar 25 19:08:21 katarynka volumio[9802]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 19:08:21 katarynka volumio[9802]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 19:08:21 katarynka volumio[9802]: info: Starting MyVolumio Remote Streaming Endpoints Mar 25 19:08:21 katarynka volumio[9802]: info: MyVolumio login type: Token Mar 25 19:08:21 katarynka volumio[9802]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Mar 25 19:08:21 katarynka volumio[9802]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Mar 25 19:08:21 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 32. Mar 25 19:08:21 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 19:08:21 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 19:08:21 katarynka go-librespot[10155]: go-librespot daemon starting... Mar 25 19:08:21 katarynka go-librespot[10156]: time="2026-03-25T19:08:21+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 19:08:21 katarynka go-librespot[10156]: time="2026-03-25T19:08:21+01:00" level=debug msg="app state loaded" Mar 25 19:08:21 katarynka go-librespot[10156]: time="2026-03-25T19:08:21+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 19:08:21 katarynka go-librespot[10156]: time="2026-03-25T19:08:21+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 25 19:08:21 katarynka go-librespot[10156]: time="2026-03-25T19:08:21+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 19:08:21 katarynka go-librespot[10156]: time="2026-03-25T19:08:21+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 19:08:22 katarynka go-librespot[10156]: time="2026-03-25T19:08:22+01:00" level=info msg="zeroconf server listening on port 40129" Mar 25 19:08:22 katarynka go-librespot[10156]: time="2026-03-25T19:08:22+01:00" level=debug msg="obtained new client token: AACtHxz6CmXDg+2IXtDB3bJx+6+wv587eEegrT3VnsOwV1klS1ayaDv4D3NWZ4m3IE/31AQ5r88rH/MtIsYdD81F262/yzz3LWlpE7p2BARWcdx3missjeDc44aKTlQQIbKFvZZORD9XnLsjS4RZl1ma9Pl6v+IF6fa5FMlSWAjqsQTQO5/SVwRQqPaaXUi4Ln6rIXJgH5OOknSMhNw2CfoeZ3e61K+S9EP+/6nBQbEcR3kjDMGfLtpV" Mar 25 19:08:22 katarynka go-librespot[10156]: time="2026-03-25T19:08:22+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 19:08:22 katarynka go-librespot[10156]: time="2026-03-25T19:08:22+01:00" level=debug msg="completed keyexchange" Mar 25 19:08:22 katarynka go-librespot[10156]: time="2026-03-25T19:08:22+01:00" level=debug msg="completed challenge" Mar 25 19:08:22 katarynka go-librespot[10156]: time="2026-03-25T19:08:22+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 19:08:22 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 19:08:22 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 19:08:23 katarynka volumio[9802]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Mar 25 19:08:23 katarynka volumio[9802]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Mar 25 19:08:23 katarynka volumio[9802]: info: Streaming services startup Mar 25 19:08:23 katarynka volumio[9802]: info: Starting Streaming Daemon Mar 25 19:08:23 katarynka sudo[10165]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Mar 25 19:08:23 katarynka sudo[10165]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 19:08:23 katarynka volumio[9802]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Mar 25 19:08:23 katarynka sudo[10165]: pam_unix(sudo:session): session closed for user root Mar 25 19:08:23 katarynka volumio[9802]: info: Getting Spotify volume Mar 25 19:08:23 katarynka volumio[9802]: info: Initializing connection to go-librespot Websocket Mar 25 19:08:23 katarynka volumio[9802]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 25 19:08:23 katarynka volumio[9802]: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 25 19:08:23 katarynka volumio[9802]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Mar 25 19:08:23 katarynka volumio[9802]: errno: -111, Mar 25 19:08:23 katarynka volumio[9802]: code: 'ECONNREFUSED', Mar 25 19:08:23 katarynka volumio[9802]: syscall: 'connect', Mar 25 19:08:23 katarynka volumio[9802]: address: '127.0.0.1', Mar 25 19:08:23 katarynka volumio[9802]: port: 9879, Mar 25 19:08:23 katarynka volumio[9802]: response: undefined Mar 25 19:08:23 katarynka volumio[9802]: } Mar 25 19:08:23 katarynka volumio[9802]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 25 19:08:24 katarynka sudo[10199]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-03-25 19:07' Mar 25 19:08:24 katarynka sudo[10199]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 19:08:25 katarynka sudo[10199]: pam_unix(sudo:session): session closed for user root Mar 25 19:08:25 katarynka volumio-remote-updater[686]: [2026-03-25 19:08:25] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Mar 25 19:08:25 katarynka volumio-remote-updater[686]: [2026-03-25 19:08:25] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Mar 25 19:08:25 katarynka systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Mar 25 19:08:25 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 33. Mar 25 19:08:25 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 19:08:25 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 19:08:25 katarynka go-librespot[10204]: go-librespot daemon starting... Mar 25 19:08:25 katarynka systemd[1]: volumio.service: Failed with result 'exit-code'. Mar 25 19:08:25 katarynka systemd[1]: volumio.service: Consumed 48.370s CPU time. Mar 25 19:08:25 katarynka systemd[1]: Started dynamicswap.service - dynamicswap service. Mar 25 19:08:25 katarynka go-librespot[10207]: time="2026-03-25T19:08:25+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 19:08:25 katarynka go-librespot[10207]: time="2026-03-25T19:08:25+01:00" level=debug msg="app state loaded" Mar 25 19:08:25 katarynka go-librespot[10207]: time="2026-03-25T19:08:25+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 19:08:25 katarynka systemd[1]: dynamicswap.service: Deactivated successfully. Mar 25 19:08:25 katarynka systemd[1]: volumio.service: Scheduled restart job, restart counter is at 93. Mar 25 19:08:25 katarynka systemd[1]: Started dynamicswap.service - dynamicswap service. Mar 25 19:08:25 katarynka systemd[1]: Stopped volumio.service - Volumio Backend Module. Mar 25 19:08:25 katarynka systemd[1]: volumio.service: Consumed 48.370s CPU time. Mar 25 19:08:25 katarynka systemd[1]: Started volumio.service - Volumio Backend Module. Mar 25 19:08:25 katarynka systemd[1]: dynamicswap.service: Deactivated successfully. Mar 25 19:08:25 katarynka go-librespot[10207]: time="2026-03-25T19:08:25+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 19:08:25 katarynka go-librespot[10207]: time="2026-03-25T19:08:25+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 19:08:25 katarynka go-librespot[10207]: time="2026-03-25T19:08:25+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 19:08:25 katarynka go-librespot[10207]: time="2026-03-25T19:08:25+01:00" level=info msg="zeroconf server listening on port 46029" Mar 25 19:08:26 katarynka go-librespot[10207]: time="2026-03-25T19:08:26+01:00" level=debug msg="obtained new client token: AACmCb6ctjxFCQOQXYoF+I65dQrOL6cKhayhqc1GoLuzhzU1cakKCIY6y4Pvi2Zm+De+sDdb4zspuEyeEqX5FgqQ3K0KWYFO5KANYej5+E/deD0/KdKimide31BDpvSOspivIZRWCqwAurdg4DfEZXsX4iGOVTqm3Cu5MuhBHcdjF9NiIV/P+Nfz9Obsyi7S3xtKh10QwssCgYqFcruWQwCL5ypOEbnqUgnuc9ATEzXMQcEa6lL3CQ8S" Mar 25 19:08:26 katarynka go-librespot[10207]: time="2026-03-25T19:08:26+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 19:08:26 katarynka go-librespot[10207]: time="2026-03-25T19:08:26+01:00" level=debug msg="completed keyexchange" Mar 25 19:08:26 katarynka go-librespot[10207]: time="2026-03-25T19:08:26+01:00" level=debug msg="completed challenge" Mar 25 19:08:26 katarynka go-librespot[10207]: time="2026-03-25T19:08:26+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 19:08:26 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 19:08:26 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 19:08:29 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 34. Mar 25 19:08:29 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 19:08:29 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 19:08:29 katarynka go-librespot[10243]: go-librespot daemon starting... Mar 25 19:08:29 katarynka go-librespot[10244]: time="2026-03-25T19:08:29+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 19:08:29 katarynka go-librespot[10244]: time="2026-03-25T19:08:29+01:00" level=debug msg="app state loaded" Mar 25 19:08:29 katarynka go-librespot[10244]: time="2026-03-25T19:08:29+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 19:08:29 katarynka volumio[10220]: info: ------------------------------------------- Mar 25 19:08:29 katarynka volumio[10220]: info: ----- Volumio3 ---- Mar 25 19:08:29 katarynka volumio[10220]: info: ------------------------------------------- Mar 25 19:08:29 katarynka volumio[10220]: info: ----- System startup ---- Mar 25 19:08:29 katarynka volumio[10220]: info: ------------------------------------------- Mar 25 19:08:30 katarynka go-librespot[10244]: time="2026-03-25T19:08:30+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 25 19:08:30 katarynka go-librespot[10244]: time="2026-03-25T19:08:30+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 25 19:08:30 katarynka go-librespot[10244]: time="2026-03-25T19:08:30+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 25 19:08:30 katarynka go-librespot[10244]: time="2026-03-25T19:08:30+01:00" level=info msg="zeroconf server listening on port 36037" Mar 25 19:08:30 katarynka go-librespot[10244]: time="2026-03-25T19:08:30+01:00" level=debug msg="obtained new client token: AACLf5N/qaWkERD1vBxvfBq4JWvPvK44JJn5BfWfm+u3X/c4hWAl/oohu9L821izmnPAG03vCeyQcWSoAve5LsrqD5/q0eK1sqYJkqj4FMRxXPFJfwgcJpAZ1b9TBPnFeOrpE+0GGOPJA/I46pvWMegC8i0tt0zL+2KSHi0+mT7VdoeysIdRTeDZjLoOInS+04GeCKQA9qW3hDAl14K+kDCbCLcI2L11inyR1XAZPHgrmYZmcLBlbQH/" Mar 25 19:08:30 katarynka go-librespot[10244]: time="2026-03-25T19:08:30+01:00" level=warning msg="failed to connect to AP ap-gew4.spotify.com:4070, retrying with a different AP" error="dial tcp 34.158.1.133:4070: connect: connection refused" Mar 25 19:08:30 katarynka go-librespot[10244]: time="2026-03-25T19:08:30+01:00" level=debug msg="connected to ap-gew4.spotify.com:443" Mar 25 19:08:30 katarynka go-librespot[10244]: time="2026-03-25T19:08:30+01:00" level=debug msg="completed keyexchange" Mar 25 19:08:30 katarynka go-librespot[10244]: time="2026-03-25T19:08:30+01:00" level=debug msg="completed challenge" Mar 25 19:08:30 katarynka volumio-remote-updater[686]: [2026-03-25 19:08:30] [connect] Successful connection Mar 25 19:08:30 katarynka go-librespot[10244]: time="2026-03-25T19:08:30+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 19:08:30 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 19:08:30 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 19:08:31 katarynka volumio[10220]: info: MYVOLUMIO Environment detected Mar 25 19:08:31 katarynka volumio[10220]: info: Plugin folders cleanup Mar 25 19:08:31 katarynka volumio[10220]: info: Scanning into folder /volumio/app/plugins/ Mar 25 19:08:31 katarynka volumio[10220]: info: Scanning category audio_interface Mar 25 19:08:31 katarynka volumio[10220]: info: Scanning category miscellanea Mar 25 19:08:31 katarynka volumio[10220]: info: Scanning category music_service Mar 25 19:08:31 katarynka volumio[10220]: info: Scanning category plugins.json Mar 25 19:08:31 katarynka volumio[10220]: info: Scanning category system_controller Mar 25 19:08:31 katarynka volumio[10220]: info: Scanning category user_interface Mar 25 19:08:31 katarynka volumio[10220]: info: Scanning into folder /data/plugins/ Mar 25 19:08:31 katarynka volumio[10220]: info: Scanning category music_service Mar 25 19:08:31 katarynka volumio[10220]: info: Plugin folders cleanup completed Mar 25 19:08:31 katarynka volumio[10220]: info: ------------------------------------------- Mar 25 19:08:31 katarynka volumio[10220]: info: ----- Core plugins startup ---- Mar 25 19:08:31 katarynka volumio[10220]: info: ------------------------------------------- Mar 25 19:08:31 katarynka volumio[10220]: info: Loading plugins from folder /volumio/app/plugins/ Mar 25 19:08:31 katarynka volumio[10220]: info: Adding plugin upnp to MyMusic Plugins Mar 25 19:08:31 katarynka volumio[10220]: info: Adding plugin airplay_emulation to MyMusic Plugins Mar 25 19:08:31 katarynka volumio[10220]: info: Adding plugin upnp_browser to MyMusic Plugins Mar 25 19:08:31 katarynka volumio[10220]: info: Loading plugins from folder /data/plugins/ Mar 25 19:08:31 katarynka volumio[10220]: info: Loading plugin "system"... Mar 25 19:08:31 katarynka volumio[10220]: info: Loading plugin "appearance"... Mar 25 19:08:33 katarynka volumio[10220]: info: Loading plugin "network"... Mar 25 19:08:33 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 35. Mar 25 19:08:33 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 19:08:33 katarynka volumio[10220]: info: Refreshing Cached IP Addresses Mar 25 19:08:33 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 19:08:33 katarynka sudo[10264]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 25 19:08:33 katarynka go-librespot[10262]: go-librespot daemon starting... Mar 25 19:08:33 katarynka sudo[10264]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 19:08:33 katarynka sudo[10266]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 25 19:08:33 katarynka sudo[10264]: pam_unix(sudo:session): session closed for user root Mar 25 19:08:33 katarynka sudo[10266]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 19:08:33 katarynka volumio[10220]: info: Loading plugin "services"... Mar 25 19:08:33 katarynka sudo[10266]: pam_unix(sudo:session): session closed for user root Mar 25 19:08:33 katarynka volumio[10220]: info: Loading plugin "alsa_controller"... Mar 25 19:08:33 katarynka sudo[10275]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Mar 25 19:08:33 katarynka sudo[10275]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 19:08:33 katarynka go-librespot[10273]: time="2026-03-25T19:08:33+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 19:08:33 katarynka go-librespot[10273]: time="2026-03-25T19:08:33+01:00" level=debug msg="app state loaded" Mar 25 19:08:33 katarynka go-librespot[10273]: time="2026-03-25T19:08:33+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 19:08:33 katarynka volumio[10220]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 25 19:08:33 katarynka volumio[10220]: info: Loading plugin "wizard"... Mar 25 19:08:33 katarynka volumio[10220]: info: Loading plugin "networkfs"... Mar 25 19:08:33 katarynka volumio[10220]: info: Starting Udev Watcher for removable devices Mar 25 19:08:33 katarynka volumio[10220]: info: Ignoring mount for partition: boot Mar 25 19:08:33 katarynka volumio[10220]: info: Ignoring mount for partition: volumio Mar 25 19:08:33 katarynka volumio[10220]: info: Ignoring mount for partition: volumio_data Mar 25 19:08:33 katarynka volumio[10220]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 25 19:08:33 katarynka volumio[10220]: info: Loading plugin "volumio_command_line_client"... Mar 25 19:08:33 katarynka volumio[10220]: info: Loading plugin "upnp"... Mar 25 19:08:33 katarynka volumio[10220]: info: [1774462113956] Starting Upmpd Daemon Mar 25 19:08:33 katarynka volumio[10220]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 25 19:08:33 katarynka volumio[10220]: info: Loading plugin "my_music"... Mar 25 19:08:33 katarynka volumio[10220]: info: Loading plugin "mpd"... Mar 25 19:08:34 katarynka go-librespot[10273]: time="2026-03-25T19:08:34+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 19:08:34 katarynka go-librespot[10273]: time="2026-03-25T19:08:34+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 19:08:34 katarynka go-librespot[10273]: time="2026-03-25T19:08:34+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 19:08:34 katarynka go-librespot[10273]: time="2026-03-25T19:08:34+01:00" level=info msg="zeroconf server listening on port 45943" Mar 25 19:08:34 katarynka sudo[10275]: pam_unix(sudo:session): session closed for user root Mar 25 19:08:34 katarynka go-librespot[10273]: time="2026-03-25T19:08:34+01:00" level=debug msg="obtained new client token: AABBHVWGmiEF51+U0CbwmedIbwD4LIztQ3ypOfBn8qSsYBT8D8BZNCwhDIiQsrf/goDpicIm2T0NjzE9lXHKQD/j+dCsxUTJkMx/fOhhx0eK3rlz+r2hrw4pWvdwDMNP+1uHrFxcbqxWQfJ5S8za3BsQt6xYePHvSncVjHrDkDx+pvfcK8xDFQeHikXB8O+rb4WqWLyfz/y5UI2xCVvmaNGzk5bZawa/crnVi5NTIfhXPuP/Q9gsoAGnHQM=" Mar 25 19:08:34 katarynka go-librespot[10273]: time="2026-03-25T19:08:34+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 19:08:34 katarynka volumio[10220]: info: Loading plugin "upnp_browser"... Mar 25 19:08:34 katarynka go-librespot[10273]: time="2026-03-25T19:08:34+01:00" level=debug msg="connected to ap-gew4.spotify.com:443" Mar 25 19:08:34 katarynka go-librespot[10273]: time="2026-03-25T19:08:34+01:00" level=debug msg="completed keyexchange" Mar 25 19:08:34 katarynka go-librespot[10273]: time="2026-03-25T19:08:34+01:00" level=debug msg="completed challenge" Mar 25 19:08:34 katarynka go-librespot[10273]: time="2026-03-25T19:08:34+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 25 19:08:34 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 19:08:34 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 19:08:37 katarynka volumio[10220]: info: Starting UPNP Browser Mar 25 19:08:37 katarynka volumio[10220]: info: Loading plugin "alarm-clock"... Mar 25 19:08:37 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 36. Mar 25 19:08:37 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 19:08:38 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 19:08:38 katarynka go-librespot[10307]: go-librespot daemon starting... Mar 25 19:08:38 katarynka volumio[10220]: info: Loading plugin "airplay_emulation"... Mar 25 19:08:38 katarynka go-librespot[10308]: time="2026-03-25T19:08:38+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 19:08:38 katarynka go-librespot[10308]: time="2026-03-25T19:08:38+01:00" level=debug msg="app state loaded" Mar 25 19:08:38 katarynka go-librespot[10308]: time="2026-03-25T19:08:38+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 19:08:38 katarynka volumio[10220]: info: Starting Shairport Sync Mar 25 19:08:38 katarynka volumio[10220]: info: Loading plugin "last_100"... Mar 25 19:08:38 katarynka volumio[10220]: info: Loading plugin "webradio"... Mar 25 19:08:38 katarynka volumio[10220]: info: Loading plugin "i2s_dacs"... Mar 25 19:08:38 katarynka volumio[10220]: info: Loading plugin "volumiodiscovery"... Mar 25 19:08:38 katarynka volumio[10220]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Mar 25 19:08:38 katarynka volumio[10220]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 25 19:08:38 katarynka volumio[10220]: *** WARNING *** For more information see Mar 25 19:08:38 katarynka volumio[10220]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Mar 25 19:08:38 katarynka volumio[10220]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 25 19:08:38 katarynka volumio[10220]: *** WARNING *** For more information see Mar 25 19:08:38 katarynka node[10220]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Mar 25 19:08:38 katarynka node[10220]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 25 19:08:38 katarynka node[10220]: *** WARNING *** For more information see Mar 25 19:08:38 katarynka node[10220]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Mar 25 19:08:38 katarynka node[10220]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 25 19:08:38 katarynka node[10220]: *** WARNING *** For more information see Mar 25 19:08:38 katarynka volumio[10220]: info: Applying required configuration parameters for plugin volumiodiscovery Mar 25 19:08:38 katarynka volumio[10220]: info: Discovery: Started advertising with name: katarynka Mar 25 19:08:38 katarynka volumio[10220]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 25 19:08:38 katarynka volumio[10220]: info: Loading plugin "spop"... Mar 25 19:08:38 katarynka go-librespot[10308]: time="2026-03-25T19:08:38+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 19:08:38 katarynka go-librespot[10308]: time="2026-03-25T19:08:38+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 19:08:38 katarynka go-librespot[10308]: time="2026-03-25T19:08:38+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 19:08:38 katarynka go-librespot[10308]: time="2026-03-25T19:08:38+01:00" level=info msg="zeroconf server listening on port 36103" Mar 25 19:08:38 katarynka go-librespot[10308]: time="2026-03-25T19:08:38+01:00" level=debug msg="obtained new client token: AABGzsQ1jhMEo5FvabIae8WW+n4Rb1vUNcTHC48VfLQN0g/GLpydM2QbWBVymbfBs9A6aqAwRQdbT+CByfxhxPpmJUY0p1yuGptdc+Q6qmsNaXd64+w+Q+tA1WyXiLKASH+Nfs5wjx7htzTaRxGIg91T+bhSd2P9ph3lNc/pPBifBc9CcQt8JzOznPFFBs7bDQzCRJnpZ9XCRVYW3prO9AYKf9FsGWOHFtih5dMkZU6r9w1AjoiGbw5v6rY=" Mar 25 19:08:39 katarynka go-librespot[10308]: time="2026-03-25T19:08:39+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 19:08:39 katarynka go-librespot[10308]: time="2026-03-25T19:08:39+01:00" level=debug msg="completed keyexchange" Mar 25 19:08:39 katarynka go-librespot[10308]: time="2026-03-25T19:08:39+01:00" level=debug msg="completed challenge" Mar 25 19:08:39 katarynka go-librespot[10308]: time="2026-03-25T19:08:39+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 25 19:08:39 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 19:08:39 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 19:08:40 katarynka volumio[10220]: info: Loading plugin "outputs"... Mar 25 19:08:40 katarynka volumio[10220]: info: Loading plugin "albumart"... Mar 25 19:08:40 katarynka volumio[10220]: info: Plugin example_plugin is not enabled Mar 25 19:08:40 katarynka volumio[10220]: info: Loading plugin "inputs"... Mar 25 19:08:40 katarynka volumio[10220]: info: Loading plugin "updater_comm"... Mar 25 19:08:40 katarynka volumio[10220]: info: Plugin mpdemulation is not enabled Mar 25 19:08:40 katarynka volumio[10220]: info: Loading plugin "rest_api"... Mar 25 19:08:40 katarynka volumio[10220]: info: Loading plugin "websocket"... Mar 25 19:08:40 katarynka volumio[10220]: info: Starting Socket.io Server version 1.7.4 Mar 25 19:08:40 katarynka volumio[10220]: info: Loading i18n strings for locale pl Mar 25 19:08:40 katarynka volumio[10220]: Updating browse sources language Mar 25 19:08:40 katarynka volumio[10220]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 25 19:08:41 katarynka volumio[10220]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 25 19:08:41 katarynka volumio[10220]: info: CoreCommandRouter::initPlayerControls Mar 25 19:08:41 katarynka volumio[10220]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 19:08:41 katarynka volumio[10220]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 19:08:41 katarynka volumio[10220]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 19:08:41 katarynka volumio[10220]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 19:08:41 katarynka volumio[10220]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 19:08:41 katarynka volumio[10220]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 19:08:41 katarynka volumio[10220]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 19:08:41 katarynka volumio[10220]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 19:08:41 katarynka volumio[10220]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 25 19:08:41 katarynka volumio[10220]: Express server listening on port 3000 Mar 25 19:08:41 katarynka volumio[10220]: [Metrics] WebUI: 12s 708.99ms Mar 25 19:08:41 katarynka volumio[10220]: info: CoreStateMachine::resetVolumioState Mar 25 19:08:41 katarynka volumio[10220]: info: CoreStateMachine::getcurrentVolume Mar 25 19:08:41 katarynka volumio[10220]: info: CoreCommandRouter::volumioRetrievevolume Mar 25 19:08:41 katarynka volumio[10220]: info: Cannot read play queue from file Mar 25 19:08:41 katarynka volumio[10220]: info: Volumio Network Manager: Network status updated: 2 Mar 25 19:08:41 katarynka volumio[10220]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 19:08:41 katarynka volumio[10318]: Forking 3 albumart workers Mar 25 19:08:41 katarynka volumio[10220]: info: CoreStateMachine::setRepeat null single undefined Mar 25 19:08:41 katarynka volumio[10220]: info: CoreStateMachine::pushState Mar 25 19:08:41 katarynka volumio[10220]: info: CorePlayQueue::getTrack 0 Mar 25 19:08:41 katarynka volumio[10220]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 25 19:08:41 katarynka volumio[10220]: info: CoreCommandRouter::volumioPushState Mar 25 19:08:41 katarynka volumio[10220]: info: CoreStateMachine::setRandom null Mar 25 19:08:41 katarynka volumio[10220]: info: CoreStateMachine::pushState Mar 25 19:08:41 katarynka volumio[10220]: info: CorePlayQueue::getTrack 0 Mar 25 19:08:41 katarynka volumio[10220]: info: CoreCommandRouter::volumioPushState Mar 25 19:08:41 katarynka volumio[10220]: info: Setting Device type: Raspberry PI Mar 25 19:08:41 katarynka volumio[10220]: info: Completed loading Core Plugins Mar 25 19:08:41 katarynka volumio[10220]: info: Preparing to generate the ALSA configuration file Mar 25 19:08:41 katarynka volumio[10220]: info: VolumeController:: Volume=96 Mute =false Mar 25 19:08:41 katarynka volumio[10220]: info: CoreStateMachine::pushState Mar 25 19:08:41 katarynka volumio[10220]: info: CorePlayQueue::getTrack 0 Mar 25 19:08:41 katarynka volumio[10220]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 25 19:08:41 katarynka volumio[10220]: info: CoreCommandRouter::volumioPushState Mar 25 19:08:41 katarynka volumio[10220]: info: CoreStateMachine::updateTrackBlock Mar 25 19:08:41 katarynka volumio[10220]: info: CorePlayQueue::getTrackBlock Mar 25 19:08:41 katarynka volumio[10220]: info: CoreCommandRouter::volumioRetrievevolume Mar 25 19:08:42 katarynka volumio[10220]: info: Asound.conf file unchanged, so no further update is needed Mar 25 19:08:42 katarynka volumio[10220]: info: Output device has changed, restarting MPD Mar 25 19:08:42 katarynka volumio[10220]: info: Output device has changed, restarting Shairport Sync Mar 25 19:08:42 katarynka volumio[10220]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 19:08:42 katarynka volumio[10220]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 19:08:42 katarynka sudo[10371]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 25 19:08:42 katarynka sudo[10371]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 19:08:42 katarynka volumio[10220]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 25 19:08:42 katarynka sudo[10374]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 25 19:08:42 katarynka sudo[10371]: pam_unix(sudo:session): session closed for user root Mar 25 19:08:42 katarynka volumio[10220]: info: ___________ START PLUGINS ___________ Mar 25 19:08:42 katarynka sudo[10374]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 19:08:42 katarynka volumio[10220]: info: ControllerMpd::onStart: Initializing MPD Mar 25 19:08:42 katarynka volumio[10220]: info: Creating MPD Configuration file Mar 25 19:08:42 katarynka volumio[10220]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 25 19:08:42 katarynka volumio[10220]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 25 19:08:42 katarynka volumio[10220]: info: [1774462122338] CoreMusicLibrary::Adding element Serwery Mediów Mar 25 19:08:42 katarynka volumio[10220]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 25 19:08:42 katarynka volumio[10220]: info: UPNP Browser: Client initialized successfully Mar 25 19:08:42 katarynka volumio[10220]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 19:08:42 katarynka volumio[10220]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 19:08:42 katarynka sudo[10384]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 25 19:08:42 katarynka systemd[1]: Stopping mpd.service - Music Player Daemon... Mar 25 19:08:42 katarynka sudo[10384]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 19:08:42 katarynka upmpdcli[1473]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Mar 25 19:08:42 katarynka sudo[10382]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 25 19:08:42 katarynka sudo[10382]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 19:08:42 katarynka sudo[10382]: pam_unix(sudo:session): session closed for user root Mar 25 19:08:42 katarynka volumio[10220]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 25 19:08:42 katarynka volumio[10220]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 19:08:42 katarynka volumio[10220]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 19:08:42 katarynka systemd[1]: mpd.service: Deactivated successfully. Mar 25 19:08:42 katarynka systemd[1]: Stopped mpd.service - Music Player Daemon. Mar 25 19:08:42 katarynka systemd[1]: mpd.service: Consumed 7.815s CPU time. Mar 25 19:08:42 katarynka systemd[1]: mpd.socket: Deactivated successfully. Mar 25 19:08:42 katarynka systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Mar 25 19:08:42 katarynka systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Mar 25 19:08:42 katarynka volumio[10220]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 25 19:08:42 katarynka volumio[10220]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 25 19:08:42 katarynka volumio[10220]: info: [1774462122645] CoreMusicLibrary::Adding element Last_100 Mar 25 19:08:42 katarynka systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Mar 25 19:08:42 katarynka volumio[10220]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 25 19:08:42 katarynka volumio[10220]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 25 19:08:42 katarynka systemd[1]: Starting mpd.service - Music Player Daemon... Mar 25 19:08:42 katarynka volumio[10220]: info: [1774462122683] CoreMusicLibrary::Adding element Webradio Mar 25 19:08:42 katarynka volumio[10220]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 25 19:08:42 katarynka volumio[10220]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 25 19:08:42 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 37. Mar 25 19:08:42 katarynka volumio[10220]: info: Initializing BBC Radios Mar 25 19:08:42 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 19:08:42 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 19:08:42 katarynka go-librespot[10399]: go-librespot daemon starting... Mar 25 19:08:42 katarynka systemd[1]: mpd.service: Deactivated successfully. Mar 25 19:08:42 katarynka systemd[1]: Stopped mpd.service - Music Player Daemon. Mar 25 19:08:42 katarynka volumio-remote-updater[686]: [2026-03-25 19:08:42] [connect] Successful connection Mar 25 19:08:42 katarynka systemd[1]: mpd.socket: Deactivated successfully. Mar 25 19:08:42 katarynka systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Mar 25 19:08:42 katarynka systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Mar 25 19:08:42 katarynka go-librespot[10401]: time="2026-03-25T19:08:42+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 19:08:42 katarynka go-librespot[10401]: time="2026-03-25T19:08:42+01:00" level=debug msg="app state loaded" Mar 25 19:08:42 katarynka systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Mar 25 19:08:42 katarynka go-librespot[10401]: time="2026-03-25T19:08:42+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 19:08:42 katarynka systemd[1]: Starting mpd.service - Music Player Daemon... Mar 25 19:08:42 katarynka volumio[10220]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 25 19:08:42 katarynka volumio[10220]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 19:08:43 katarynka volumio[10220]: info: Creating Spotify config file Mar 25 19:08:43 katarynka volumio[10220]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 19:08:43 katarynka sudo[10417]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Mar 25 19:08:43 katarynka sudo[10417]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Mar 25 19:08:43 katarynka sudo[10417]: pam_unix(sudo:session): session closed for user root Mar 25 19:08:43 katarynka go-librespot[10401]: time="2026-03-25T19:08:43+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 25 19:08:43 katarynka go-librespot[10401]: time="2026-03-25T19:08:43+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 19:08:43 katarynka go-librespot[10401]: time="2026-03-25T19:08:43+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 19:08:43 katarynka go-librespot[10401]: time="2026-03-25T19:08:43+01:00" level=info msg="zeroconf server listening on port 45755" Mar 25 19:08:43 katarynka go-librespot[10401]: time="2026-03-25T19:08:43+01:00" level=debug msg="obtained new client token: AACkjB9s8YdrxjBo2HHzRkF31ljZQEEIp9NdG0pF4vi04w7avTpcK4Nhf9pwmiGdrXPDXj8i7uWLW3B0TBhmrluZgcGt0jjf9sRLOcdrBjpJTV1Wir5u5/Chu+NIbuFyuGOEsP/qGJCqNbk450D6D97NtTxx2xLxL8k/VYNAofskKCV/YOBCWDf9vrD6OH4MWo16ofkHQ7II//DICmK9IpIHRWt2Pi5hF+3O5Xhq92phMZ7nQIj89rEwbOs=" Mar 25 19:08:43 katarynka go-librespot[10401]: time="2026-03-25T19:08:43+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 19:08:44 katarynka go-librespot[10401]: time="2026-03-25T19:08:44+01:00" level=debug msg="completed keyexchange" Mar 25 19:08:44 katarynka go-librespot[10401]: time="2026-03-25T19:08:44+01:00" level=debug msg="completed challenge" Mar 25 19:08:44 katarynka go-librespot[10401]: time="2026-03-25T19:08:44+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 19:08:44 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 19:08:44 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 19:08:44 katarynka volumio[10220]: info: Volumio Calling Home Mar 25 19:08:45 katarynka volumio[10220]: info: Discovery: adding 4d616d77-6a8c-4da2-85a4-840d70f98e51 Mar 25 19:08:45 katarynka volumio[10220]: info: Discovery: Found device katarynka Mar 25 19:08:45 katarynka volumio[10220]: info: CoreCommandRouter::volumioGetState Mar 25 19:08:45 katarynka volumio[10220]: info: CorePlayQueue::getTrack 0 Mar 25 19:08:45 katarynka sudo[10443]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 25 19:08:45 katarynka sudo[10443]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 19:08:45 katarynka sudo[10443]: pam_unix(sudo:session): session closed for user root Mar 25 19:08:45 katarynka sudo[10441]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 25 19:08:45 katarynka sudo[10441]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 19:08:45 katarynka sudo[10441]: pam_unix(sudo:session): session closed for user root Mar 25 19:08:45 katarynka volumio[10220]: info: MPD Permissions set Mar 25 19:08:45 katarynka volumio[10220]: info: MPD Permissions set Mar 25 19:08:45 katarynka volumio[10220]: info: VolumeController:: Volume=96 Mute =false Mar 25 19:08:45 katarynka volumio[10220]: info: CoreStateMachine::pushState Mar 25 19:08:45 katarynka volumio[10220]: info: CorePlayQueue::getTrack 0 Mar 25 19:08:45 katarynka volumio[10220]: info: CoreCommandRouter::volumioPushState Mar 25 19:08:45 katarynka volumio[10220]: info: Discovery: this is already registered, 4d616d77-6a8c-4da2-85a4-840d70f98e51 Mar 25 19:08:45 katarynka volumio[10220]: info: Discovery: Found device katarynka Mar 25 19:08:45 katarynka volumio[10220]: info: CoreCommandRouter::volumioGetState Mar 25 19:08:45 katarynka volumio[10220]: info: CorePlayQueue::getTrack 0 Mar 25 19:08:45 katarynka volumio-remote-updater[686]: [2026-03-25 19:08:45] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1774462122 101 Mar 25 19:08:45 katarynka volumio[10220]: 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 19:08:45 katarynka volumio[10220]: info: Volumio called home Mar 25 19:08:45 katarynka volumio[10220]: info: Spotify config file written Mar 25 19:08:45 katarynka sudo[10447]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Mar 25 19:08:45 katarynka sudo[10447]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 19:08:45 katarynka volumio[10337]: Starting albumart workers Mar 25 19:08:45 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 19:08:45 katarynka volumio[10220]: 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 19:08:45 katarynka volumio[10220]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 19:08:45 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 19:08:45 katarynka go-librespot[10449]: go-librespot daemon starting... Mar 25 19:08:45 katarynka volumio[10220]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 19:08:45 katarynka volumio[10220]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 19:08:45 katarynka volumio[10220]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 19:08:45 katarynka sudo[10447]: pam_unix(sudo:session): session closed for user root Mar 25 19:08:45 katarynka volumio[10220]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 19:08:45 katarynka volumio[10220]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 19:08:45 katarynka volumio[10220]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 19:08:45 katarynka volumio[10220]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 19:08:46 katarynka go-librespot[10450]: time="2026-03-25T19:08:46+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 19:08:46 katarynka go-librespot[10450]: time="2026-03-25T19:08:46+01:00" level=debug msg="app state loaded" Mar 25 19:08:46 katarynka go-librespot[10450]: time="2026-03-25T19:08:46+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 19:08:46 katarynka volumio[10220]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 19:08:46 katarynka volumio[10220]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 19:08:46 katarynka volumio[10220]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 19:08:46 katarynka volumio[10220]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 19:08:46 katarynka volumio[10220]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 19:08:46 katarynka volumio[10220]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 19:08:46 katarynka volumio[10220]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 19:08:46 katarynka volumio[10220]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 19:08:46 katarynka volumio[10220]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 19:08:46 katarynka volumio[10220]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 19:08:46 katarynka volumio[10220]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 19:08:46 katarynka volumio[10220]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 19:08:46 katarynka volumio[10220]: info: No need to fix Spotify hosts Mar 25 19:08:46 katarynka volumio[10340]: Starting albumart workers Mar 25 19:08:46 katarynka volumio[10339]: Starting albumart workers Mar 25 19:08:46 katarynka volumio[10220]: info: Starting Shairport Sync Mar 25 19:08:46 katarynka volumio[10220]: info: Starting Shairport Sync Mar 25 19:08:46 katarynka volumio[10220]: info: Starting Shairport Sync Mar 25 19:08:46 katarynka go-librespot[10450]: time="2026-03-25T19:08:46+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 25 19:08:46 katarynka go-librespot[10450]: time="2026-03-25T19:08:46+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 25 19:08:46 katarynka go-librespot[10450]: time="2026-03-25T19:08:46+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 25 19:08:46 katarynka go-librespot[10450]: time="2026-03-25T19:08:46+01:00" level=info msg="zeroconf server listening on port 46861" Mar 25 19:08:46 katarynka sudo[10469]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 25 19:08:46 katarynka sudo[10469]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 19:08:46 katarynka sudo[10473]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 25 19:08:46 katarynka sudo[10473]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 19:08:46 katarynka sudo[10471]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 25 19:08:46 katarynka sudo[10471]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 19:08:46 katarynka systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Mar 25 19:08:46 katarynka sudo[10476]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Mar 25 19:08:46 katarynka go-librespot[10450]: time="2026-03-25T19:08:46+01:00" level=debug msg="obtained new client token: AACzlMo6pEk0v6LRnoBzkOc/IRBqF5wu/wn/fMRl7e5hqX+g9WRCaIBmWzxnLF/N33u4NemIIuVojCP5oYxHl7gD5RTtmjqovv2vwAPluwBeBPs11CO3k1GfDD2+K2m+ksB+Ux1sB65Edd7SrMZgntWrdZjWNmlE3XZ+AzmqRrJtwJAwlIaTFYiptAoUQYEYmKgDwpD68WDZAr+Jf5Zei02f3qNdPdrK3jxwl9u0T57KEvdWfxjqlUv3YlM=" Mar 25 19:08:46 katarynka systemd[1]: shairport-sync.service: Deactivated successfully. Mar 25 19:08:46 katarynka systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 25 19:08:46 katarynka systemd[1]: shairport-sync.service: Consumed 2.240s CPU time. Mar 25 19:08:47 katarynka sudo[10476]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 19:08:47 katarynka systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 25 19:08:47 katarynka go-librespot[10450]: time="2026-03-25T19:08:47+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 19:08:47 katarynka sudo[10469]: pam_unix(sudo:session): session closed for user root Mar 25 19:08:47 katarynka sudo[10471]: pam_unix(sudo:session): session closed for user root Mar 25 19:08:47 katarynka sudo[10473]: pam_unix(sudo:session): session closed for user root Mar 25 19:08:47 katarynka sudo[10476]: pam_unix(sudo:session): session closed for user root Mar 25 19:08:47 katarynka volumio[10220]: info: CoreCommandRouter::volumioGetState Mar 25 19:08:47 katarynka volumio[10220]: info: CorePlayQueue::getTrack 0 Mar 25 19:08:47 katarynka go-librespot[10450]: time="2026-03-25T19:08:47+01:00" level=debug msg="completed keyexchange" Mar 25 19:08:47 katarynka go-librespot[10450]: time="2026-03-25T19:08:47+01:00" level=debug msg="completed challenge" Mar 25 19:08:47 katarynka volumio[10220]: info: Upmpdcli Daemon Started Mar 25 19:08:47 katarynka volumio[10220]: info: Shairport-Sync Started Mar 25 19:08:47 katarynka volumio[10220]: Error adding Membership: Error: addMembership EINVAL Mar 25 19:08:47 katarynka volumio[10220]: info: Shairport-Sync Started Mar 25 19:08:47 katarynka volumio[10220]: info: Shairport-Sync Started Mar 25 19:08:47 katarynka go-librespot[10450]: time="2026-03-25T19:08:47+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 25 19:08:47 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 19:08:47 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 19:08:47 katarynka volumio[10220]: info: An error occurred while refreshing Spotify Token Error: Bad Request Mar 25 19:08:48 katarynka upmpdcli[1473]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Timeout Mar 25 19:08:48 katarynka upmpdcli[1473]: :2:../src/mpdcli.cxx:396::MPDCli::updStatus: connection failed Mar 25 19:08:48 katarynka upmpdcli[1473]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Mar 25 19:08:49 katarynka volumio[10220]: info: go-librespot daemon successfully initialized Mar 25 19:08:50 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 38. Mar 25 19:08:50 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 19:08:51 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 19:08:51 katarynka go-librespot[10516]: go-librespot daemon starting... Mar 25 19:08:51 katarynka go-librespot[10517]: time="2026-03-25T19:08:51+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 19:08:51 katarynka go-librespot[10517]: time="2026-03-25T19:08:51+01:00" level=debug msg="app state loaded" Mar 25 19:08:51 katarynka go-librespot[10517]: time="2026-03-25T19:08:51+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 19:08:51 katarynka mpd[10422]: 2026-03-25T19:08:51 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Mar 25 19:08:51 katarynka systemd[1]: Started mpd.service - Music Player Daemon. Mar 25 19:08:51 katarynka upmpdcli[1473]: :3:../src/mpdcli.cxx:148::MPDCli::startEventLoop: already started Mar 25 19:08:51 katarynka sudo[10384]: pam_unix(sudo:session): session closed for user root Mar 25 19:08:51 katarynka sudo[10374]: pam_unix(sudo:session): session closed for user root Mar 25 19:08:51 katarynka volumio[10220]: info: Completed starting Core Plugins Mar 25 19:08:51 katarynka volumio[10220]: info: ------------------------------------------- Mar 25 19:08:51 katarynka volumio[10220]: info: ----- MyVolumio plugins startup ---- Mar 25 19:08:51 katarynka volumio[10220]: info: ------------------------------------------- Mar 25 19:08:51 katarynka volumio[10220]: info: [MyVolumio PluginManager] Fetching plans data.... Mar 25 19:08:51 katarynka volumio[10220]: error: MPD error: The expression evaluated to a falsy value: Mar 25 19:08:51 katarynka volumio[10220]: assert.ok(self.idling) Mar 25 19:08:51 katarynka volumio[10220]: error: The expression evaluated to a falsy value: Mar 25 19:08:51 katarynka volumio[10220]: assert.ok(self.idling) Mar 25 19:08:51 katarynka volumio[10220]: info: MPD running with PID10422 Mar 25 19:08:51 katarynka volumio[10220]: ,establishing connection Mar 25 19:08:51 katarynka volumio[10220]: error: updateQueue error: null Mar 25 19:08:51 katarynka volumio[10220]: error: updateQueue error: null Mar 25 19:08:51 katarynka go-librespot[10517]: time="2026-03-25T19:08: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-gae2.spotify.com:80]" Mar 25 19:08:51 katarynka go-librespot[10517]: time="2026-03-25T19:08:51+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 19:08:51 katarynka go-librespot[10517]: time="2026-03-25T19:08:51+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 19:08:51 katarynka go-librespot[10517]: time="2026-03-25T19:08:51+01:00" level=info msg="zeroconf server listening on port 45927" Mar 25 19:08:51 katarynka go-librespot[10517]: time="2026-03-25T19:08:51+01:00" level=debug msg="obtained new client token: AACfBosN594qz3ALuFhblja+E6c5Y8nteMnv2Soq9N1KiuKZBk1rX70NbQ6JvrTrz9WeEHDxVeEWk8B5U8fFPp8KuEkG4eqTlEHHBJ5ICcIcooF+ZSEeV10qilErcufDSWDqOosJwEOB1KETl8aroe7l8xPK/vANoRX56Gmfk/PnC8p5qSPb7SGiLH1t3bXnNVocdVZAVv4Zi6u+ktIw6Q7iaFE+ZRDUQxRa5+y9q60WFd49Wu0EQ5IJw9s=" Mar 25 19:08:51 katarynka go-librespot[10517]: time="2026-03-25T19:08:51+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 19:08:51 katarynka go-librespot[10517]: time="2026-03-25T19:08:51+01:00" level=debug msg="completed keyexchange" Mar 25 19:08:51 katarynka go-librespot[10517]: time="2026-03-25T19:08:51+01:00" level=debug msg="completed challenge" Mar 25 19:08:51 katarynka go-librespot[10517]: time="2026-03-25T19:08:51+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 25 19:08:51 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 19:08:51 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 19:08:52 katarynka volumio[10220]: info: Initializing connection to go-librespot Websocket Mar 25 19:08:52 katarynka volumio[10220]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 25 19:08:54 katarynka wpa_supplicant[1165]: wlan0: WPA: Group rekeying completed with 84:a9:c4:23:8a:fc [GTK=TKIP] Mar 25 19:08:54 katarynka sudo[10546]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Mar 25 19:08:54 katarynka sudo[10546]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 19:08:54 katarynka sudo[10548]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Mar 25 19:08:54 katarynka sudo[10548]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 19:08:54 katarynka systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Mar 25 19:08:54 katarynka systemd[1]: mpd_monitor.service: Deactivated successfully. Mar 25 19:08:54 katarynka systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Mar 25 19:08:54 katarynka systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Mar 25 19:08:54 katarynka sudo[10546]: pam_unix(sudo:session): session closed for user root Mar 25 19:08:54 katarynka mpd_monitor.sh[10551]: MPD Monitor Service: Starting MPD Monitor Service Mar 25 19:08:54 katarynka sudo[10548]: pam_unix(sudo:session): session closed for user root Mar 25 19:08:54 katarynka volumio[10220]: info: Successfully started MPD Monitor Mar 25 19:08:54 katarynka volumio[10220]: info: Successfully started MPD Monitor Mar 25 19:08:55 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 39. Mar 25 19:08:55 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 19:08:55 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 19:08:55 katarynka go-librespot[10555]: go-librespot daemon starting... Mar 25 19:08:55 katarynka go-librespot[10556]: time="2026-03-25T19:08:55+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 19:08:55 katarynka go-librespot[10556]: time="2026-03-25T19:08:55+01:00" level=debug msg="app state loaded" Mar 25 19:08:55 katarynka go-librespot[10556]: time="2026-03-25T19:08:55+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 19:08:55 katarynka volumio[10220]: info: Initializing connection to go-librespot Websocket Mar 25 19:08:55 katarynka go-librespot[10556]: time="2026-03-25T19:08:55+01:00" level=debug msg="new websocket client" Mar 25 19:08:55 katarynka go-librespot[10556]: time="2026-03-25T19:08: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 19:08:55 katarynka go-librespot[10556]: time="2026-03-25T19:08: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 19:08:55 katarynka go-librespot[10556]: time="2026-03-25T19:08: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 19:08:55 katarynka volumio[10220]: info: Connection to go-librespot Websocket established Mar 25 19:08:55 katarynka go-librespot[10556]: time="2026-03-25T19:08:55+01:00" level=info msg="zeroconf server listening on port 41335" Mar 25 19:08:55 katarynka go-librespot[10556]: time="2026-03-25T19:08:55+01:00" level=debug msg="obtained new client token: AABaITsNJ5bCZk/ZFWXbCR6vBT9KiV2dG3zeO/aunnApVhd2TQhxXMBxhBJ03DlfOiJYmNFiINZYv1iewMaCa3x46RPty0fLqmB2Vu5CMCKmSBgkn/3cIEAVyjnS6T/kyDqy6EXzHxJNa9AloL0FXykyaXwfRN0yj3Bn+gqWrldj7E5dByG7ntRNCIgWafDVy63X3hztI32iExevastFp/nVbndGCIiaIQm7Q610wonK2BULai50+9faWYs=" Mar 25 19:08:55 katarynka go-librespot[10556]: time="2026-03-25T19:08:55+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 19:08:55 katarynka go-librespot[10556]: time="2026-03-25T19:08:55+01:00" level=debug msg="completed keyexchange" Mar 25 19:08:55 katarynka go-librespot[10556]: time="2026-03-25T19:08:55+01:00" level=debug msg="completed challenge" Mar 25 19:08:56 katarynka go-librespot[10556]: time="2026-03-25T19:08:56+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 25 19:08:56 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 19:08:56 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 19:08:56 katarynka volumio[10220]: info: Connection to go-librespot Websocket closed Mar 25 19:08:56 katarynka volumio[10220]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Mar 25 19:08:58 katarynka volumio[10220]: info: Getting Spotify volume Mar 25 19:08:58 katarynka volumio[10220]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 25 19:08:58 katarynka volumio[10220]: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 25 19:08:58 katarynka volumio[10220]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Mar 25 19:08:58 katarynka volumio[10220]: errno: -111, Mar 25 19:08:58 katarynka volumio[10220]: code: 'ECONNREFUSED', Mar 25 19:08:58 katarynka volumio[10220]: syscall: 'connect', Mar 25 19:08:58 katarynka volumio[10220]: address: '127.0.0.1', Mar 25 19:08:58 katarynka volumio[10220]: port: 9879, Mar 25 19:08:58 katarynka volumio[10220]: response: undefined Mar 25 19:08:58 katarynka volumio[10220]: } Mar 25 19:08:58 katarynka volumio[10220]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 25 19:08:59 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 40. Mar 25 19:08:59 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 19:08:59 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 19:08:59 katarynka go-librespot[10577]: go-librespot daemon starting... Mar 25 19:08:59 katarynka go-librespot[10578]: time="2026-03-25T19:08:59+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 19:08:59 katarynka go-librespot[10578]: time="2026-03-25T19:08:59+01:00" level=debug msg="app state loaded" Mar 25 19:08:59 katarynka go-librespot[10578]: time="2026-03-25T19:08:59+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 19:08:59 katarynka go-librespot[10578]: time="2026-03-25T19:08: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 19:08:59 katarynka go-librespot[10578]: time="2026-03-25T19:08: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 19:08:59 katarynka go-librespot[10578]: time="2026-03-25T19:08: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 19:08:59 katarynka go-librespot[10578]: time="2026-03-25T19:08:59+01:00" level=info msg="zeroconf server listening on port 35877" Mar 25 19:08:59 katarynka go-librespot[10578]: time="2026-03-25T19:08:59+01:00" level=debug msg="obtained new client token: AADkhI+IPlD1iiYTSXtXaxkOg1aaCrsstArTdaXBACOh9ODCZZQq6jMhwubCPTpGGeYy0Z4bGnmI9RIeJ0nCkmAr8q11YpFcstcV66GDZqmVSf8GdzDsAnnhVrOJGiWJN1YN8aaowZEyOW/o3NN/uYEf8+Uk0oRu2arqOIZUj6uBC6h4mbYawfj6PBrWBVV919myaO+cxfg3Mb92AY4zRyVf5q5saN1C5+L5on7vydfJd6Eoe+ZjBaY6G4s=" Mar 25 19:08:59 katarynka go-librespot[10578]: time="2026-03-25T19:08:59+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 19:09:00 katarynka go-librespot[10578]: time="2026-03-25T19:09:00+01:00" level=debug msg="completed keyexchange" Mar 25 19:09:00 katarynka go-librespot[10578]: time="2026-03-25T19:09:00+01:00" level=debug msg="completed challenge" Mar 25 19:09:00 katarynka go-librespot[10578]: time="2026-03-25T19:09:00+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 25 19:09:00 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 19:09:00 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 19:09:00 katarynka sudo[10588]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-03-25 19:08' Mar 25 19:09:00 katarynka sudo[10588]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 19:09:00 katarynka sudo[10588]: pam_unix(sudo:session): session closed for user root Mar 25 19:09:00 katarynka volumio-remote-updater[686]: [2026-03-25 19:09:00] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Mar 25 19:09:00 katarynka volumio-remote-updater[686]: [2026-03-25 19:09:00] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Mar 25 19:09:00 katarynka systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Mar 25 19:09:00 katarynka systemd[1]: volumio.service: Failed with result 'exit-code'. Mar 25 19:09:00 katarynka systemd[1]: volumio.service: Consumed 42.866s CPU time. Mar 25 19:09:00 katarynka systemd[1]: Started dynamicswap.service - dynamicswap service. Mar 25 19:09:00 katarynka systemd[1]: dynamicswap.service: Deactivated successfully. Mar 25 19:09:00 katarynka systemd[1]: volumio.service: Scheduled restart job, restart counter is at 94. Mar 25 19:09:01 katarynka systemd[1]: Started dynamicswap.service - dynamicswap service. Mar 25 19:09:01 katarynka systemd[1]: Stopped volumio.service - Volumio Backend Module. Mar 25 19:09:01 katarynka systemd[1]: volumio.service: Consumed 42.866s CPU time. Mar 25 19:09:01 katarynka systemd[1]: Started volumio.service - Volumio Backend Module. Mar 25 19:09:01 katarynka systemd[1]: dynamicswap.service: Deactivated successfully. Mar 25 19:09:03 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 41. Mar 25 19:09:03 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 19:09:03 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 19:09:03 katarynka go-librespot[10616]: go-librespot daemon starting... Mar 25 19:09:03 katarynka go-librespot[10617]: time="2026-03-25T19:09:03+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 19:09:03 katarynka go-librespot[10617]: time="2026-03-25T19:09:03+01:00" level=debug msg="app state loaded" Mar 25 19:09:03 katarynka go-librespot[10617]: time="2026-03-25T19:09:03+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 19:09:03 katarynka go-librespot[10617]: time="2026-03-25T19:09: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 19:09:03 katarynka go-librespot[10617]: time="2026-03-25T19:09: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 19:09:03 katarynka go-librespot[10617]: time="2026-03-25T19:09: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 19:09:04 katarynka go-librespot[10617]: time="2026-03-25T19:09:04+01:00" level=info msg="zeroconf server listening on port 45065" Mar 25 19:09:04 katarynka go-librespot[10617]: time="2026-03-25T19:09:04+01:00" level=debug msg="obtained new client token: AAA6H4q0dXT2D6Z338Il7b0XuMRTLO+mcLl4r13G4TBzza2VP2j9eN+3Pz/HXrHYuX4BSKhEup6ecZVF4qLveZNBsRjRPcKRzuyfmsUMdkigVJWB8uOIRePVSlJfy7HrZXcG5lyUYXT6qB3vIFD+id4Ci1/RRLf6eU4RibcDydpl+LaVTxsID0v+vWWALotYCptJa3aYJbLLxr/N3moAFSEaFWKrTIJ0fz9xWWtfs5eQeUdcKDmRlOno" Mar 25 19:09:04 katarynka go-librespot[10617]: time="2026-03-25T19:09:04+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 19:09:04 katarynka go-librespot[10617]: time="2026-03-25T19:09:04+01:00" level=debug msg="completed keyexchange" Mar 25 19:09:04 katarynka go-librespot[10617]: time="2026-03-25T19:09:04+01:00" level=debug msg="completed challenge" Mar 25 19:09:04 katarynka go-librespot[10617]: time="2026-03-25T19:09:04+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 25 19:09:04 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 19:09:04 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 19:09:04 katarynka volumio[10600]: info: ------------------------------------------- Mar 25 19:09:04 katarynka volumio[10600]: info: ----- Volumio3 ---- Mar 25 19:09:04 katarynka volumio[10600]: info: ------------------------------------------- Mar 25 19:09:04 katarynka volumio[10600]: info: ----- System startup ---- Mar 25 19:09:04 katarynka volumio[10600]: info: ------------------------------------------- Mar 25 19:09:05 katarynka volumio-remote-updater[686]: [2026-03-25 19:09:05] [connect] Successful connection Mar 25 19:09:06 katarynka volumio[10600]: info: MYVOLUMIO Environment detected Mar 25 19:09:06 katarynka volumio[10600]: info: Plugin folders cleanup Mar 25 19:09:06 katarynka volumio[10600]: info: Scanning into folder /volumio/app/plugins/ Mar 25 19:09:06 katarynka volumio[10600]: info: Scanning category audio_interface Mar 25 19:09:06 katarynka volumio[10600]: info: Scanning category miscellanea Mar 25 19:09:06 katarynka volumio[10600]: info: Scanning category music_service Mar 25 19:09:06 katarynka volumio[10600]: info: Scanning category plugins.json Mar 25 19:09:06 katarynka volumio[10600]: info: Scanning category system_controller Mar 25 19:09:06 katarynka volumio[10600]: info: Scanning category user_interface Mar 25 19:09:06 katarynka volumio[10600]: info: Scanning into folder /data/plugins/ Mar 25 19:09:06 katarynka volumio[10600]: info: Scanning category music_service Mar 25 19:09:06 katarynka volumio[10600]: info: Plugin folders cleanup completed Mar 25 19:09:06 katarynka volumio[10600]: info: ------------------------------------------- Mar 25 19:09:06 katarynka volumio[10600]: info: ----- Core plugins startup ---- Mar 25 19:09:06 katarynka volumio[10600]: info: ------------------------------------------- Mar 25 19:09:06 katarynka volumio[10600]: info: Loading plugins from folder /volumio/app/plugins/ Mar 25 19:09:06 katarynka volumio[10600]: info: Adding plugin upnp to MyMusic Plugins Mar 25 19:09:06 katarynka volumio[10600]: info: Adding plugin airplay_emulation to MyMusic Plugins Mar 25 19:09:06 katarynka volumio[10600]: info: Adding plugin upnp_browser to MyMusic Plugins Mar 25 19:09:06 katarynka volumio[10600]: info: Loading plugins from folder /data/plugins/ Mar 25 19:09:06 katarynka volumio[10600]: info: Loading plugin "system"... Mar 25 19:09:06 katarynka volumio[10600]: info: Loading plugin "appearance"... Mar 25 19:09:07 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 42. Mar 25 19:09:07 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 19:09:07 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 19:09:07 katarynka go-librespot[10637]: go-librespot daemon starting... Mar 25 19:09:07 katarynka go-librespot[10638]: time="2026-03-25T19:09:07+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 19:09:07 katarynka go-librespot[10638]: time="2026-03-25T19:09:07+01:00" level=debug msg="app state loaded" Mar 25 19:09:07 katarynka go-librespot[10638]: time="2026-03-25T19:09:07+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 19:09:08 katarynka go-librespot[10638]: time="2026-03-25T19:09:08+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 25 19:09:08 katarynka go-librespot[10638]: time="2026-03-25T19:09:08+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 19:09:08 katarynka go-librespot[10638]: time="2026-03-25T19:09:08+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 19:09:08 katarynka go-librespot[10638]: time="2026-03-25T19:09:08+01:00" level=info msg="zeroconf server listening on port 41597" Mar 25 19:09:08 katarynka go-librespot[10638]: time="2026-03-25T19:09:08+01:00" level=debug msg="obtained new client token: AADfcf6va+CVQWcUDt+kEfI3mQkn6BSb4apJud+G7vOQOnT/+en+PHiBHynsBl7sGH4/b3rftBnYlRfmuJSWGCe+kN9uvjOaVf2+euE12IOX5Tp/73eW70x/U8QctrvdRp+XeB/o/OlnH0qFxqR+6E6mG3A4r7U/vlDfdy4EuFI0d1YhL4YoWBIq7FGGB4j8WUrYVfioNbRnS9KBzsy4QCBm/N7XyZpZE2eEz2KsaPDF4W/9tPmjofjp" Mar 25 19:09:08 katarynka go-librespot[10638]: time="2026-03-25T19:09:08+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 19:09:08 katarynka go-librespot[10638]: time="2026-03-25T19:09:08+01:00" level=debug msg="completed keyexchange" Mar 25 19:09:08 katarynka go-librespot[10638]: time="2026-03-25T19:09:08+01:00" level=debug msg="completed challenge" Mar 25 19:09:08 katarynka go-librespot[10638]: time="2026-03-25T19:09: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 19:09:08 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 19:09:08 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 19:09:08 katarynka volumio[10600]: info: Loading plugin "network"... Mar 25 19:09:08 katarynka volumio[10600]: info: Refreshing Cached IP Addresses Mar 25 19:09:08 katarynka sudo[10647]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 25 19:09:08 katarynka sudo[10647]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 19:09:08 katarynka sudo[10647]: pam_unix(sudo:session): session closed for user root Mar 25 19:09:08 katarynka sudo[10649]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 25 19:09:08 katarynka sudo[10649]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 19:09:08 katarynka volumio[10600]: info: Loading plugin "services"... Mar 25 19:09:08 katarynka sudo[10649]: pam_unix(sudo:session): session closed for user root Mar 25 19:09:08 katarynka volumio[10600]: info: Loading plugin "alsa_controller"... Mar 25 19:09:08 katarynka sudo[10657]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Mar 25 19:09:08 katarynka sudo[10657]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 19:09:08 katarynka volumio[10600]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 25 19:09:08 katarynka volumio[10600]: info: Loading plugin "wizard"... Mar 25 19:09:08 katarynka volumio[10600]: info: Loading plugin "networkfs"... Mar 25 19:09:09 katarynka volumio[10600]: info: Starting Udev Watcher for removable devices Mar 25 19:09:09 katarynka volumio[10600]: info: Ignoring mount for partition: boot Mar 25 19:09:09 katarynka volumio[10600]: info: Ignoring mount for partition: volumio Mar 25 19:09:09 katarynka volumio[10600]: info: Ignoring mount for partition: volumio_data Mar 25 19:09:09 katarynka volumio[10600]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 25 19:09:09 katarynka volumio[10600]: info: Loading plugin "volumio_command_line_client"... Mar 25 19:09:09 katarynka volumio[10600]: info: Loading plugin "upnp"... Mar 25 19:09:09 katarynka volumio[10600]: info: [1774462149093] Starting Upmpd Daemon Mar 25 19:09:09 katarynka volumio[10600]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 25 19:09:09 katarynka volumio[10600]: info: Loading plugin "my_music"... Mar 25 19:09:09 katarynka volumio[10600]: info: Loading plugin "mpd"... Mar 25 19:09:09 katarynka sudo[10657]: pam_unix(sudo:session): session closed for user root Mar 25 19:09:09 katarynka volumio[10600]: info: Loading plugin "upnp_browser"... Mar 25 19:09:11 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 43. Mar 25 19:09:11 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 19:09:11 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 19:09:11 katarynka go-librespot[10680]: go-librespot daemon starting... Mar 25 19:09:11 katarynka go-librespot[10681]: time="2026-03-25T19:09:11+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 19:09:11 katarynka go-librespot[10681]: time="2026-03-25T19:09:11+01:00" level=debug msg="app state loaded" Mar 25 19:09:11 katarynka go-librespot[10681]: time="2026-03-25T19:09:11+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 19:09:11 katarynka go-librespot[10681]: time="2026-03-25T19:09: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 19:09:11 katarynka go-librespot[10681]: time="2026-03-25T19:09: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 19:09:11 katarynka go-librespot[10681]: time="2026-03-25T19:09: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 19:09:12 katarynka go-librespot[10681]: time="2026-03-25T19:09:12+01:00" level=info msg="zeroconf server listening on port 44031" Mar 25 19:09:12 katarynka go-librespot[10681]: time="2026-03-25T19:09:12+01:00" level=debug msg="obtained new client token: AABDKxOKM8piaLrSY64qtCJQsMc6dGsEkRvw3cEICQMmmMA/A5Pyv1Nom2KRyFlMhttP6g4BoPqbooKnEDORwjjSS5f5sJaxJetCPplcpnIcxB5/Nw9KDdMf9FNrEOHPIyUXhAOqBc5BtUBwRi9yRkOHfGEXTzkgFpAomORI0y9unD+pOn4uvUOmZX4Pjf0+Q1jxamI7NO5Qg956yfABsjCm912Y0XevlZgjvlIdXRaxz8vrq0bkPj23" Mar 25 19:09:12 katarynka go-librespot[10681]: time="2026-03-25T19:09:12+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 19:09:12 katarynka go-librespot[10681]: time="2026-03-25T19:09:12+01:00" level=debug msg="completed keyexchange" Mar 25 19:09:12 katarynka go-librespot[10681]: time="2026-03-25T19:09:12+01:00" level=debug msg="completed challenge" Mar 25 19:09:12 katarynka go-librespot[10681]: time="2026-03-25T19:09: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 19:09:12 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 19:09:12 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 19:09:12 katarynka volumio[10600]: info: Starting UPNP Browser Mar 25 19:09:12 katarynka volumio[10600]: info: Loading plugin "alarm-clock"... Mar 25 19:09:13 katarynka volumio[10600]: info: Loading plugin "airplay_emulation"... Mar 25 19:09:13 katarynka volumio[10600]: info: Starting Shairport Sync Mar 25 19:09:13 katarynka volumio[10600]: info: Loading plugin "last_100"... Mar 25 19:09:13 katarynka volumio[10600]: info: Loading plugin "webradio"... Mar 25 19:09:13 katarynka volumio[10600]: info: Loading plugin "i2s_dacs"... Mar 25 19:09:13 katarynka volumio[10600]: info: Loading plugin "volumiodiscovery"... Mar 25 19:09:13 katarynka volumio[10600]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Mar 25 19:09:13 katarynka volumio[10600]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 25 19:09:13 katarynka volumio[10600]: *** WARNING *** For more information see Mar 25 19:09:13 katarynka volumio[10600]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Mar 25 19:09:13 katarynka volumio[10600]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 25 19:09:13 katarynka volumio[10600]: *** WARNING *** For more information see Mar 25 19:09:13 katarynka node[10600]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Mar 25 19:09:13 katarynka node[10600]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 25 19:09:13 katarynka node[10600]: *** WARNING *** For more information see Mar 25 19:09:13 katarynka node[10600]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Mar 25 19:09:13 katarynka node[10600]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 25 19:09:13 katarynka node[10600]: *** WARNING *** For more information see Mar 25 19:09:13 katarynka volumio[10600]: info: Applying required configuration parameters for plugin volumiodiscovery Mar 25 19:09:13 katarynka volumio[10600]: info: Discovery: Started advertising with name: katarynka Mar 25 19:09:13 katarynka volumio[10600]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 25 19:09:13 katarynka volumio[10600]: info: Loading plugin "spop"... Mar 25 19:09:15 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 44. Mar 25 19:09:15 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 19:09:15 katarynka volumio[10600]: info: Loading plugin "outputs"... Mar 25 19:09:15 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 19:09:15 katarynka go-librespot[10693]: go-librespot daemon starting... Mar 25 19:09:15 katarynka volumio[10600]: info: Loading plugin "albumart"... Mar 25 19:09:15 katarynka go-librespot[10694]: time="2026-03-25T19:09:15+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 19:09:15 katarynka go-librespot[10694]: time="2026-03-25T19:09:15+01:00" level=debug msg="app state loaded" Mar 25 19:09:15 katarynka go-librespot[10694]: time="2026-03-25T19:09:15+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 19:09:15 katarynka volumio[10600]: info: Plugin example_plugin is not enabled Mar 25 19:09:15 katarynka volumio[10600]: info: Loading plugin "inputs"... Mar 25 19:09:15 katarynka volumio[10600]: info: Loading plugin "updater_comm"... Mar 25 19:09:15 katarynka volumio[10600]: info: Plugin mpdemulation is not enabled Mar 25 19:09:15 katarynka volumio[10600]: info: Loading plugin "rest_api"... Mar 25 19:09:15 katarynka volumio[10600]: info: Loading plugin "websocket"... Mar 25 19:09:16 katarynka volumio[10600]: info: Starting Socket.io Server version 1.7.4 Mar 25 19:09:16 katarynka volumio[10600]: info: Loading i18n strings for locale pl Mar 25 19:09:16 katarynka volumio[10600]: Updating browse sources language Mar 25 19:09:16 katarynka volumio[10600]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 25 19:09:16 katarynka go-librespot[10694]: time="2026-03-25T19:09:16+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 25 19:09:16 katarynka go-librespot[10694]: time="2026-03-25T19:09:16+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 19:09:16 katarynka go-librespot[10694]: time="2026-03-25T19:09:16+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 19:09:16 katarynka go-librespot[10694]: time="2026-03-25T19:09:16+01:00" level=info msg="zeroconf server listening on port 36385" Mar 25 19:09:16 katarynka go-librespot[10694]: time="2026-03-25T19:09:16+01:00" level=debug msg="obtained new client token: AADD5DIHzNnKl+u8vic6+OtLLeITxoh1RnqnhotlMhgiBMZod1cKny/+yzyZT27MvZkNOM+NaLWySVVVv2bw23+d3iYJ3BbGsBrhISHRxR//PZuh8A1slzwkLYKd+WQ9nvPA5ytC1qmYW596MC16MotnIx61THctEyIS3mvjBSMrclIkBPhJPIfnnG93BjTQoWqVAt4a4lO0zyjzC/GC6A2lZpd/2u5k+g/Uy9esS+benhZWwigOa7sY" Mar 25 19:09:16 katarynka volumio[10600]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 25 19:09:16 katarynka go-librespot[10694]: time="2026-03-25T19:09:16+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 19:09:16 katarynka volumio[10600]: info: CoreCommandRouter::initPlayerControls Mar 25 19:09:16 katarynka volumio[10600]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 19:09:16 katarynka volumio[10600]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 19:09:16 katarynka volumio[10600]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 19:09:16 katarynka volumio[10600]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 19:09:16 katarynka volumio[10600]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 19:09:16 katarynka volumio[10600]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 19:09:16 katarynka volumio[10600]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 19:09:16 katarynka volumio[10600]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 19:09:16 katarynka volumio[10600]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 25 19:09:16 katarynka volumio[10600]: Express server listening on port 3000 Mar 25 19:09:16 katarynka volumio[10600]: [Metrics] WebUI: 12s 512.96ms Mar 25 19:09:16 katarynka go-librespot[10694]: time="2026-03-25T19:09:16+01:00" level=debug msg="completed keyexchange" Mar 25 19:09:16 katarynka go-librespot[10694]: time="2026-03-25T19:09:16+01:00" level=debug msg="completed challenge" Mar 25 19:09:16 katarynka volumio[10600]: info: CoreStateMachine::resetVolumioState Mar 25 19:09:16 katarynka volumio[10600]: info: CoreStateMachine::getcurrentVolume Mar 25 19:09:16 katarynka volumio[10600]: info: CoreCommandRouter::volumioRetrievevolume Mar 25 19:09:16 katarynka go-librespot[10694]: time="2026-03-25T19:09: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 19:09:16 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 19:09:16 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 19:09:16 katarynka volumio[10600]: info: Cannot read play queue from file Mar 25 19:09:16 katarynka volumio[10600]: info: Volumio Network Manager: Network status updated: 2 Mar 25 19:09:16 katarynka volumio[10700]: Forking 3 albumart workers Mar 25 19:09:16 katarynka volumio[10600]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 19:09:16 katarynka volumio[10600]: info: CoreStateMachine::setRepeat null single undefined Mar 25 19:09:16 katarynka volumio[10600]: info: CoreStateMachine::pushState Mar 25 19:09:16 katarynka volumio[10600]: info: CorePlayQueue::getTrack 0 Mar 25 19:09:16 katarynka volumio[10600]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 25 19:09:16 katarynka volumio[10600]: info: CoreCommandRouter::volumioPushState Mar 25 19:09:16 katarynka volumio[10600]: info: CoreStateMachine::setRandom null Mar 25 19:09:16 katarynka volumio[10600]: info: CoreStateMachine::pushState Mar 25 19:09:16 katarynka volumio[10600]: info: CorePlayQueue::getTrack 0 Mar 25 19:09:16 katarynka volumio[10600]: info: CoreCommandRouter::volumioPushState Mar 25 19:09:16 katarynka volumio[10600]: info: Setting Device type: Raspberry PI Mar 25 19:09:16 katarynka volumio[10600]: info: Completed loading Core Plugins Mar 25 19:09:16 katarynka volumio[10600]: info: Preparing to generate the ALSA configuration file Mar 25 19:09:16 katarynka volumio[10600]: info: VolumeController:: Volume=96 Mute =false Mar 25 19:09:17 katarynka volumio[10600]: info: CoreStateMachine::pushState Mar 25 19:09:17 katarynka volumio[10600]: info: CorePlayQueue::getTrack 0 Mar 25 19:09:17 katarynka volumio[10600]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 25 19:09:17 katarynka volumio[10600]: info: CoreCommandRouter::volumioPushState Mar 25 19:09:17 katarynka volumio[10600]: info: CoreStateMachine::updateTrackBlock Mar 25 19:09:17 katarynka volumio[10600]: info: CorePlayQueue::getTrackBlock Mar 25 19:09:17 katarynka volumio[10600]: info: CoreCommandRouter::volumioRetrievevolume Mar 25 19:09:17 katarynka volumio[10600]: info: Asound.conf file unchanged, so no further update is needed Mar 25 19:09:17 katarynka volumio[10600]: info: Output device has changed, restarting MPD Mar 25 19:09:17 katarynka volumio[10600]: info: Output device has changed, restarting Shairport Sync Mar 25 19:09:17 katarynka volumio[10600]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 19:09:17 katarynka volumio[10600]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 19:09:17 katarynka sudo[10755]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 25 19:09:17 katarynka volumio[10600]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 25 19:09:17 katarynka sudo[10755]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 19:09:17 katarynka volumio[10600]: info: ___________ START PLUGINS ___________ Mar 25 19:09:17 katarynka volumio[10600]: info: ControllerMpd::onStart: Initializing MPD Mar 25 19:09:17 katarynka volumio[10600]: info: Creating MPD Configuration file Mar 25 19:09:17 katarynka sudo[10755]: pam_unix(sudo:session): session closed for user root Mar 25 19:09:17 katarynka sudo[10757]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 25 19:09:17 katarynka sudo[10757]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 19:09:17 katarynka volumio[10600]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 25 19:09:17 katarynka volumio[10600]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 25 19:09:17 katarynka volumio[10600]: info: [1774462157481] CoreMusicLibrary::Adding element Serwery Mediów Mar 25 19:09:17 katarynka volumio[10600]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 25 19:09:17 katarynka volumio[10600]: info: UPNP Browser: Client initialized successfully Mar 25 19:09:17 katarynka sudo[10765]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 25 19:09:17 katarynka sudo[10765]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 19:09:17 katarynka systemd[1]: Stopping mpd.service - Music Player Daemon... Mar 25 19:09:17 katarynka sudo[10765]: pam_unix(sudo:session): session closed for user root Mar 25 19:09:17 katarynka upmpdcli[1473]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Mar 25 19:09:17 katarynka sudo[10767]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 25 19:09:17 katarynka sudo[10767]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 19:09:17 katarynka volumio[10600]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 19:09:17 katarynka volumio[10600]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 19:09:17 katarynka systemd[1]: mpd.service: Deactivated successfully. Mar 25 19:09:17 katarynka systemd[1]: Stopped mpd.service - Music Player Daemon. Mar 25 19:09:17 katarynka systemd[1]: mpd.service: Consumed 7.743s CPU time. Mar 25 19:09:17 katarynka systemd[1]: mpd.socket: Deactivated successfully. Mar 25 19:09:17 katarynka systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Mar 25 19:09:17 katarynka systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Mar 25 19:09:17 katarynka volumio[10600]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 25 19:09:17 katarynka volumio[10600]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 19:09:17 katarynka volumio[10600]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 19:09:17 katarynka systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Mar 25 19:09:17 katarynka systemd[1]: Starting mpd.service - Music Player Daemon... Mar 25 19:09:17 katarynka volumio[10600]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 25 19:09:17 katarynka volumio[10600]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 25 19:09:17 katarynka volumio[10600]: info: [1774462157879] CoreMusicLibrary::Adding element Last_100 Mar 25 19:09:17 katarynka volumio[10600]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 25 19:09:17 katarynka volumio[10600]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 25 19:09:17 katarynka volumio[10600]: info: [1774462157902] CoreMusicLibrary::Adding element Webradio Mar 25 19:09:17 katarynka volumio[10600]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 25 19:09:17 katarynka volumio[10600]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 25 19:09:17 katarynka volumio[10600]: info: Initializing BBC Radios Mar 25 19:09:18 katarynka volumio[10600]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 25 19:09:18 katarynka volumio[10600]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 19:09:18 katarynka volumio[10600]: info: Creating Spotify config file Mar 25 19:09:18 katarynka volumio[10600]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 19:09:18 katarynka volumio-remote-updater[686]: [2026-03-25 19:09:18] [connect] Successful connection Mar 25 19:09:18 katarynka sudo[10779]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Mar 25 19:09:18 katarynka sudo[10779]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Mar 25 19:09:18 katarynka sudo[10779]: pam_unix(sudo:session): session closed for user root Mar 25 19:09:19 katarynka volumio[10600]: info: Volumio Calling Home Mar 25 19:09:19 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 45. Mar 25 19:09:19 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 19:09:19 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 19:09:19 katarynka go-librespot[10815]: go-librespot daemon starting... Mar 25 19:09:19 katarynka go-librespot[10817]: time="2026-03-25T19:09:19+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 19:09:20 katarynka volumio[10721]: Starting albumart workers Mar 25 19:09:20 katarynka go-librespot[10817]: time="2026-03-25T19:09:20+01:00" level=info msg="zeroconf server listening on port 42103" Mar 25 19:09:20 katarynka sudo[10825]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 25 19:09:20 katarynka sudo[10825]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 19:09:20 katarynka sudo[10827]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 25 19:09:20 katarynka volumio[10600]: info: Discovery: adding 4d616d77-6a8c-4da2-85a4-840d70f98e51 Mar 25 19:09:20 katarynka volumio[10600]: info: Discovery: Found device katarynka Mar 25 19:09:20 katarynka sudo[10827]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 19:09:20 katarynka volumio[10600]: info: CoreCommandRouter::volumioGetState Mar 25 19:09:20 katarynka volumio[10600]: info: CorePlayQueue::getTrack 0 Mar 25 19:09:20 katarynka sudo[10825]: pam_unix(sudo:session): session closed for user root Mar 25 19:09:20 katarynka sudo[10827]: pam_unix(sudo:session): session closed for user root Mar 25 19:09:20 katarynka volumio[10600]: info: MPD Permissions set Mar 25 19:09:20 katarynka volumio[10600]: info: MPD Permissions set Mar 25 19:09:20 katarynka volumio[10600]: info: VolumeController:: Volume=96 Mute =false Mar 25 19:09:20 katarynka volumio[10600]: info: CoreStateMachine::pushState Mar 25 19:09:20 katarynka volumio[10600]: info: CorePlayQueue::getTrack 0 Mar 25 19:09:20 katarynka volumio[10600]: info: CoreCommandRouter::volumioPushState Mar 25 19:09:20 katarynka volumio-remote-updater[686]: [2026-03-25 19:09:20] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1774462158 101 Mar 25 19:09:20 katarynka volumio[10600]: 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 19:09:21 katarynka volumio[10600]: info: Volumio called home Mar 25 19:09:21 katarynka volumio[10600]: info: Spotify config file written Mar 25 19:09:21 katarynka volumio[10600]: info: Discovery: this is already registered, 4d616d77-6a8c-4da2-85a4-840d70f98e51 Mar 25 19:09:21 katarynka volumio[10600]: info: Discovery: Found device katarynka Mar 25 19:09:21 katarynka volumio[10600]: info: CoreCommandRouter::volumioGetState Mar 25 19:09:21 katarynka volumio[10600]: info: CorePlayQueue::getTrack 0 Mar 25 19:09:21 katarynka sudo[10831]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Mar 25 19:09:21 katarynka sudo[10831]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 19:09:21 katarynka volumio[10719]: Starting albumart workers Mar 25 19:09:21 katarynka volumio[10722]: Starting albumart workers Mar 25 19:09:21 katarynka systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Mar 25 19:09:21 katarynka systemd[1]: go-librespot-daemon.service: Killing process 10822 (n/a) with signal SIGKILL. Mar 25 19:09:21 katarynka systemd[1]: go-librespot-daemon.service: Deactivated successfully. Mar 25 19:09:21 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 19:09:21 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 19:09:21 katarynka go-librespot[10833]: go-librespot daemon starting... Mar 25 19:09:21 katarynka sudo[10831]: pam_unix(sudo:session): session closed for user root Mar 25 19:09:21 katarynka go-librespot[10834]: time="2026-03-25T19:09:21+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 19:09:21 katarynka go-librespot[10834]: time="2026-03-25T19:09:21+01:00" level=debug msg="app state loaded" Mar 25 19:09:21 katarynka go-librespot[10834]: time="2026-03-25T19:09:21+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 19:09:21 katarynka volumio[10600]: 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 19:09:21 katarynka volumio[10600]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 19:09:21 katarynka volumio[10600]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 19:09:21 katarynka volumio[10600]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 19:09:21 katarynka volumio[10600]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 19:09:21 katarynka volumio[10600]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 19:09:21 katarynka volumio[10600]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 19:09:21 katarynka volumio[10600]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 19:09:21 katarynka volumio[10600]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 19:09:21 katarynka volumio[10600]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 19:09:21 katarynka volumio[10600]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 19:09:21 katarynka volumio[10600]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 19:09:21 katarynka volumio[10600]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 19:09:21 katarynka volumio[10600]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 19:09:21 katarynka volumio[10600]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 19:09:21 katarynka volumio[10600]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 19:09:21 katarynka volumio[10600]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 19:09:21 katarynka volumio[10600]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 19:09:21 katarynka volumio[10600]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 19:09:21 katarynka volumio[10600]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 19:09:21 katarynka volumio[10600]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 19:09:21 katarynka volumio[10600]: info: No need to fix Spotify hosts Mar 25 19:09:22 katarynka go-librespot[10834]: time="2026-03-25T19:09:22+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 25 19:09:22 katarynka go-librespot[10834]: time="2026-03-25T19:09:22+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 19:09:22 katarynka go-librespot[10834]: time="2026-03-25T19:09:22+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 19:09:22 katarynka go-librespot[10834]: time="2026-03-25T19:09:22+01:00" level=info msg="zeroconf server listening on port 43167" Mar 25 19:09:22 katarynka go-librespot[10834]: time="2026-03-25T19:09:22+01:00" level=debug msg="obtained new client token: AACxJF8i0aXtbYU0q3aglgTNtm+j6LA/zT8axAMMe+Doe/vvITY+3M8/72+DL75trGTx9Kwqzz7gAHNQvdFG1UKb8GtDlEv9V3gby3kUtpl7l/VA3jOEA+4kt0xIcrgMUlRfPT0KGe7FgSb0pxNWobJoIprYJc+00P0s0N8CJcT5pk5Spw6DPzXm5R62nrUZm5Gx5fe2I8SYrQYEyi+Du8xhPR/kr2SG8n5LCLekNrJ/SYh5pc20RVqsDeg=" Mar 25 19:09:22 katarynka go-librespot[10834]: time="2026-03-25T19:09:22+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 19:09:22 katarynka go-librespot[10834]: time="2026-03-25T19:09:22+01:00" level=debug msg="completed keyexchange" Mar 25 19:09:22 katarynka go-librespot[10834]: time="2026-03-25T19:09:22+01:00" level=debug msg="completed challenge" Mar 25 19:09:22 katarynka go-librespot[10834]: time="2026-03-25T19:09:22+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 19:09:22 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 19:09:22 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 19:09:22 katarynka volumio[10600]: info: Starting Shairport Sync Mar 25 19:09:22 katarynka volumio[10600]: info: Starting Shairport Sync Mar 25 19:09:22 katarynka volumio[10600]: info: Starting Shairport Sync Mar 25 19:09:22 katarynka sudo[10860]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 25 19:09:22 katarynka sudo[10858]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 25 19:09:22 katarynka sudo[10860]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 19:09:22 katarynka sudo[10858]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 19:09:23 katarynka sudo[10862]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 25 19:09:23 katarynka sudo[10862]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 19:09:23 katarynka systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Mar 25 19:09:23 katarynka systemd[1]: shairport-sync.service: Deactivated successfully. Mar 25 19:09:23 katarynka systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 25 19:09:23 katarynka systemd[1]: shairport-sync.service: Consumed 2.213s CPU time. Mar 25 19:09:23 katarynka sudo[10864]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Mar 25 19:09:23 katarynka sudo[10864]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 19:09:23 katarynka systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 25 19:09:23 katarynka sudo[10860]: pam_unix(sudo:session): session closed for user root Mar 25 19:09:23 katarynka sudo[10858]: pam_unix(sudo:session): session closed for user root Mar 25 19:09:23 katarynka volumio[10600]: info: CoreCommandRouter::volumioGetState Mar 25 19:09:23 katarynka volumio[10600]: info: CorePlayQueue::getTrack 0 Mar 25 19:09:23 katarynka volumio[10600]: info: Shairport-Sync Started Mar 25 19:09:23 katarynka volumio[10600]: Error adding Membership: Error: addMembership EINVAL Mar 25 19:09:23 katarynka systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Mar 25 19:09:23 katarynka systemd[1]: shairport-sync.service: Deactivated successfully. Mar 25 19:09:23 katarynka systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 25 19:09:23 katarynka sudo[10864]: pam_unix(sudo:session): session closed for user root Mar 25 19:09:23 katarynka upmpdcli[1473]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Timeout Mar 25 19:09:23 katarynka upmpdcli[1473]: :2:../src/mpdcli.cxx:396::MPDCli::updStatus: connection failed Mar 25 19:09:23 katarynka upmpdcli[1473]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Mar 25 19:09:23 katarynka systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 25 19:09:23 katarynka volumio[10600]: info: Shairport-Sync Started Mar 25 19:09:23 katarynka sudo[10862]: pam_unix(sudo:session): session closed for user root Mar 25 19:09:23 katarynka volumio[10600]: info: Shairport-Sync Started Mar 25 19:09:23 katarynka volumio[10600]: info: Upmpdcli Daemon Started Mar 25 19:09:23 katarynka volumio[10600]: info: An error occurred while refreshing Spotify Token Error: Bad Request Mar 25 19:09:25 katarynka volumio[10600]: info: go-librespot daemon successfully initialized Mar 25 19:09:25 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Mar 25 19:09:25 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 19:09:26 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 19:09:26 katarynka go-librespot[10911]: go-librespot daemon starting... Mar 25 19:09:26 katarynka go-librespot[10912]: time="2026-03-25T19:09:26+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 19:09:26 katarynka go-librespot[10912]: time="2026-03-25T19:09:26+01:00" level=debug msg="app state loaded" Mar 25 19:09:26 katarynka go-librespot[10912]: time="2026-03-25T19:09:26+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 19:09:26 katarynka mpd[10797]: 2026-03-25T19:09:26 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Mar 25 19:09:26 katarynka systemd[1]: Started mpd.service - Music Player Daemon. Mar 25 19:09:26 katarynka upmpdcli[1473]: :3:../src/mpdcli.cxx:148::MPDCli::startEventLoop: already started Mar 25 19:09:26 katarynka sudo[10757]: pam_unix(sudo:session): session closed for user root Mar 25 19:09:26 katarynka sudo[10767]: pam_unix(sudo:session): session closed for user root Mar 25 19:09:26 katarynka volumio[10600]: info: Completed starting Core Plugins Mar 25 19:09:26 katarynka volumio[10600]: info: ------------------------------------------- Mar 25 19:09:26 katarynka volumio[10600]: info: ----- MyVolumio plugins startup ---- Mar 25 19:09:26 katarynka volumio[10600]: info: ------------------------------------------- Mar 25 19:09:26 katarynka volumio[10600]: info: [MyVolumio PluginManager] Fetching plans data.... Mar 25 19:09:26 katarynka volumio[10600]: error: MPD error: The expression evaluated to a falsy value: Mar 25 19:09:26 katarynka volumio[10600]: assert.ok(self.idling) Mar 25 19:09:26 katarynka volumio[10600]: error: The expression evaluated to a falsy value: Mar 25 19:09:26 katarynka volumio[10600]: assert.ok(self.idling) Mar 25 19:09:26 katarynka volumio[10600]: error: updateQueue error: null Mar 25 19:09:26 katarynka volumio[10600]: info: MPD running with PID10797 Mar 25 19:09:26 katarynka volumio[10600]: ,establishing connection Mar 25 19:09:26 katarynka volumio[10600]: error: updateQueue error: null Mar 25 19:09:26 katarynka go-librespot[10912]: time="2026-03-25T19:09:26+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Mar 25 19:09:26 katarynka go-librespot[10912]: time="2026-03-25T19:09:26+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 19:09:26 katarynka go-librespot[10912]: time="2026-03-25T19:09:26+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 19:09:26 katarynka go-librespot[10912]: time="2026-03-25T19:09:26+01:00" level=info msg="zeroconf server listening on port 33591" Mar 25 19:09:26 katarynka go-librespot[10912]: time="2026-03-25T19:09:26+01:00" level=debug msg="obtained new client token: AABOcQmMuvZ71tqRl0/1IxuNd7MIQbxQrbdpDsmDcnyC9Toj9pOTpAawJWU4p9q9gwnrK53OzsP+hp0i57GYtRfPjMXYLjhHLiNAZNrkNU3yW9H0Mp5pYekMTtl9u1zIsNkmFQDkMnl3WcGcONa+iidclm/JTwoXtgw+NHWXbSszTmfhmqcs4LGDzsB5Y8qyulY/Wn/rBHe6A9hmmLYLmosbtQ440G57z/ZuEiWbYYxSDjiJMbi9ldL0/4E=" Mar 25 19:09:26 katarynka go-librespot[10912]: time="2026-03-25T19:09:26+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 19:09:26 katarynka go-librespot[10912]: time="2026-03-25T19:09:26+01:00" level=debug msg="completed keyexchange" Mar 25 19:09:26 katarynka go-librespot[10912]: time="2026-03-25T19:09:26+01:00" level=debug msg="completed challenge" Mar 25 19:09:26 katarynka go-librespot[10912]: time="2026-03-25T19:09:26+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 19:09:26 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 19:09:26 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 19:09:28 katarynka volumio[10600]: info: Initializing connection to go-librespot Websocket Mar 25 19:09:28 katarynka volumio[10600]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 25 19:09:29 katarynka sudo[10933]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Mar 25 19:09:29 katarynka sudo[10933]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 19:09:29 katarynka sudo[10940]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Mar 25 19:09:29 katarynka sudo[10940]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 19:09:29 katarynka systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Mar 25 19:09:29 katarynka systemd[1]: mpd_monitor.service: Deactivated successfully. Mar 25 19:09:29 katarynka systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Mar 25 19:09:29 katarynka systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Mar 25 19:09:29 katarynka mpd_monitor.sh[10944]: MPD Monitor Service: Starting MPD Monitor Service Mar 25 19:09:29 katarynka sudo[10933]: pam_unix(sudo:session): session closed for user root Mar 25 19:09:29 katarynka sudo[10940]: pam_unix(sudo:session): session closed for user root Mar 25 19:09:29 katarynka volumio[10600]: info: Successfully started MPD Monitor Mar 25 19:09:29 katarynka volumio[10600]: info: Successfully started MPD Monitor Mar 25 19:09:29 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Mar 25 19:09:29 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 19:09:29 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 19:09:30 katarynka go-librespot[10948]: go-librespot daemon starting... Mar 25 19:09:30 katarynka go-librespot[10949]: time="2026-03-25T19:09:30+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 19:09:30 katarynka go-librespot[10949]: time="2026-03-25T19:09:30+01:00" level=debug msg="app state loaded" Mar 25 19:09:30 katarynka go-librespot[10949]: time="2026-03-25T19:09:30+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 19:09:30 katarynka go-librespot[10949]: time="2026-03-25T19:09:30+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 25 19:09:30 katarynka go-librespot[10949]: time="2026-03-25T19:09:30+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 19:09:30 katarynka go-librespot[10949]: time="2026-03-25T19:09:30+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 19:09:30 katarynka go-librespot[10949]: time="2026-03-25T19:09:30+01:00" level=info msg="zeroconf server listening on port 34343" Mar 25 19:09:30 katarynka go-librespot[10949]: time="2026-03-25T19:09:30+01:00" level=debug msg="obtained new client token: AABzgyu+8D2OlXjOBFwNUXLFy5t3ZvuqKEU6X/uWnt7KdqCEQTiDcnBe5xCThgS1ECKzYVQVZ2CJta5vun181ok47kdPdEUBeuoweBGhIAT39LxVYnjcYx7z3tf+ZBq7SsDpoYl1DcT7KuG9GKEdpXVOZCLJoOXvo7NkRF9DMFQOUHZSfHEyd6t+66sjRdG6Ge2BIb30XBbLuaAWdZPbyA6+C8HBaLqB9JxgTf+hdMUhpZP0k9tn0TuqFnE=" Mar 25 19:09:30 katarynka go-librespot[10949]: time="2026-03-25T19:09:30+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 19:09:30 katarynka go-librespot[10949]: time="2026-03-25T19:09:30+01:00" level=debug msg="completed keyexchange" Mar 25 19:09:30 katarynka go-librespot[10949]: time="2026-03-25T19:09:30+01:00" level=debug msg="completed challenge" Mar 25 19:09:30 katarynka go-librespot[10949]: time="2026-03-25T19:09:30+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 19:09:30 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 19:09:30 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 19:09:31 katarynka volumio[10600]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Mar 25 19:09:31 katarynka volumio[10600]: info: Initializing connection to go-librespot Websocket Mar 25 19:09:31 katarynka volumio[10600]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 25 19:09:33 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Mar 25 19:09:33 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 19:09:34 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 19:09:34 katarynka go-librespot[10957]: go-librespot daemon starting... Mar 25 19:09:34 katarynka go-librespot[10958]: time="2026-03-25T19:09:34+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 19:09:34 katarynka go-librespot[10958]: time="2026-03-25T19:09:34+01:00" level=debug msg="app state loaded" Mar 25 19:09:34 katarynka go-librespot[10958]: time="2026-03-25T19:09:34+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 19:09:34 katarynka volumio[10600]: info: Initializing connection to go-librespot Websocket Mar 25 19:09:34 katarynka go-librespot[10958]: time="2026-03-25T19:09:34+01:00" level=debug msg="new websocket client" Mar 25 19:09:34 katarynka volumio[10600]: info: Connection to go-librespot Websocket established Mar 25 19:09:34 katarynka go-librespot[10958]: time="2026-03-25T19:09:34+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 19:09:34 katarynka go-librespot[10958]: time="2026-03-25T19:09:34+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 19:09:34 katarynka go-librespot[10958]: time="2026-03-25T19:09:34+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 19:09:34 katarynka go-librespot[10958]: time="2026-03-25T19:09:34+01:00" level=info msg="zeroconf server listening on port 35843" Mar 25 19:09:35 katarynka volumio[10600]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Mar 25 19:09:35 katarynka volumio[10600]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Mar 25 19:09:35 katarynka volumio[10600]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Mar 25 19:09:35 katarynka volumio[10600]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Mar 25 19:09:35 katarynka volumio[10600]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Mar 25 19:09:35 katarynka volumio[10600]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Mar 25 19:09:35 katarynka volumio[10600]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Mar 25 19:09:35 katarynka volumio[10600]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Mar 25 19:09:35 katarynka volumio[10600]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Mar 25 19:09:35 katarynka volumio[10600]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Mar 25 19:09:35 katarynka volumio[10600]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Mar 25 19:09:35 katarynka volumio[10600]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Mar 25 19:09:35 katarynka volumio[10600]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Mar 25 19:09:35 katarynka volumio[10600]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Mar 25 19:09:35 katarynka volumio[10600]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Mar 25 19:09:35 katarynka volumio[10600]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Mar 25 19:09:35 katarynka volumio[10600]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Mar 25 19:09:35 katarynka volumio[10600]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Mar 25 19:09:35 katarynka volumio[10600]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Mar 25 19:09:35 katarynka volumio[10600]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Mar 25 19:09:35 katarynka volumio[10600]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Mar 25 19:09:35 katarynka volumio[10600]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Mar 25 19:09:35 katarynka volumio[10600]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Mar 25 19:09:35 katarynka volumio[10600]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Mar 25 19:09:35 katarynka volumio[10600]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Mar 25 19:09:35 katarynka volumio[10600]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Mar 25 19:09:35 katarynka volumio[10600]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Mar 25 19:09:35 katarynka volumio[10600]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Mar 25 19:09:35 katarynka volumio[10600]: info: Adding plugin bluetooth to MyMusic Plugins Mar 25 19:09:35 katarynka volumio[10600]: info: Adding plugin multiroom to MyMusic Plugins Mar 25 19:09:35 katarynka volumio[10600]: info: Adding plugin metavolumio to MyMusic Plugins Mar 25 19:09:35 katarynka volumio[10600]: info: Adding plugin cd_controller to MyMusic Plugins Mar 25 19:09:35 katarynka volumio[10600]: info: Adding plugin qobuzconnect to MyMusic Plugins Mar 25 19:09:35 katarynka volumio[10600]: info: Adding plugin smart_inputs to MyMusic Plugins Mar 25 19:09:35 katarynka volumio[10600]: info: Adding plugin tidalconnect to MyMusic Plugins Mar 25 19:09:35 katarynka volumio[10600]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Mar 25 19:09:35 katarynka go-librespot[10958]: time="2026-03-25T19:09:35+01:00" level=debug msg="obtained new client token: AAD0gmk6wSexxQw3msvtOeRcNuWTRWCusVAJjmtoKnpXDNqGS1VSHZkcyUh64Iq7xXHCZ7/ZbANQVkZYT6kTTVrgz/AmxezS1il7wlalwrXDDGqE64SWI3cofbq+xdRAjXk6XXufO2rcCdi4CFPbsdrp/tyjiC9Mza0dNjuGetXOvSchuzgu3PJMPJqBVanEF90FP7J61hb+70t7UNrpy3+atKABlvLOitToosnJkhEzmt18aGqQCAz5" Mar 25 19:09:35 katarynka go-librespot[10958]: time="2026-03-25T19:09:35+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 19:09:35 katarynka go-librespot[10958]: time="2026-03-25T19:09:35+01:00" level=debug msg="completed keyexchange" Mar 25 19:09:35 katarynka go-librespot[10958]: time="2026-03-25T19:09:35+01:00" level=debug msg="completed challenge" Mar 25 19:09:35 katarynka go-librespot[10958]: time="2026-03-25T19:09: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 19:09:35 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 19:09:35 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 19:09:37 katarynka volumio[10600]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Mar 25 19:09:37 katarynka volumio[10600]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Mar 25 19:09:37 katarynka volumio[10600]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 19:09:37 katarynka volumio[10600]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 19:09:37 katarynka volumio[10600]: info: Starting MyVolumio Remote Streaming Endpoints Mar 25 19:09:37 katarynka volumio[10600]: info: MyVolumio login type: Token Mar 25 19:09:37 katarynka volumio[10600]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Mar 25 19:09:37 katarynka volumio[10600]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Mar 25 19:09:38 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Mar 25 19:09:38 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 19:09:38 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 19:09:38 katarynka go-librespot[10966]: go-librespot daemon starting... Mar 25 19:09:38 katarynka go-librespot[10967]: time="2026-03-25T19:09:38+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 19:09:38 katarynka go-librespot[10967]: time="2026-03-25T19:09:38+01:00" level=debug msg="app state loaded" Mar 25 19:09:38 katarynka go-librespot[10967]: time="2026-03-25T19:09:38+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 19:09:38 katarynka volumio[10600]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Mar 25 19:09:38 katarynka volumio[10600]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Mar 25 19:09:38 katarynka volumio[10600]: info: Streaming services startup Mar 25 19:09:38 katarynka volumio[10600]: info: Starting Streaming Daemon Mar 25 19:09:39 katarynka go-librespot[10967]: time="2026-03-25T19:09:39+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 25 19:09:39 katarynka go-librespot[10967]: time="2026-03-25T19:09:39+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 25 19:09:39 katarynka go-librespot[10967]: time="2026-03-25T19:09:39+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 25 19:09:39 katarynka sudo[10975]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Mar 25 19:09:39 katarynka sudo[10975]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 19:09:39 katarynka volumio[10600]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Mar 25 19:09:39 katarynka go-librespot[10967]: time="2026-03-25T19:09:39+01:00" level=info msg="zeroconf server listening on port 33021" Mar 25 19:09:39 katarynka sudo[10975]: pam_unix(sudo:session): session closed for user root Mar 25 19:09:39 katarynka go-librespot[10967]: time="2026-03-25T19:09:39+01:00" level=debug msg="obtained new client token: AADF/6eK3Ci5TgB+sSDQ0zBNEUhbSWt+2AtKbQ+zuSmsLkaXYrCYgQvrl0ulb3AtYh9WyKYXFbv5ArCeqGH629qGKSK4gPBaGjoPtqURA4VawQLf0m9Bbx4O2SanL5P5pXAApMQlIkmgEHoAwA1oeT/sBlq1idP7fG44P2l8AU5MZwcrReqtEh2LvQXiFJPdOOp4WKMIgKY2Lou2uX0FDj+fM6YBIyRHg2R9LCC4RIYxgyKjQ0Upt5GF" Mar 25 19:09:39 katarynka volumio[10600]: info: Getting Spotify volume Mar 25 19:09:39 katarynka volumio[10600]: info: Connection to go-librespot Websocket closed Mar 25 19:09:39 katarynka volumio[10600]: error: Cannot start Volumio Streaming Daemon Mar 25 19:09:39 katarynka volumio[10600]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Mar 25 19:09:39 katarynka volumio[10600]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Mar 25 19:09:39 katarynka go-librespot[10967]: time="2026-03-25T19:09:39+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 19:09:39 katarynka volumio[10600]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Mar 25 19:09:39 katarynka go-librespot[10967]: time="2026-03-25T19:09:39+01:00" level=debug msg="completed keyexchange" Mar 25 19:09:39 katarynka go-librespot[10967]: time="2026-03-25T19:09:39+01:00" level=debug msg="completed challenge" Mar 25 19:09:39 katarynka go-librespot[10967]: time="2026-03-25T19:09:39+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 25 19:09:39 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 19:09:39 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 19:09:39 katarynka volumio[10600]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 25 19:09:39 katarynka volumio[10600]: Error: socket hang up Mar 25 19:09:39 katarynka volumio[10600]: at connResetException (node:internal/errors:720:14) Mar 25 19:09:39 katarynka volumio[10600]: at Socket.socketOnEnd (node:_http_client:519:23) Mar 25 19:09:39 katarynka volumio[10600]: at Socket.emit (node:events:526:35) Mar 25 19:09:39 katarynka volumio[10600]: at endReadableNT (node:internal/streams/readable:1376:12) Mar 25 19:09:39 katarynka volumio[10600]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Mar 25 19:09:39 katarynka volumio[10600]: code: 'ECONNRESET', Mar 25 19:09:39 katarynka volumio[10600]: response: undefined Mar 25 19:09:39 katarynka volumio[10600]: } Mar 25 19:09:39 katarynka volumio[10600]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 25 19:09:40 katarynka sudo[11009]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-03-25 19:08' Mar 25 19:09:40 katarynka sudo[11009]: 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"