Mar 25 17:46:59 katarynka sudo[19299]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 25 17:46:59 katarynka sudo[19299]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 17:47:00 katarynka volumio[19045]: info: An error occurred while refreshing Spotify Token Error: Bad Request Mar 25 17:47:00 katarynka sudo[19303]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Mar 25 17:47:00 katarynka sudo[19303]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 17:47:00 katarynka systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Mar 25 17:47:00 katarynka sudo[19303]: pam_unix(sudo:session): session closed for user root Mar 25 17:47:00 katarynka volumio[19045]: info: CoreCommandRouter::volumioGetState Mar 25 17:47:00 katarynka volumio[19045]: info: CorePlayQueue::getTrack 0 Mar 25 17:47:00 katarynka systemd[1]: shairport-sync.service: Deactivated successfully. Mar 25 17:47:00 katarynka systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 25 17:47:00 katarynka systemd[1]: shairport-sync.service: Consumed 2.368s CPU time. Mar 25 17:47:00 katarynka volumio[19045]: info: Upmpdcli Daemon Started Mar 25 17:47:00 katarynka systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 25 17:47:00 katarynka sudo[19295]: pam_unix(sudo:session): session closed for user root Mar 25 17:47:00 katarynka sudo[19299]: pam_unix(sudo:session): session closed for user root Mar 25 17:47:00 katarynka sudo[19297]: pam_unix(sudo:session): session closed for user root Mar 25 17:47:00 katarynka volumio[19045]: info: Shairport-Sync Started Mar 25 17:47:00 katarynka volumio[19045]: Error adding Membership: Error: addMembership EINVAL Mar 25 17:47:00 katarynka volumio[19045]: info: Shairport-Sync Started Mar 25 17:47:00 katarynka volumio[19045]: info: Shairport-Sync Started Mar 25 17:47:02 katarynka mpd[19240]: 2026-03-25T17:47:02 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Mar 25 17:47:02 katarynka volumio[19045]: info: go-librespot daemon successfully initialized Mar 25 17:47:02 katarynka systemd[1]: Started mpd.service - Music Player Daemon. Mar 25 17:47:02 katarynka sudo[19203]: pam_unix(sudo:session): session closed for user root Mar 25 17:47:02 katarynka sudo[19193]: pam_unix(sudo:session): session closed for user root Mar 25 17:47:02 katarynka volumio[19045]: info: Completed starting Core Plugins Mar 25 17:47:02 katarynka volumio[19045]: info: ------------------------------------------- Mar 25 17:47:02 katarynka volumio[19045]: info: ----- MyVolumio plugins startup ---- Mar 25 17:47:02 katarynka volumio[19045]: info: ------------------------------------------- Mar 25 17:47:02 katarynka volumio[19045]: info: [MyVolumio PluginManager] Fetching plans data.... Mar 25 17:47:02 katarynka volumio[19045]: error: MPD error: The expression evaluated to a falsy value: Mar 25 17:47:02 katarynka volumio[19045]: assert.ok(self.idling) Mar 25 17:47:02 katarynka volumio[19045]: error: The expression evaluated to a falsy value: Mar 25 17:47:02 katarynka volumio[19045]: assert.ok(self.idling) Mar 25 17:47:02 katarynka volumio[19045]: error: updateQueue error: null Mar 25 17:47:02 katarynka volumio[19045]: info: MPD running with PID19240 Mar 25 17:47:02 katarynka volumio[19045]: ,establishing connection Mar 25 17:47:02 katarynka volumio[19045]: error: updateQueue error: null Mar 25 17:47:03 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Mar 25 17:47:03 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 17:47:03 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 17:47:03 katarynka go-librespot[19342]: go-librespot daemon starting... Mar 25 17:47:03 katarynka go-librespot[19343]: time="2026-03-25T17:47:03+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 17:47:03 katarynka go-librespot[19343]: time="2026-03-25T17:47:03+01:00" level=debug msg="app state loaded" Mar 25 17:47:03 katarynka go-librespot[19343]: time="2026-03-25T17:47:03+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 17:47:03 katarynka go-librespot[19343]: time="2026-03-25T17:47: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 17:47:03 katarynka go-librespot[19343]: time="2026-03-25T17:47: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 17:47:03 katarynka go-librespot[19343]: time="2026-03-25T17:47: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 17:47:03 katarynka go-librespot[19343]: time="2026-03-25T17:47:03+01:00" level=info msg="zeroconf server listening on port 35969" Mar 25 17:47:03 katarynka go-librespot[19343]: time="2026-03-25T17:47:03+01:00" level=debug msg="obtained new client token: AAD/m8VHftCAKIKkmcyHoz8DFqCpzQZjKRG6cnSjsix4F5veUlwGFbFmJkHVuED3MCW+MpPLjuKterfyUwKKOQzzd/K0AhBkWcmoVucluhYAZiV7l3voQq0ITK6vQ1zSTEdtOWulXfmVPOY4G2HGcG7HD1OcChnQmmJt/ztNNuIyu+vISQaKSNtC89X3q+xZxiBkxT7FeYpQ88EJv6gdnaCRwaHk5NwyN4gaMaaZDhajQekSCC482dPvj3Q=" Mar 25 17:47:03 katarynka go-librespot[19343]: time="2026-03-25T17:47:03+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 17:47:03 katarynka go-librespot[19343]: time="2026-03-25T17:47:03+01:00" level=debug msg="completed keyexchange" Mar 25 17:47:03 katarynka go-librespot[19343]: time="2026-03-25T17:47:03+01:00" level=debug msg="completed challenge" Mar 25 17:47:03 katarynka go-librespot[19343]: time="2026-03-25T17:47:03+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 25 17:47:03 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 17:47:03 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 17:47:05 katarynka volumio[19045]: info: Initializing connection to go-librespot Websocket Mar 25 17:47:05 katarynka volumio[19045]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 25 17:47:05 katarynka sudo[19351]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Mar 25 17:47:05 katarynka sudo[19351]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 17:47:05 katarynka sudo[19353]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Mar 25 17:47:05 katarynka sudo[19353]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 17:47:05 katarynka systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Mar 25 17:47:05 katarynka systemd[1]: mpd_monitor.service: Deactivated successfully. Mar 25 17:47:05 katarynka systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Mar 25 17:47:05 katarynka systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Mar 25 17:47:05 katarynka sudo[19351]: pam_unix(sudo:session): session closed for user root Mar 25 17:47:05 katarynka sudo[19353]: pam_unix(sudo:session): session closed for user root Mar 25 17:47:05 katarynka mpd_monitor.sh[19356]: MPD Monitor Service: Starting MPD Monitor Service Mar 25 17:47:05 katarynka volumio[19045]: info: Successfully started MPD Monitor Mar 25 17:47:05 katarynka volumio[19045]: info: Successfully started MPD Monitor Mar 25 17:47:07 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Mar 25 17:47:07 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 17:47:07 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 17:47:07 katarynka go-librespot[19374]: go-librespot daemon starting... Mar 25 17:47:07 katarynka go-librespot[19375]: time="2026-03-25T17:47:07+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 17:47:07 katarynka go-librespot[19375]: time="2026-03-25T17:47:07+01:00" level=debug msg="app state loaded" Mar 25 17:47:07 katarynka go-librespot[19375]: time="2026-03-25T17:47:07+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 17:47:07 katarynka go-librespot[19375]: time="2026-03-25T17:47:07+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 25 17:47:07 katarynka go-librespot[19375]: time="2026-03-25T17:47:07+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 25 17:47:07 katarynka go-librespot[19375]: time="2026-03-25T17:47:07+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 25 17:47:07 katarynka go-librespot[19375]: time="2026-03-25T17:47:07+01:00" level=info msg="zeroconf server listening on port 39199" Mar 25 17:47:07 katarynka go-librespot[19375]: time="2026-03-25T17:47:07+01:00" level=debug msg="obtained new client token: AABos0rkyDe8niHtzJbSOmicIMKWQn3QSW3alwn6INu48iZ8KVAD+NWgGz/US9ROpzhTMR4sad6+Ioj2Vv+JhVsdEYi+EXx+oiPILznJqRq8i4/9tWXdL+LkFKj9Hu+mynvQWDCDiddBBm089xugdcVycOcnpZSYuEcdtRgu3Cnsn1Fxkf8Wm+vj3cUTv8lC+axc5t/Mg+hb/fY4ElcdlBBYxX+wX6lbygig8Wy+onTW4Xj/HurVgmIrJj0=" Mar 25 17:47:07 katarynka go-librespot[19375]: time="2026-03-25T17:47:07+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 17:47:07 katarynka volumio[19045]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Mar 25 17:47:07 katarynka go-librespot[19375]: time="2026-03-25T17:47:07+01:00" level=debug msg="connected to ap-gew4.spotify.com:443" Mar 25 17:47:08 katarynka go-librespot[19375]: time="2026-03-25T17:47:08+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: read tcp 192.168.100.107:40082->34.158.1.133:443: read: connection reset by peer" Mar 25 17:47:08 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 17:47:08 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 17:47:08 katarynka volumio[19045]: info: Initializing connection to go-librespot Websocket Mar 25 17:47:08 katarynka volumio[19045]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 25 17:47:11 katarynka volumio[19045]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Mar 25 17:47:11 katarynka volumio[19045]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Mar 25 17:47:11 katarynka volumio[19045]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Mar 25 17:47:11 katarynka volumio[19045]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Mar 25 17:47:11 katarynka volumio[19045]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Mar 25 17:47:11 katarynka volumio[19045]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Mar 25 17:47:11 katarynka volumio[19045]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Mar 25 17:47:11 katarynka volumio[19045]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Mar 25 17:47:11 katarynka volumio[19045]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Mar 25 17:47:11 katarynka volumio[19045]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Mar 25 17:47:11 katarynka volumio[19045]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Mar 25 17:47:11 katarynka volumio[19045]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Mar 25 17:47:11 katarynka volumio[19045]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Mar 25 17:47:11 katarynka volumio[19045]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Mar 25 17:47:11 katarynka volumio[19045]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Mar 25 17:47:11 katarynka volumio[19045]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Mar 25 17:47:11 katarynka volumio[19045]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Mar 25 17:47:11 katarynka volumio[19045]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Mar 25 17:47:11 katarynka volumio[19045]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Mar 25 17:47:11 katarynka volumio[19045]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Mar 25 17:47:11 katarynka volumio[19045]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Mar 25 17:47:11 katarynka volumio[19045]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Mar 25 17:47:11 katarynka volumio[19045]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Mar 25 17:47:11 katarynka volumio[19045]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Mar 25 17:47:11 katarynka volumio[19045]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Mar 25 17:47:11 katarynka volumio[19045]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Mar 25 17:47:11 katarynka volumio[19045]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Mar 25 17:47:11 katarynka volumio[19045]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Mar 25 17:47:11 katarynka volumio[19045]: info: Adding plugin bluetooth to MyMusic Plugins Mar 25 17:47:11 katarynka volumio[19045]: info: Adding plugin multiroom to MyMusic Plugins Mar 25 17:47:11 katarynka volumio[19045]: info: Adding plugin metavolumio to MyMusic Plugins Mar 25 17:47:11 katarynka volumio[19045]: info: Adding plugin cd_controller to MyMusic Plugins Mar 25 17:47:11 katarynka volumio[19045]: info: Adding plugin qobuzconnect to MyMusic Plugins Mar 25 17:47:11 katarynka volumio[19045]: info: Adding plugin smart_inputs to MyMusic Plugins Mar 25 17:47:11 katarynka volumio[19045]: info: Adding plugin tidalconnect to MyMusic Plugins Mar 25 17:47:11 katarynka volumio[19045]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Mar 25 17:47:11 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Mar 25 17:47:11 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 17:47:11 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 17:47:11 katarynka go-librespot[19383]: go-librespot daemon starting... Mar 25 17:47:11 katarynka go-librespot[19384]: time="2026-03-25T17:47:11+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 17:47:11 katarynka go-librespot[19384]: time="2026-03-25T17:47:11+01:00" level=debug msg="app state loaded" Mar 25 17:47:11 katarynka go-librespot[19384]: time="2026-03-25T17:47:11+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 17:47:11 katarynka go-librespot[19384]: time="2026-03-25T17:47: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-gew1.spotify.com:80]" Mar 25 17:47:11 katarynka go-librespot[19384]: time="2026-03-25T17:47:11+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 17:47:11 katarynka go-librespot[19384]: time="2026-03-25T17:47:11+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 17:47:11 katarynka go-librespot[19384]: time="2026-03-25T17:47:11+01:00" level=info msg="zeroconf server listening on port 45821" Mar 25 17:47:12 katarynka go-librespot[19384]: time="2026-03-25T17:47:12+01:00" level=debug msg="obtained new client token: AABwApfZF520IBacTBb+7hOiFu9LHbst8OIt+fwDEi2S9BRhes9+AnvPZDHZv5GFj461dEJVEOcYHL9cFnIL7RFg10Ng3OSkuk2xzkWU1uz9TAX8yeVUjGuTg/6Bkn8GdFvMtRZYwRfc4iN0rx2XCj23M8o2yYnWQwteFRhQKIOz43xB752l0pyMT/8iSRfXTNQgrDZ1VflpHb/GC+1TcveybuGjG0qXfYtNL333WiBb5u/rrs4bb1w9" Mar 25 17:47:12 katarynka go-librespot[19384]: time="2026-03-25T17:47:12+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 17:47:12 katarynka go-librespot[19384]: time="2026-03-25T17:47:12+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Mar 25 17:47:12 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 17:47:12 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 17:47:13 katarynka volumio[19045]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Mar 25 17:47:13 katarynka volumio[19045]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Mar 25 17:47:13 katarynka volumio[19045]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 17:47:13 katarynka volumio[19045]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 17:47:13 katarynka volumio[19045]: info: Starting MyVolumio Remote Streaming Endpoints Mar 25 17:47:13 katarynka volumio[19045]: info: MyVolumio login type: Token Mar 25 17:47:13 katarynka volumio[19045]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Mar 25 17:47:13 katarynka volumio[19045]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Mar 25 17:47:14 katarynka volumio[19045]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Mar 25 17:47:14 katarynka volumio[19045]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Mar 25 17:47:14 katarynka volumio[19045]: info: Streaming services startup Mar 25 17:47:14 katarynka volumio[19045]: info: Starting Streaming Daemon Mar 25 17:47:15 katarynka sudo[19395]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Mar 25 17:47:15 katarynka sudo[19395]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 17:47:15 katarynka volumio[19045]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Mar 25 17:47:15 katarynka sudo[19395]: pam_unix(sudo:session): session closed for user root Mar 25 17:47:15 katarynka volumio[19045]: info: Initializing connection to go-librespot Websocket Mar 25 17:47:15 katarynka volumio[19045]: error: Cannot start Volumio Streaming Daemon Mar 25 17:47:15 katarynka volumio[19045]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Mar 25 17:47:15 katarynka volumio[19045]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Mar 25 17:47:15 katarynka volumio[19045]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 25 17:47:15 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Mar 25 17:47:15 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 17:47:15 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 17:47:15 katarynka go-librespot[19401]: go-librespot daemon starting... Mar 25 17:47:15 katarynka go-librespot[19402]: time="2026-03-25T17:47:15+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 17:47:15 katarynka go-librespot[19402]: time="2026-03-25T17:47:15+01:00" level=debug msg="app state loaded" Mar 25 17:47:15 katarynka go-librespot[19402]: time="2026-03-25T17:47:15+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 17:47:15 katarynka go-librespot[19402]: time="2026-03-25T17:47:15+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 25 17:47:15 katarynka go-librespot[19402]: time="2026-03-25T17:47:15+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 25 17:47:15 katarynka go-librespot[19402]: time="2026-03-25T17:47:15+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 25 17:47:15 katarynka go-librespot[19402]: time="2026-03-25T17:47:15+01:00" level=info msg="zeroconf server listening on port 44109" Mar 25 17:47:15 katarynka go-librespot[19402]: time="2026-03-25T17:47:15+01:00" level=debug msg="obtained new client token: AAB2kJZLy6PtUPZ2rxlDDdRiSe+XfyDBRey1TG78Cp+EAhuTqi7tnQGIGuMfcsUbcJmWVchShTzt8ZGo6dl73rX/TMxuyP3ARqlTf9od81Z1Tj1WU+BW7NimSjo5QXLm3NG9YePC1ZzBWkmYbqQigKFKekCukOCt4lxHLUb6y6/yY3gckKbotNGDlxOiqaiHUEjZ2Jfag6DwsUdnpYtWwnUUZJAscijixQENLDJ77j3MGM91r6LR3eRkJTE=" Mar 25 17:47:16 katarynka go-librespot[19402]: time="2026-03-25T17:47:16+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 17:47:16 katarynka go-librespot[19402]: time="2026-03-25T17:47:16+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Mar 25 17:47:16 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 17:47:16 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 17:47:16 katarynka volumio[19045]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Mar 25 17:47:17 katarynka volumio[19045]: info: MyVolumio token set successfully Mar 25 17:47:17 katarynka volumio[19045]: info: MYVOLUMIO: Adding device Mar 25 17:47:17 katarynka volumio[19045]: info: MYVOLUMIO: Evaluating Server Mar 25 17:47:17 katarynka volumio[19045]: info: MyVolumio status changed Mar 25 17:47:17 katarynka volumio[19045]: info: Streaming services startup Mar 25 17:47:17 katarynka volumio[19045]: info: Starting Streaming Daemon Mar 25 17:47:17 katarynka volumio[19045]: info: Removing browser output: myVolumio user plan is not superstar Mar 25 17:47:17 katarynka volumio[19045]: info: Removing audio output: Mar 25 17:47:17 katarynka volumio[19045]: info: Stoppping Tunnel 1 Mar 25 17:47:17 katarynka sudo[19446]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Mar 25 17:47:17 katarynka sudo[19446]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 17:47:17 katarynka sudo[19449]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Mar 25 17:47:17 katarynka sudo[19449]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 17:47:17 katarynka sudo[19446]: pam_unix(sudo:session): session closed for user root Mar 25 17:47:17 katarynka volumio[19045]: error: Cannot start Volumio Streaming Daemon Mar 25 17:47:17 katarynka volumio[19045]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Mar 25 17:47:17 katarynka volumio[19045]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Mar 25 17:47:17 katarynka systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Mar 25 17:47:17 katarynka systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Mar 25 17:47:17 katarynka systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Mar 25 17:47:17 katarynka systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Mar 25 17:47:17 katarynka systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Mar 25 17:47:17 katarynka systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Mar 25 17:47:17 katarynka systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Mar 25 17:47:17 katarynka systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Mar 25 17:47:17 katarynka sudo[19449]: pam_unix(sudo:session): session closed for user root Mar 25 17:47:17 katarynka volumio[19045]: info: Remote SSH Stopped Mar 25 17:47:17 katarynka volumio[19045]: info: Setting Geolocation for MyVolumio to eu7 Mar 25 17:47:17 katarynka volumio[19045]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 17:47:17 katarynka volumio[19045]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 17:47:17 katarynka volumio[19045]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 17:47:18 katarynka volumio[19045]: info: Initializing connection to go-librespot Websocket Mar 25 17:47:18 katarynka volumio[19045]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 25 17:47:18 katarynka volumio[19045]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Mar 25 17:47:18 katarynka volumio[19045]: info: Updating MyVolumio device info Mar 25 17:47:18 katarynka volumio[19045]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 17:47:18 katarynka volumio[19045]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 17:47:18 katarynka volumio[19045]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 17:47:19 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Mar 25 17:47:19 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 17:47:19 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 17:47:19 katarynka go-librespot[19453]: go-librespot daemon starting... Mar 25 17:47:19 katarynka go-librespot[19454]: time="2026-03-25T17:47:19+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 17:47:19 katarynka go-librespot[19454]: time="2026-03-25T17:47:19+01:00" level=debug msg="app state loaded" Mar 25 17:47:19 katarynka go-librespot[19454]: time="2026-03-25T17:47:19+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 17:47:19 katarynka volumio[19045]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Mar 25 17:47:19 katarynka go-librespot[19454]: time="2026-03-25T17:47:19+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 25 17:47:19 katarynka go-librespot[19454]: time="2026-03-25T17:47:19+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 25 17:47:19 katarynka go-librespot[19454]: time="2026-03-25T17:47:19+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 25 17:47:19 katarynka go-librespot[19454]: time="2026-03-25T17:47:19+01:00" level=info msg="zeroconf server listening on port 36089" Mar 25 17:47:19 katarynka go-librespot[19454]: time="2026-03-25T17:47:19+01:00" level=debug msg="obtained new client token: AABuQ/8ASNCVrzMeRIOAjQmTE8+zwxSf8tpb9zkRd1lJXz4cgoP1Jo2QvBIsBA5Lzgzze8sRzUVO632xNPgxtGgcL07BK604rmjrs3OcWW1X+Ngi4EZnAMcW0zowOe66GdqWzzDD7iU4sDjj5Mt7fLDUrZJA1etlRXzXMxusPZStXFYlwt5+Hl4KUGjK9EZ/atBwbI9wjOPc0ZdJfR7cTbIXNXlAVxklDHl1J8Pb53MiTf0PSHl6af3C9O4=" Mar 25 17:47:19 katarynka go-librespot[19454]: time="2026-03-25T17:47:19+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 17:47:19 katarynka go-librespot[19454]: time="2026-03-25T17:47:19+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Mar 25 17:47:19 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 17:47:19 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 17:47:21 katarynka volumio[19045]: info: Initializing connection to go-librespot Websocket Mar 25 17:47:21 katarynka volumio[19045]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 25 17:47:22 katarynka volumio[19045]: info: MYVOLUMIO: Adding device Mar 25 17:47:22 katarynka volumio[19045]: info: MYVOLUMIO: Evaluating Server Mar 25 17:47:23 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Mar 25 17:47:23 katarynka volumio[19045]: info: Setting Geolocation for MyVolumio to eu10 Mar 25 17:47:23 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 17:47:23 katarynka volumio[19045]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 17:47:23 katarynka volumio[19045]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 17:47:23 katarynka volumio[19045]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 17:47:23 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 17:47:23 katarynka go-librespot[19479]: go-librespot daemon starting... Mar 25 17:47:23 katarynka go-librespot[19480]: time="2026-03-25T17:47:23+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 17:47:23 katarynka go-librespot[19480]: time="2026-03-25T17:47:23+01:00" level=debug msg="app state loaded" Mar 25 17:47:23 katarynka go-librespot[19480]: time="2026-03-25T17:47:23+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 17:47:23 katarynka volumio[19045]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Mar 25 17:47:23 katarynka go-librespot[19480]: time="2026-03-25T17:47:23+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 25 17:47:23 katarynka go-librespot[19480]: time="2026-03-25T17:47:23+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 25 17:47:23 katarynka go-librespot[19480]: time="2026-03-25T17:47:23+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 25 17:47:23 katarynka go-librespot[19480]: time="2026-03-25T17:47:23+01:00" level=info msg="zeroconf server listening on port 45017" Mar 25 17:47:23 katarynka go-librespot[19480]: time="2026-03-25T17:47:23+01:00" level=debug msg="obtained new client token: AABZNHDbVYQ9WDOOL1RFkCSAQcrZDDU1p0xMm/Hj8i8f/YavYdzE/pswuNB6w73PwHRNVvrCslHk/kywvkGTCg6lDuZBlf01U5fbFWOSpAA/ZLg0SDl3U7tJsZybzO2a3h+D3olILdZptUOeexu4OJ1cQ26kjUB0hsacmOECAbS8+ZzeFK+1xGNvtaOlaEZWFuPW3Ekxne1fcCAvAkadkuQIufHNzR1i/qyMYzJGmANM2MyJZr8CRpZ74Uw=" Mar 25 17:47:23 katarynka go-librespot[19480]: time="2026-03-25T17:47:23+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 17:47:23 katarynka go-librespot[19480]: time="2026-03-25T17:47:23+01:00" level=debug msg="completed keyexchange" Mar 25 17:47:23 katarynka go-librespot[19480]: time="2026-03-25T17:47:23+01:00" level=debug msg="completed challenge" Mar 25 17:47:23 katarynka go-librespot[19480]: time="2026-03-25T17:47:23+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 25 17:47:23 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 17:47:23 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 17:47:24 katarynka volumio[19045]: info: Updating MyVolumio device info Mar 25 17:47:24 katarynka volumio[19045]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 17:47:24 katarynka volumio[19045]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 17:47:24 katarynka volumio[19045]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 17:47:24 katarynka volumio[19045]: info: Initializing connection to go-librespot Websocket Mar 25 17:47:24 katarynka volumio[19045]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 25 17:47:24 katarynka volumio[19045]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Mar 25 17:47:26 katarynka volumio[19045]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 25 17:47:26 katarynka volumio[19045]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 17:47:26 katarynka volumio[19045]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Mar 25 17:47:26 katarynka volumio-remote-updater[665]: Test mode disabled Mar 25 17:47:26 katarynka volumio-remote-updater[665]: Alpha mode disabled Mar 25 17:47:26 katarynka volumio-remote-updater[665]: Alpha legacy test mode disabled Mar 25 17:47:26 katarynka volumio[19045]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled Mar 25 17:47:27 katarynka volumio[19045]: info: Update Ready: {"changeLogLink":"http://volumio.org","description":"

FIXES

\n
    \n
  • Fix for BLE notification issues
    • \n
  • Fix for mDNS/BCT
    • \n
  • Fix wireless init on Pi
    • \n
  • Fix raspi-config abuse on Pi
    • \n
\n

NEW ADDITIONS

\n
    \n
  • Bluetooth party mode
    • \n
  • Update Tidal SDK
    • \n
  • Update Qobuz Connect SDK
    • \n
\n","title":"Update v4.103","updateavailable":true} Mar 25 17:47:27 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Mar 25 17:47:27 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 17:47:27 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 17:47:27 katarynka go-librespot[19508]: go-librespot daemon starting... Mar 25 17:47:27 katarynka volumio[19045]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Mar 25 17:47:27 katarynka go-librespot[19509]: time="2026-03-25T17:47:27+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 17:47:27 katarynka go-librespot[19509]: time="2026-03-25T17:47:27+01:00" level=debug msg="app state loaded" Mar 25 17:47:27 katarynka go-librespot[19509]: time="2026-03-25T17:47:27+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 17:47:27 katarynka volumio[19045]: info: Initializing connection to go-librespot Websocket Mar 25 17:47:27 katarynka go-librespot[19509]: time="2026-03-25T17:47:27+01:00" level=debug msg="new websocket client" Mar 25 17:47:27 katarynka volumio[19045]: info: Connection to go-librespot Websocket established Mar 25 17:47:27 katarynka go-librespot[19509]: time="2026-03-25T17:47:27+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 25 17:47:27 katarynka go-librespot[19509]: time="2026-03-25T17:47:27+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 25 17:47:27 katarynka go-librespot[19509]: time="2026-03-25T17:47:27+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 25 17:47:27 katarynka go-librespot[19509]: time="2026-03-25T17:47:27+01:00" level=info msg="zeroconf server listening on port 39935" Mar 25 17:47:27 katarynka go-librespot[19509]: time="2026-03-25T17:47:27+01:00" level=debug msg="obtained new client token: AADLRzaXGxRNs63K/KfAp4Y+IgZAMEjN3rj+49d7OL3opqToDIFWhm5a66QIoVV+ehnv1ChxDTbMEaipNwFF2y+7FtQt4a/0jfs/FFdYc0K7Fd+gJBWl16bjzBvUFafbNzlnmDOkIlLe36UkXMth5hUrby2+aseXRTAKaB+fs9EnPMkwDK4lZO3FB7b0ilNwTu6bD9nfzguZmhrLmjg+J4TztfECtQSdS6rhBMv8tc0tNIyABLvoIRULzIo=" Mar 25 17:47:27 katarynka go-librespot[19509]: time="2026-03-25T17:47:27+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 17:47:27 katarynka go-librespot[19509]: time="2026-03-25T17:47:27+01:00" level=debug msg="completed keyexchange" Mar 25 17:47:27 katarynka go-librespot[19509]: time="2026-03-25T17:47:27+01:00" level=debug msg="completed challenge" Mar 25 17:47:27 katarynka go-librespot[19509]: time="2026-03-25T17:47:27+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 25 17:47:27 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 17:47:27 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 17:47:27 katarynka volumio[19045]: info: Connection to go-librespot Websocket closed Mar 25 17:47:28 katarynka volumio[19045]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Mar 25 17:47:28 katarynka volumio[19045]: 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 17:47:28 katarynka volumio[19045]: info: CoreCommandRouter::volumioGetState Mar 25 17:47:28 katarynka volumio[19045]: info: CorePlayQueue::getTrack 0 Mar 25 17:47:30 katarynka volumio[19045]: info: Getting Spotify volume Mar 25 17:47:30 katarynka volumio[19045]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 25 17:47:30 katarynka volumio[19045]: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 25 17:47:30 katarynka volumio[19045]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Mar 25 17:47:30 katarynka volumio[19045]: errno: -111, Mar 25 17:47:30 katarynka volumio[19045]: code: 'ECONNREFUSED', Mar 25 17:47:30 katarynka volumio[19045]: syscall: 'connect', Mar 25 17:47:30 katarynka volumio[19045]: address: '127.0.0.1', Mar 25 17:47:30 katarynka volumio[19045]: port: 9879, Mar 25 17:47:30 katarynka volumio[19045]: response: undefined Mar 25 17:47:30 katarynka volumio[19045]: } Mar 25 17:47:30 katarynka volumio[19045]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 25 17:47:31 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Mar 25 17:47:31 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 17:47:31 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 17:47:31 katarynka go-librespot[19528]: go-librespot daemon starting... Mar 25 17:47:31 katarynka go-librespot[19529]: time="2026-03-25T17:47:31+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 17:47:31 katarynka go-librespot[19529]: time="2026-03-25T17:47:31+01:00" level=debug msg="app state loaded" Mar 25 17:47:31 katarynka go-librespot[19529]: time="2026-03-25T17:47:31+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 17:47:31 katarynka go-librespot[19529]: time="2026-03-25T17:47:31+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 25 17:47:31 katarynka go-librespot[19529]: time="2026-03-25T17:47:31+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 17:47:31 katarynka go-librespot[19529]: time="2026-03-25T17:47:31+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 17:47:31 katarynka go-librespot[19529]: time="2026-03-25T17:47:31+01:00" level=info msg="zeroconf server listening on port 36443" Mar 25 17:47:31 katarynka sudo[19539]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-03-25 17:46' Mar 25 17:47:31 katarynka sudo[19539]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 17:47:31 katarynka go-librespot[19529]: time="2026-03-25T17:47:31+01:00" level=debug msg="obtained new client token: AAAWgO7GtQj0OwUeu3Q5+r6R2Y8OInmFQNKem+3DpvkUw6oyTjKq7kDcAZXhz3dq2/dXUlnpRVaTIM1K0onUSv2Qsku+wCEqD7gEdRI7wjCt+tWnjBZb9szKaP3wRLnKyqN/Z0+u4epGskMNOjWZbA11fZH1FNKrshRfUfX3KzrfGrRNExtYZE3/A6S1iNa1FHmIuOtG643jsbrsJmh1BenKRPk5YUYZQ4IppHEuGFzY1Nfi4UlV5aWFRuk=" Mar 25 17:47:31 katarynka go-librespot[19529]: time="2026-03-25T17:47:31+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 17:47:31 katarynka go-librespot[19529]: time="2026-03-25T17:47:31+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Mar 25 17:47:31 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 17:47:31 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 17:47:32 katarynka sudo[19539]: pam_unix(sudo:session): session closed for user root Mar 25 17:47:32 katarynka volumio-remote-updater[665]: [2026-03-25 17:47:32] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Mar 25 17:47:32 katarynka volumio-remote-updater[665]: [2026-03-25 17:47:32] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Mar 25 17:47:32 katarynka systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Mar 25 17:47:32 katarynka systemd[1]: volumio.service: Failed with result 'exit-code'. Mar 25 17:47:32 katarynka systemd[1]: volumio.service: Consumed 49.903s CPU time. Mar 25 17:47:32 katarynka systemd[1]: Started dynamicswap.service - dynamicswap service. Mar 25 17:47:32 katarynka systemd[1]: dynamicswap.service: Deactivated successfully. Mar 25 17:47:32 katarynka systemd[1]: volumio.service: Scheduled restart job, restart counter is at 37. Mar 25 17:47:32 katarynka systemd[1]: Started dynamicswap.service - dynamicswap service. Mar 25 17:47:32 katarynka systemd[1]: Stopped volumio.service - Volumio Backend Module. Mar 25 17:47:32 katarynka systemd[1]: volumio.service: Consumed 49.903s CPU time. Mar 25 17:47:32 katarynka systemd[1]: Started volumio.service - Volumio Backend Module. Mar 25 17:47:32 katarynka systemd[1]: dynamicswap.service: Deactivated successfully. Mar 25 17:47:35 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Mar 25 17:47:35 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 17:47:35 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 17:47:35 katarynka go-librespot[19574]: go-librespot daemon starting... Mar 25 17:47:35 katarynka go-librespot[19575]: time="2026-03-25T17:47:35+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 17:47:35 katarynka go-librespot[19575]: time="2026-03-25T17:47:35+01:00" level=debug msg="app state loaded" Mar 25 17:47:35 katarynka go-librespot[19575]: time="2026-03-25T17:47:35+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 17:47:35 katarynka go-librespot[19575]: time="2026-03-25T17:47:35+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 25 17:47:35 katarynka go-librespot[19575]: time="2026-03-25T17:47:35+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 17:47:35 katarynka go-librespot[19575]: time="2026-03-25T17:47:35+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 17:47:35 katarynka go-librespot[19575]: time="2026-03-25T17:47:35+01:00" level=info msg="zeroconf server listening on port 39227" Mar 25 17:47:35 katarynka go-librespot[19575]: time="2026-03-25T17:47:35+01:00" level=debug msg="obtained new client token: AABq8cb+25GtBaGErywqoRjwyg46hgEzRaxg64gxHcM3cdB1Bj3p6GbG489pGPfcJYEPJBUU1g9eVjAEfKJdt1Uc0GMgb2tEwdGAy0lc+v08iE/8khIDADcvEMqjhh9kePJLGYFdgM9Jk/hb1sv/4ZxVUNzEZFyw69eb15J+vSEyEP4zzWXIiu4OCGXTjuxiA0mDVsFe4UQF7D/+s0Wapqg8nXQk9YXsHhIP065CYYoTqDRfbfChsJRGmSE=" Mar 25 17:47:35 katarynka go-librespot[19575]: time="2026-03-25T17:47:35+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 17:47:35 katarynka go-librespot[19575]: time="2026-03-25T17:47:35+01:00" level=debug msg="completed keyexchange" Mar 25 17:47:35 katarynka go-librespot[19575]: time="2026-03-25T17:47:35+01:00" level=debug msg="completed challenge" Mar 25 17:47:36 katarynka go-librespot[19575]: time="2026-03-25T17:47:36+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 25 17:47:36 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 17:47:36 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 17:47:36 katarynka volumio[19556]: info: ------------------------------------------- Mar 25 17:47:36 katarynka volumio[19556]: info: ----- Volumio3 ---- Mar 25 17:47:36 katarynka volumio[19556]: info: ------------------------------------------- Mar 25 17:47:36 katarynka volumio[19556]: info: ----- System startup ---- Mar 25 17:47:36 katarynka volumio[19556]: info: ------------------------------------------- Mar 25 17:47:37 katarynka volumio-remote-updater[665]: [2026-03-25 17:47:37] [connect] Successful connection Mar 25 17:47:37 katarynka volumio[19556]: info: MYVOLUMIO Environment detected Mar 25 17:47:37 katarynka volumio[19556]: info: Plugin folders cleanup Mar 25 17:47:37 katarynka volumio[19556]: info: Scanning into folder /volumio/app/plugins/ Mar 25 17:47:37 katarynka volumio[19556]: info: Scanning category audio_interface Mar 25 17:47:37 katarynka volumio[19556]: info: Scanning category miscellanea Mar 25 17:47:37 katarynka volumio[19556]: info: Scanning category music_service Mar 25 17:47:37 katarynka volumio[19556]: info: Scanning category plugins.json Mar 25 17:47:37 katarynka volumio[19556]: info: Scanning category system_controller Mar 25 17:47:37 katarynka volumio[19556]: info: Scanning category user_interface Mar 25 17:47:37 katarynka volumio[19556]: info: Scanning into folder /data/plugins/ Mar 25 17:47:37 katarynka volumio[19556]: info: Scanning category music_service Mar 25 17:47:37 katarynka volumio[19556]: info: Plugin folders cleanup completed Mar 25 17:47:37 katarynka volumio[19556]: info: ------------------------------------------- Mar 25 17:47:37 katarynka volumio[19556]: info: ----- Core plugins startup ---- Mar 25 17:47:37 katarynka volumio[19556]: info: ------------------------------------------- Mar 25 17:47:37 katarynka volumio[19556]: info: Loading plugins from folder /volumio/app/plugins/ Mar 25 17:47:37 katarynka volumio[19556]: info: Adding plugin upnp to MyMusic Plugins Mar 25 17:47:37 katarynka volumio[19556]: info: Adding plugin airplay_emulation to MyMusic Plugins Mar 25 17:47:37 katarynka volumio[19556]: info: Adding plugin upnp_browser to MyMusic Plugins Mar 25 17:47:37 katarynka volumio[19556]: info: Loading plugins from folder /data/plugins/ Mar 25 17:47:37 katarynka volumio[19556]: info: Loading plugin "system"... Mar 25 17:47:37 katarynka volumio[19556]: info: Loading plugin "appearance"... Mar 25 17:47:39 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Mar 25 17:47:39 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 17:47:39 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 17:47:39 katarynka go-librespot[19594]: go-librespot daemon starting... Mar 25 17:47:39 katarynka go-librespot[19595]: time="2026-03-25T17:47:39+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 17:47:39 katarynka go-librespot[19595]: time="2026-03-25T17:47:39+01:00" level=debug msg="app state loaded" Mar 25 17:47:39 katarynka go-librespot[19595]: time="2026-03-25T17:47:39+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 17:47:39 katarynka volumio[19556]: info: Loading plugin "network"... Mar 25 17:47:39 katarynka go-librespot[19595]: time="2026-03-25T17:47: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 25 17:47:39 katarynka go-librespot[19595]: time="2026-03-25T17:47:39+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 17:47:39 katarynka go-librespot[19595]: time="2026-03-25T17:47:39+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 17:47:39 katarynka volumio[19556]: info: Refreshing Cached IP Addresses Mar 25 17:47:39 katarynka go-librespot[19595]: time="2026-03-25T17:47:39+01:00" level=info msg="zeroconf server listening on port 36711" Mar 25 17:47:39 katarynka sudo[19603]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 25 17:47:39 katarynka sudo[19603]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 17:47:39 katarynka sudo[19605]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 25 17:47:39 katarynka sudo[19605]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 17:47:39 katarynka sudo[19603]: pam_unix(sudo:session): session closed for user root Mar 25 17:47:39 katarynka sudo[19605]: pam_unix(sudo:session): session closed for user root Mar 25 17:47:39 katarynka volumio[19556]: info: Loading plugin "services"... Mar 25 17:47:39 katarynka volumio[19556]: info: Loading plugin "alsa_controller"... Mar 25 17:47:39 katarynka sudo[19614]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Mar 25 17:47:39 katarynka sudo[19614]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 17:47:39 katarynka go-librespot[19595]: time="2026-03-25T17:47:39+01:00" level=debug msg="obtained new client token: AAAGn0iqkqaysO/1wvscVeEiXNEWairmyiYwz9UNMq5i08ESlkALuWWZ0DRd5kke7/g5eVxoyUUeZZCAaRURm0qLbLfcQPaWppu1wkYXt9R0AstOgWzqkHXiUn9Fg5ZFR5NoLH0h8cbH8gU7NEOwtadZJkKHGVMfgLI/6wULCUm40moN9Dz1KfbY0DtrPaFtuHPk5je757vR7+DS0etURTjDzhAtLjYSYgzf/CUYceTkIo4cfFwR5lCoWd0=" Mar 25 17:47:39 katarynka volumio[19556]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 25 17:47:39 katarynka volumio[19556]: info: Loading plugin "wizard"... Mar 25 17:47:39 katarynka volumio[19556]: info: Loading plugin "networkfs"... Mar 25 17:47:39 katarynka volumio[19556]: info: Starting Udev Watcher for removable devices Mar 25 17:47:40 katarynka volumio[19556]: info: Ignoring mount for partition: boot Mar 25 17:47:40 katarynka volumio[19556]: info: Ignoring mount for partition: volumio Mar 25 17:47:40 katarynka volumio[19556]: info: Ignoring mount for partition: volumio_data Mar 25 17:47:40 katarynka volumio[19556]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 25 17:47:40 katarynka volumio[19556]: info: Loading plugin "volumio_command_line_client"... Mar 25 17:47:40 katarynka go-librespot[19595]: time="2026-03-25T17:47:40+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 17:47:40 katarynka volumio[19556]: info: Loading plugin "upnp"... Mar 25 17:47:40 katarynka volumio[19556]: info: [1774457260090] Starting Upmpd Daemon Mar 25 17:47:40 katarynka volumio[19556]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 25 17:47:40 katarynka volumio[19556]: info: Loading plugin "my_music"... Mar 25 17:47:40 katarynka volumio[19556]: info: Loading plugin "mpd"... Mar 25 17:47:40 katarynka go-librespot[19595]: time="2026-03-25T17:47:40+01:00" level=debug msg="completed keyexchange" Mar 25 17:47:40 katarynka go-librespot[19595]: time="2026-03-25T17:47:40+01:00" level=debug msg="completed challenge" Mar 25 17:47:40 katarynka go-librespot[19595]: time="2026-03-25T17:47:40+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 25 17:47:40 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 17:47:40 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 17:47:40 katarynka sudo[19614]: pam_unix(sudo:session): session closed for user root Mar 25 17:47:40 katarynka volumio[19556]: info: Loading plugin "upnp_browser"... Mar 25 17:47:43 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 11. Mar 25 17:47:43 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 17:47:43 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 17:47:43 katarynka go-librespot[19636]: go-librespot daemon starting... Mar 25 17:47:43 katarynka volumio[19556]: info: Starting UPNP Browser Mar 25 17:47:43 katarynka volumio[19556]: info: Loading plugin "alarm-clock"... Mar 25 17:47:43 katarynka go-librespot[19637]: time="2026-03-25T17:47:43+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 17:47:43 katarynka go-librespot[19637]: time="2026-03-25T17:47:43+01:00" level=debug msg="app state loaded" Mar 25 17:47:43 katarynka go-librespot[19637]: time="2026-03-25T17:47:43+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 17:47:44 katarynka volumio[19556]: info: Loading plugin "airplay_emulation"... Mar 25 17:47:44 katarynka volumio[19556]: info: Starting Shairport Sync Mar 25 17:47:44 katarynka volumio[19556]: info: Loading plugin "last_100"... Mar 25 17:47:44 katarynka volumio[19556]: info: Loading plugin "webradio"... Mar 25 17:47:44 katarynka go-librespot[19637]: time="2026-03-25T17:47:44+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 25 17:47:44 katarynka go-librespot[19637]: time="2026-03-25T17:47:44+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 17:47:44 katarynka go-librespot[19637]: time="2026-03-25T17:47:44+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 17:47:44 katarynka go-librespot[19637]: time="2026-03-25T17:47:44+01:00" level=info msg="zeroconf server listening on port 39215" Mar 25 17:47:44 katarynka volumio[19556]: info: Loading plugin "i2s_dacs"... Mar 25 17:47:44 katarynka go-librespot[19637]: time="2026-03-25T17:47:44+01:00" level=debug msg="obtained new client token: AAC3mi7MVG8KqsRi5IbcbKs6BsLs86dHlKnna4CqF87A7WTbCAUGr/7PmoPQP+5RhBIMVdtjkohORjTWAicGjSkgxbz65iQ25rLeU7tdSIqv1Tg4EGIAAYkWCmGWKB0VIepKC6iimAaYGw8RqwXZ9QywCFxGSnXvddXwPsMUcm/08i0ZcKT/cA2VEHppQHCTTAG91JiAOtoNiONloz37JpwYlbFLwl0LEezpCnfa+mWrkyHhxppdQsjQ2p4=" Mar 25 17:47:44 katarynka volumio[19556]: info: Loading plugin "volumiodiscovery"... Mar 25 17:47:44 katarynka go-librespot[19637]: time="2026-03-25T17:47:44+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 17:47:44 katarynka volumio[19556]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Mar 25 17:47:44 katarynka volumio[19556]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 25 17:47:44 katarynka volumio[19556]: *** WARNING *** For more information see Mar 25 17:47:44 katarynka volumio[19556]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Mar 25 17:47:44 katarynka volumio[19556]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 25 17:47:44 katarynka volumio[19556]: *** WARNING *** For more information see Mar 25 17:47:44 katarynka node[19556]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Mar 25 17:47:44 katarynka node[19556]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 25 17:47:44 katarynka node[19556]: *** WARNING *** For more information see Mar 25 17:47:44 katarynka node[19556]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Mar 25 17:47:44 katarynka node[19556]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 25 17:47:44 katarynka node[19556]: *** WARNING *** For more information see Mar 25 17:47:44 katarynka volumio[19556]: info: Applying required configuration parameters for plugin volumiodiscovery Mar 25 17:47:44 katarynka volumio[19556]: info: Discovery: Started advertising with name: katarynka Mar 25 17:47:44 katarynka go-librespot[19637]: time="2026-03-25T17:47:44+01:00" level=debug msg="completed keyexchange" Mar 25 17:47:44 katarynka go-librespot[19637]: time="2026-03-25T17:47:44+01:00" level=debug msg="completed challenge" Mar 25 17:47:44 katarynka volumio[19556]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 25 17:47:44 katarynka volumio[19556]: info: Loading plugin "spop"... Mar 25 17:47:44 katarynka go-librespot[19637]: time="2026-03-25T17:47: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 17:47:44 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 17:47:44 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 17:47:46 katarynka volumio[19556]: info: Loading plugin "outputs"... Mar 25 17:47:46 katarynka volumio[19556]: info: Loading plugin "albumart"... Mar 25 17:47:46 katarynka volumio[19556]: info: Plugin example_plugin is not enabled Mar 25 17:47:46 katarynka volumio[19556]: info: Loading plugin "inputs"... Mar 25 17:47:46 katarynka volumio[19556]: info: Loading plugin "updater_comm"... Mar 25 17:47:46 katarynka volumio[19556]: info: Plugin mpdemulation is not enabled Mar 25 17:47:46 katarynka volumio[19556]: info: Loading plugin "rest_api"... Mar 25 17:47:46 katarynka volumio[19556]: info: Loading plugin "websocket"... Mar 25 17:47:46 katarynka volumio[19556]: info: Starting Socket.io Server version 1.7.4 Mar 25 17:47:46 katarynka volumio[19556]: info: Loading i18n strings for locale pl Mar 25 17:47:46 katarynka volumio[19556]: Updating browse sources language Mar 25 17:47:46 katarynka volumio[19556]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 25 17:47:46 katarynka volumio[19556]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 25 17:47:46 katarynka volumio[19556]: info: CoreCommandRouter::initPlayerControls Mar 25 17:47:46 katarynka volumio[19556]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 17:47:47 katarynka volumio[19556]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 17:47:47 katarynka volumio[19556]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 17:47:47 katarynka volumio[19556]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 17:47:47 katarynka volumio[19556]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 17:47:47 katarynka volumio[19556]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 17:47:47 katarynka volumio[19556]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 17:47:47 katarynka volumio[19556]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 17:47:47 katarynka volumio[19556]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 25 17:47:47 katarynka volumio[19556]: Express server listening on port 3000 Mar 25 17:47:47 katarynka volumio[19556]: [Metrics] WebUI: 11s 933.68ms Mar 25 17:47:47 katarynka volumio[19556]: info: CoreStateMachine::resetVolumioState Mar 25 17:47:47 katarynka volumio[19556]: info: CoreStateMachine::getcurrentVolume Mar 25 17:47:47 katarynka volumio[19556]: info: CoreCommandRouter::volumioRetrievevolume Mar 25 17:47:47 katarynka volumio[19556]: info: Cannot read play queue from file Mar 25 17:47:47 katarynka volumio[19556]: info: Volumio Network Manager: Network status updated: 2 Mar 25 17:47:47 katarynka volumio[19650]: Forking 3 albumart workers Mar 25 17:47:47 katarynka volumio[19556]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 17:47:47 katarynka volumio[19556]: info: CoreStateMachine::setRepeat null single undefined Mar 25 17:47:47 katarynka volumio[19556]: info: CoreStateMachine::pushState Mar 25 17:47:47 katarynka volumio[19556]: info: CorePlayQueue::getTrack 0 Mar 25 17:47:47 katarynka volumio[19556]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 25 17:47:47 katarynka volumio[19556]: info: CoreCommandRouter::volumioPushState Mar 25 17:47:47 katarynka volumio[19556]: info: CoreStateMachine::setRandom null Mar 25 17:47:47 katarynka volumio[19556]: info: CoreStateMachine::pushState Mar 25 17:47:47 katarynka volumio[19556]: info: CorePlayQueue::getTrack 0 Mar 25 17:47:47 katarynka volumio[19556]: info: CoreCommandRouter::volumioPushState Mar 25 17:47:47 katarynka volumio[19556]: info: Setting Device type: Raspberry PI Mar 25 17:47:47 katarynka volumio[19556]: info: VolumeController:: Volume=96 Mute =false Mar 25 17:47:47 katarynka volumio[19556]: info: CoreStateMachine::pushState Mar 25 17:47:47 katarynka volumio[19556]: info: CorePlayQueue::getTrack 0 Mar 25 17:47:47 katarynka volumio[19556]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 25 17:47:47 katarynka volumio[19556]: info: CoreCommandRouter::volumioPushState Mar 25 17:47:47 katarynka volumio[19556]: info: CoreStateMachine::updateTrackBlock Mar 25 17:47:47 katarynka volumio[19556]: info: CorePlayQueue::getTrackBlock Mar 25 17:47:47 katarynka volumio[19556]: info: CoreCommandRouter::volumioRetrievevolume Mar 25 17:47:47 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 12. Mar 25 17:47:47 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 17:47:47 katarynka volumio[19556]: info: Completed loading Core Plugins Mar 25 17:47:47 katarynka volumio[19556]: info: Preparing to generate the ALSA configuration file Mar 25 17:47:47 katarynka go-librespot[19699]: go-librespot daemon starting... Mar 25 17:47:47 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 17:47:47 katarynka go-librespot[19700]: time="2026-03-25T17:47:47+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 17:47:47 katarynka go-librespot[19700]: time="2026-03-25T17:47:47+01:00" level=debug msg="app state loaded" Mar 25 17:47:47 katarynka go-librespot[19700]: time="2026-03-25T17:47:47+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 17:47:47 katarynka volumio[19556]: info: Asound.conf file unchanged, so no further update is needed Mar 25 17:47:47 katarynka volumio[19556]: info: Output device has changed, restarting MPD Mar 25 17:47:47 katarynka volumio[19556]: info: Output device has changed, restarting Shairport Sync Mar 25 17:47:47 katarynka volumio[19556]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 17:47:47 katarynka volumio[19556]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 17:47:48 katarynka sudo[19713]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 25 17:47:48 katarynka sudo[19713]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 17:47:48 katarynka sudo[19713]: pam_unix(sudo:session): session closed for user root Mar 25 17:47:48 katarynka volumio[19556]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 25 17:47:48 katarynka volumio[19556]: info: ___________ START PLUGINS ___________ Mar 25 17:47:48 katarynka sudo[19715]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 25 17:47:48 katarynka sudo[19715]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 17:47:48 katarynka volumio[19556]: info: ControllerMpd::onStart: Initializing MPD Mar 25 17:47:48 katarynka volumio[19556]: info: Creating MPD Configuration file Mar 25 17:47:48 katarynka volumio[19556]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 25 17:47:48 katarynka volumio[19556]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 25 17:47:48 katarynka volumio[19556]: info: [1774457268256] CoreMusicLibrary::Adding element Serwery Mediów Mar 25 17:47:48 katarynka volumio[19556]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 25 17:47:48 katarynka systemd[1]: Stopping mpd.service - Music Player Daemon... Mar 25 17:47:48 katarynka sudo[19726]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 25 17:47:48 katarynka sudo[19726]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 17:47:48 katarynka sudo[19724]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 25 17:47:48 katarynka volumio[19556]: info: UPNP Browser: Client initialized successfully Mar 25 17:47:48 katarynka go-librespot[19700]: time="2026-03-25T17:47:48+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 17:47:48 katarynka go-librespot[19700]: time="2026-03-25T17:47:48+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 17:47:48 katarynka go-librespot[19700]: time="2026-03-25T17:47:48+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 17:47:48 katarynka sudo[19724]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 17:47:48 katarynka go-librespot[19700]: time="2026-03-25T17:47:48+01:00" level=info msg="zeroconf server listening on port 34559" Mar 25 17:47:48 katarynka sudo[19724]: pam_unix(sudo:session): session closed for user root Mar 25 17:47:48 katarynka systemd[1]: mpd.service: Deactivated successfully. Mar 25 17:47:48 katarynka systemd[1]: Stopped mpd.service - Music Player Daemon. Mar 25 17:47:48 katarynka systemd[1]: mpd.service: Consumed 7.146s CPU time. Mar 25 17:47:48 katarynka systemd[1]: mpd.socket: Deactivated successfully. Mar 25 17:47:48 katarynka systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Mar 25 17:47:48 katarynka volumio[19556]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 17:47:48 katarynka volumio[19556]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 17:47:48 katarynka systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Mar 25 17:47:48 katarynka volumio[19556]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 25 17:47:48 katarynka volumio[19556]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 17:47:48 katarynka volumio[19556]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 17:47:48 katarynka systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Mar 25 17:47:48 katarynka go-librespot[19700]: time="2026-03-25T17:47:48+01:00" level=debug msg="obtained new client token: AADA4TMI9i0DvG09UPXf6Y1xlVtQRBIMbhW+pbU6jK/te7fRAAu5gkCiaMwHXS9XYNWqG+07zaF5l+sy6aJKzgag5jJ9s2G5e4Ih7W2mMbSy1PMrn8OeOEsiHZUIsRI7+8zbFuYMtQJ71XChmy6TJarlw+jKeH9MEBNqOy+MCjHQ/yZSdN/RaUrhemtQBQhArznU0xIeP+7A5+iYHXcmNaofXFpXpsxEz3GUUZc20ggUd59P+b2LDN9M8V0=" Mar 25 17:47:48 katarynka systemd[1]: Starting mpd.service - Music Player Daemon... Mar 25 17:47:48 katarynka systemd[1]: mpd.service: Deactivated successfully. Mar 25 17:47:48 katarynka systemd[1]: Stopped mpd.service - Music Player Daemon. Mar 25 17:47:48 katarynka systemd[1]: mpd.socket: Deactivated successfully. Mar 25 17:47:48 katarynka systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Mar 25 17:47:48 katarynka systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Mar 25 17:47:48 katarynka go-librespot[19700]: time="2026-03-25T17:47:48+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 17:47:48 katarynka systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Mar 25 17:47:48 katarynka volumio[19556]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 25 17:47:48 katarynka volumio[19556]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 25 17:47:48 katarynka volumio[19556]: info: [1774457268683] CoreMusicLibrary::Adding element Last_100 Mar 25 17:47:48 katarynka volumio[19556]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 25 17:47:48 katarynka systemd[1]: Starting mpd.service - Music Player Daemon... Mar 25 17:47:48 katarynka go-librespot[19700]: time="2026-03-25T17:47:48+01:00" level=warning msg="failed to connect to AP ap-gew4.spotify.com:443, retrying with a different AP" error="dial tcp 34.158.1.133:443: connect: connection refused" Mar 25 17:47:48 katarynka volumio[19556]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 25 17:47:48 katarynka volumio[19556]: info: [1774457268722] CoreMusicLibrary::Adding element Webradio Mar 25 17:47:48 katarynka volumio[19556]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 25 17:47:48 katarynka go-librespot[19700]: time="2026-03-25T17:47:48+01:00" level=debug msg="connected to ap-gew4.spotify.com:80" Mar 25 17:47:48 katarynka volumio[19556]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 25 17:47:48 katarynka volumio[19556]: info: Initializing BBC Radios Mar 25 17:47:48 katarynka go-librespot[19700]: time="2026-03-25T17:47:48+01:00" level=debug msg="completed keyexchange" Mar 25 17:47:48 katarynka go-librespot[19700]: time="2026-03-25T17:47:48+01:00" level=debug msg="completed challenge" Mar 25 17:47:48 katarynka go-librespot[19700]: time="2026-03-25T17:47:48+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 25 17:47:48 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 17:47:48 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 17:47:48 katarynka volumio[19556]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 25 17:47:48 katarynka volumio[19556]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 17:47:49 katarynka volumio[19556]: info: Creating Spotify config file Mar 25 17:47:49 katarynka volumio[19556]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 17:47:49 katarynka sudo[19741]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Mar 25 17:47:49 katarynka sudo[19741]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Mar 25 17:47:49 katarynka sudo[19741]: pam_unix(sudo:session): session closed for user root Mar 25 17:47:49 katarynka volumio-remote-updater[665]: [2026-03-25 17:47:49] [connect] Successful connection Mar 25 17:47:49 katarynka volumio[19556]: info: Volumio Calling Home Mar 25 17:47:50 katarynka volumio[19671]: Starting albumart workers Mar 25 17:47:50 katarynka volumio[19669]: Starting albumart workers Mar 25 17:47:51 katarynka volumio[19556]: info: VolumeController:: Volume=96 Mute =false Mar 25 17:47:51 katarynka volumio[19556]: info: CoreStateMachine::pushState Mar 25 17:47:51 katarynka volumio[19556]: info: CorePlayQueue::getTrack 0 Mar 25 17:47:51 katarynka volumio[19556]: info: CoreCommandRouter::volumioPushState Mar 25 17:47:51 katarynka volumio[19556]: info: Discovery: adding 4d616d77-6a8c-4da2-85a4-840d70f98e51 Mar 25 17:47:51 katarynka volumio[19556]: info: Discovery: Found device katarynka Mar 25 17:47:51 katarynka volumio[19556]: info: CoreCommandRouter::volumioGetState Mar 25 17:47:51 katarynka volumio[19556]: info: CorePlayQueue::getTrack 0 Mar 25 17:47:51 katarynka volumio[19556]: info: Discovery: this is already registered, 4d616d77-6a8c-4da2-85a4-840d70f98e51 Mar 25 17:47:51 katarynka volumio[19556]: info: Discovery: Found device katarynka Mar 25 17:47:51 katarynka sudo[19776]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 25 17:47:51 katarynka sudo[19776]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 17:47:51 katarynka volumio[19556]: info: CoreCommandRouter::volumioGetState Mar 25 17:47:51 katarynka volumio[19556]: info: CorePlayQueue::getTrack 0 Mar 25 17:47:51 katarynka sudo[19776]: pam_unix(sudo:session): session closed for user root Mar 25 17:47:51 katarynka sudo[19777]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 25 17:47:51 katarynka sudo[19777]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 17:47:51 katarynka volumio[19556]: info: MPD Permissions set Mar 25 17:47:51 katarynka volumio[19556]: info: MPD Permissions set Mar 25 17:47:51 katarynka sudo[19777]: pam_unix(sudo:session): session closed for user root Mar 25 17:47:51 katarynka volumio-remote-updater[665]: [2026-03-25 17:47:51] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1774457269 101 Mar 25 17:47:51 katarynka volumio[19556]: 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 17:47:51 katarynka volumio[19556]: info: Volumio called home Mar 25 17:47:51 katarynka volumio[19556]: info: Spotify config file written Mar 25 17:47:51 katarynka sudo[19781]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Mar 25 17:47:51 katarynka sudo[19781]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 17:47:51 katarynka volumio[19666]: Starting albumart workers Mar 25 17:47:51 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 17:47:51 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 17:47:51 katarynka go-librespot[19783]: go-librespot daemon starting... Mar 25 17:47:51 katarynka sudo[19781]: pam_unix(sudo:session): session closed for user root Mar 25 17:47:52 katarynka go-librespot[19784]: time="2026-03-25T17:47:52+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 17:47:52 katarynka go-librespot[19784]: time="2026-03-25T17:47:52+01:00" level=debug msg="app state loaded" Mar 25 17:47:52 katarynka volumio[19556]: 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 17:47:52 katarynka go-librespot[19784]: time="2026-03-25T17:47:52+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 17:47:52 katarynka volumio[19556]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 17:47:52 katarynka volumio[19556]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 17:47:52 katarynka volumio[19556]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 17:47:52 katarynka volumio[19556]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 17:47:52 katarynka volumio[19556]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 17:47:52 katarynka volumio[19556]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 17:47:52 katarynka volumio[19556]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 17:47:52 katarynka volumio[19556]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 17:47:52 katarynka volumio[19556]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 17:47:52 katarynka volumio[19556]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 17:47:52 katarynka volumio[19556]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 17:47:52 katarynka volumio[19556]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 17:47:52 katarynka volumio[19556]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 17:47:52 katarynka volumio[19556]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 17:47:52 katarynka volumio[19556]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 17:47:52 katarynka volumio[19556]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 17:47:52 katarynka volumio[19556]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 17:47:52 katarynka volumio[19556]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 17:47:52 katarynka volumio[19556]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 17:47:52 katarynka volumio[19556]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 17:47:52 katarynka volumio[19556]: info: No need to fix Spotify hosts Mar 25 17:47:52 katarynka go-librespot[19784]: time="2026-03-25T17:47:52+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 17:47:52 katarynka go-librespot[19784]: time="2026-03-25T17:47:52+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 17:47:52 katarynka go-librespot[19784]: time="2026-03-25T17:47:52+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 17:47:52 katarynka go-librespot[19784]: time="2026-03-25T17:47:52+01:00" level=info msg="zeroconf server listening on port 35663" Mar 25 17:47:52 katarynka volumio[19556]: info: Starting Shairport Sync Mar 25 17:47:52 katarynka volumio[19556]: info: Starting Shairport Sync Mar 25 17:47:52 katarynka volumio[19556]: info: Starting Shairport Sync Mar 25 17:47:52 katarynka go-librespot[19784]: time="2026-03-25T17:47:52+01:00" level=debug msg="obtained new client token: AADYDb9RFOklVV0Pfnrfi6m1cFYPBImMDFX7pl9BsPIySYzkQffuCrwazXbCYyvOzSmq9nYGSqJgqq2KAMsiJKQHwyK5D3jGwoxtNc7ZEtYeFUZCrpl8fPCvrDubNFcxe0qrulWAu7RN6A6rkxT83etfNziyJziATG7VeP2qb4nTKLcR7jIDsd1AY0nCiCsUUPPdzbbz6sFzu4RycwwXH44UpiAD6wm5xFtW8htMMjjJgjC9JBNPYLrasPU=" Mar 25 17:47:52 katarynka go-librespot[19784]: time="2026-03-25T17:47:52+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 17:47:52 katarynka sudo[19804]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 25 17:47:52 katarynka sudo[19804]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 17:47:52 katarynka sudo[19806]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 25 17:47:52 katarynka sudo[19806]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 17:47:52 katarynka go-librespot[19784]: time="2026-03-25T17:47:52+01:00" level=debug msg="completed keyexchange" Mar 25 17:47:52 katarynka go-librespot[19784]: time="2026-03-25T17:47:52+01:00" level=debug msg="completed challenge" Mar 25 17:47:52 katarynka sudo[19808]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Mar 25 17:47:53 katarynka sudo[19808]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 17:47:53 katarynka sudo[19802]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 25 17:47:53 katarynka sudo[19802]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 17:47:53 katarynka go-librespot[19784]: time="2026-03-25T17:47:53+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 17:47:53 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 17:47:53 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 17:47:53 katarynka systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Mar 25 17:47:53 katarynka systemd[1]: shairport-sync.service: Deactivated successfully. Mar 25 17:47:53 katarynka systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 25 17:47:53 katarynka systemd[1]: shairport-sync.service: Consumed 2.388s CPU time. Mar 25 17:47:53 katarynka volumio[19556]: info: CoreCommandRouter::volumioGetState Mar 25 17:47:53 katarynka volumio[19556]: info: CorePlayQueue::getTrack 0 Mar 25 17:47:53 katarynka systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 25 17:47:53 katarynka sudo[19806]: pam_unix(sudo:session): session closed for user root Mar 25 17:47:53 katarynka volumio[19556]: info: Shairport-Sync Started Mar 25 17:47:53 katarynka volumio[19556]: Error adding Membership: Error: addMembership EINVAL Mar 25 17:47:53 katarynka volumio[19556]: info: An error occurred while refreshing Spotify Token Error: Bad Request Mar 25 17:47:53 katarynka systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Mar 25 17:47:53 katarynka systemd[1]: shairport-sync.service: Deactivated successfully. Mar 25 17:47:53 katarynka systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 25 17:47:53 katarynka systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 25 17:47:53 katarynka sudo[19808]: pam_unix(sudo:session): session closed for user root Mar 25 17:47:53 katarynka sudo[19802]: pam_unix(sudo:session): session closed for user root Mar 25 17:47:53 katarynka volumio[19556]: info: Upmpdcli Daemon Started Mar 25 17:47:53 katarynka sudo[19804]: pam_unix(sudo:session): session closed for user root Mar 25 17:47:53 katarynka volumio[19556]: info: Shairport-Sync Started Mar 25 17:47:53 katarynka volumio[19556]: info: Shairport-Sync Started Mar 25 17:47:55 katarynka volumio[19556]: info: go-librespot daemon successfully initialized Mar 25 17:47:56 katarynka mpd[19756]: 2026-03-25T17:47:56 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Mar 25 17:47:56 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 13. Mar 25 17:47:56 katarynka systemd[1]: Started mpd.service - Music Player Daemon. Mar 25 17:47:56 katarynka sudo[19726]: pam_unix(sudo:session): session closed for user root Mar 25 17:47:56 katarynka sudo[19715]: pam_unix(sudo:session): session closed for user root Mar 25 17:47:56 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 17:47:56 katarynka volumio[19556]: info: Completed starting Core Plugins Mar 25 17:47:56 katarynka volumio[19556]: info: ------------------------------------------- Mar 25 17:47:56 katarynka volumio[19556]: info: ----- MyVolumio plugins startup ---- Mar 25 17:47:56 katarynka volumio[19556]: info: ------------------------------------------- Mar 25 17:47:56 katarynka volumio[19556]: info: [MyVolumio PluginManager] Fetching plans data.... Mar 25 17:47:56 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 17:47:56 katarynka go-librespot[19865]: go-librespot daemon starting... Mar 25 17:47:56 katarynka go-librespot[19866]: time="2026-03-25T17:47:56+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 17:47:56 katarynka go-librespot[19866]: time="2026-03-25T17:47:56+01:00" level=debug msg="app state loaded" Mar 25 17:47:56 katarynka go-librespot[19866]: time="2026-03-25T17:47:56+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 17:47:56 katarynka volumio[19556]: error: MPD error: The expression evaluated to a falsy value: Mar 25 17:47:56 katarynka volumio[19556]: assert.ok(self.idling) Mar 25 17:47:56 katarynka volumio[19556]: error: The expression evaluated to a falsy value: Mar 25 17:47:56 katarynka volumio[19556]: assert.ok(self.idling) Mar 25 17:47:56 katarynka volumio[19556]: error: updateQueue error: null Mar 25 17:47:56 katarynka volumio[19556]: info: MPD running with PID19756 Mar 25 17:47:56 katarynka volumio[19556]: ,establishing connection Mar 25 17:47:56 katarynka volumio[19556]: error: updateQueue error: null Mar 25 17:47:56 katarynka go-librespot[19866]: time="2026-03-25T17:47:56+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 25 17:47:56 katarynka go-librespot[19866]: time="2026-03-25T17:47:56+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 17:47:56 katarynka go-librespot[19866]: time="2026-03-25T17:47:56+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 17:47:56 katarynka go-librespot[19866]: time="2026-03-25T17:47:56+01:00" level=info msg="zeroconf server listening on port 36061" Mar 25 17:47:56 katarynka go-librespot[19866]: time="2026-03-25T17:47:56+01:00" level=debug msg="obtained new client token: AAB8wtJHJ4pg+UyJ+hljbrZpTfUrzJ77YQG/Fkiu70Kd+SR2gJ9iMFcAPjgtKZbNlKJz8gw465Vtxg28KvkeofLLr3+DI96Q6NV0vozw72FgPnXo8URt0yyuSHCHiYY8WhbDkkI23D1rLkUxFIbGe2LQfVdMaE1/80uIoIfbysN8zOn+2mpPYWUyitsmrpuWHBZmtr7rXssyfec/LG10d2hSv0/0hA4bLHMkAnjOl8FavoaBXpCj2X1ZC9E=" Mar 25 17:47:56 katarynka go-librespot[19866]: time="2026-03-25T17:47:56+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 17:47:56 katarynka go-librespot[19866]: time="2026-03-25T17:47:56+01:00" level=debug msg="completed keyexchange" Mar 25 17:47:56 katarynka go-librespot[19866]: time="2026-03-25T17:47:56+01:00" level=debug msg="completed challenge" Mar 25 17:47:57 katarynka go-librespot[19866]: time="2026-03-25T17:47:57+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 17:47:57 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 17:47:57 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 17:47:58 katarynka volumio[19556]: info: Initializing connection to go-librespot Websocket Mar 25 17:47:58 katarynka volumio[19556]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 25 17:47:59 katarynka sudo[19874]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Mar 25 17:47:59 katarynka sudo[19874]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 17:47:59 katarynka sudo[19876]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Mar 25 17:47:59 katarynka sudo[19876]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 17:47:59 katarynka systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Mar 25 17:47:59 katarynka systemd[1]: mpd_monitor.service: Deactivated successfully. Mar 25 17:47:59 katarynka systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Mar 25 17:47:59 katarynka systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Mar 25 17:47:59 katarynka sudo[19876]: pam_unix(sudo:session): session closed for user root Mar 25 17:47:59 katarynka sudo[19874]: pam_unix(sudo:session): session closed for user root Mar 25 17:47:59 katarynka mpd_monitor.sh[19879]: MPD Monitor Service: Starting MPD Monitor Service Mar 25 17:47:59 katarynka volumio[19556]: info: Successfully started MPD Monitor Mar 25 17:47:59 katarynka volumio[19556]: info: Successfully started MPD Monitor Mar 25 17:48:00 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 14. Mar 25 17:48:00 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 17:48:00 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 17:48:00 katarynka go-librespot[19887]: go-librespot daemon starting... Mar 25 17:48:00 katarynka go-librespot[19898]: time="2026-03-25T17:48:00+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 17:48:00 katarynka go-librespot[19898]: time="2026-03-25T17:48:00+01:00" level=debug msg="app state loaded" Mar 25 17:48:00 katarynka go-librespot[19898]: time="2026-03-25T17:48:00+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 17:48:00 katarynka go-librespot[19898]: time="2026-03-25T17:48:00+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 25 17:48:00 katarynka go-librespot[19898]: time="2026-03-25T17:48:00+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 25 17:48:00 katarynka go-librespot[19898]: time="2026-03-25T17:48:00+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 25 17:48:00 katarynka go-librespot[19898]: time="2026-03-25T17:48:00+01:00" level=info msg="zeroconf server listening on port 37243" Mar 25 17:48:00 katarynka go-librespot[19898]: time="2026-03-25T17:48:00+01:00" level=debug msg="obtained new client token: AACi4wdTI4xO0GwWNVwC6NIjhb56HFPuR/8tv41BcS8LC61kwP2fEpTColX22gqwvweyz9YIU5NpCWMKy8pWC9AZ+k+dC+76PKnU5C1GVso3sq/+nqa84haBNPrhDL/yeBIljQXxIO4Lgg5aZ1H2wo9fPyIKkzYKbPcuhK7+Z54CMKMEDeff7D2WLP7Olr1AnJ2/Hp01JKRN1BqjpKpmne5vjEhRo2/Y0ac+xUhOohrGj7x9J7QnzcQdGKM=" Mar 25 17:48:00 katarynka go-librespot[19898]: time="2026-03-25T17:48:00+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 17:48:00 katarynka go-librespot[19898]: time="2026-03-25T17:48:00+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Mar 25 17:48:00 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 17:48:00 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 17:48:01 katarynka volumio[19556]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Mar 25 17:48:01 katarynka volumio[19556]: info: Initializing connection to go-librespot Websocket Mar 25 17:48:01 katarynka volumio[19556]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 25 17:48:03 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 15. Mar 25 17:48:03 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 17:48:03 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 17:48:03 katarynka go-librespot[19910]: go-librespot daemon starting... Mar 25 17:48:03 katarynka go-librespot[19911]: time="2026-03-25T17:48:03+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 17:48:03 katarynka go-librespot[19911]: time="2026-03-25T17:48:03+01:00" level=debug msg="app state loaded" Mar 25 17:48:03 katarynka go-librespot[19911]: time="2026-03-25T17:48:03+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 17:48:04 katarynka go-librespot[19911]: time="2026-03-25T17:48:04+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 25 17:48:04 katarynka go-librespot[19911]: time="2026-03-25T17:48:04+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 17:48:04 katarynka go-librespot[19911]: time="2026-03-25T17:48:04+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 17:48:04 katarynka go-librespot[19911]: time="2026-03-25T17:48:04+01:00" level=info msg="zeroconf server listening on port 38443" Mar 25 17:48:04 katarynka go-librespot[19911]: time="2026-03-25T17:48:04+01:00" level=debug msg="obtained new client token: AAB+Dc7BNp3QF7npCjG7xSY/IU38PfaxjX0dhA4a++2/uIIwE2L3UovOuHw/Q5mFOwr+3hBJofbHDTNMwf0PNTz/8QpKk04Pclt3PenhhSi6NgSIVgxwmt+it33DoSskFGBb+u3GWeLIr+UKVnsnHLmUdGKWuES6Aug4IkGci/lqRkb341IBvqiqhN79Newp9ZbV6KagJmZjECneMhj2gnqm1KC0gxm0B+KEc4SgbsxevbhEY+nduymDM34=" Mar 25 17:48:04 katarynka volumio[19556]: info: Initializing connection to go-librespot Websocket Mar 25 17:48:04 katarynka go-librespot[19911]: time="2026-03-25T17:48:04+01:00" level=debug msg="new websocket client" Mar 25 17:48:04 katarynka volumio[19556]: info: Connection to go-librespot Websocket established Mar 25 17:48:04 katarynka go-librespot[19911]: time="2026-03-25T17:48:04+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 17:48:04 katarynka go-librespot[19911]: time="2026-03-25T17:48:04+01:00" level=debug msg="completed keyexchange" Mar 25 17:48:04 katarynka go-librespot[19911]: time="2026-03-25T17:48:04+01:00" level=debug msg="completed challenge" Mar 25 17:48:04 katarynka volumio[19556]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Mar 25 17:48:04 katarynka volumio[19556]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Mar 25 17:48:04 katarynka volumio[19556]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Mar 25 17:48:04 katarynka volumio[19556]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Mar 25 17:48:04 katarynka volumio[19556]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Mar 25 17:48:04 katarynka volumio[19556]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Mar 25 17:48:04 katarynka volumio[19556]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Mar 25 17:48:04 katarynka volumio[19556]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Mar 25 17:48:04 katarynka volumio[19556]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Mar 25 17:48:04 katarynka volumio[19556]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Mar 25 17:48:04 katarynka volumio[19556]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Mar 25 17:48:04 katarynka volumio[19556]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Mar 25 17:48:04 katarynka volumio[19556]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Mar 25 17:48:04 katarynka volumio[19556]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Mar 25 17:48:04 katarynka volumio[19556]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Mar 25 17:48:04 katarynka volumio[19556]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Mar 25 17:48:04 katarynka go-librespot[19911]: time="2026-03-25T17:48: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 17:48:04 katarynka volumio[19556]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Mar 25 17:48:04 katarynka volumio[19556]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Mar 25 17:48:04 katarynka volumio[19556]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Mar 25 17:48:04 katarynka volumio[19556]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Mar 25 17:48:04 katarynka volumio[19556]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Mar 25 17:48:04 katarynka volumio[19556]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Mar 25 17:48:04 katarynka volumio[19556]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Mar 25 17:48:04 katarynka volumio[19556]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Mar 25 17:48:04 katarynka volumio[19556]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Mar 25 17:48:04 katarynka volumio[19556]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Mar 25 17:48:04 katarynka volumio[19556]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Mar 25 17:48:04 katarynka volumio[19556]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Mar 25 17:48:04 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 17:48:04 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 17:48:04 katarynka volumio[19556]: info: Adding plugin bluetooth to MyMusic Plugins Mar 25 17:48:04 katarynka volumio[19556]: info: Adding plugin multiroom to MyMusic Plugins Mar 25 17:48:04 katarynka volumio[19556]: info: Adding plugin metavolumio to MyMusic Plugins Mar 25 17:48:04 katarynka volumio[19556]: info: Adding plugin cd_controller to MyMusic Plugins Mar 25 17:48:04 katarynka volumio[19556]: info: Adding plugin qobuzconnect to MyMusic Plugins Mar 25 17:48:04 katarynka volumio[19556]: info: Adding plugin smart_inputs to MyMusic Plugins Mar 25 17:48:04 katarynka volumio[19556]: info: Adding plugin tidalconnect to MyMusic Plugins Mar 25 17:48:04 katarynka volumio[19556]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Mar 25 17:48:06 katarynka volumio[19556]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Mar 25 17:48:06 katarynka volumio[19556]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Mar 25 17:48:06 katarynka volumio[19556]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 17:48:06 katarynka volumio[19556]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 17:48:06 katarynka volumio[19556]: info: Starting MyVolumio Remote Streaming Endpoints Mar 25 17:48:06 katarynka volumio[19556]: info: MyVolumio login type: Token Mar 25 17:48:06 katarynka volumio[19556]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Mar 25 17:48:06 katarynka volumio[19556]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Mar 25 17:48:07 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 16. Mar 25 17:48:07 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 17:48:07 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 17:48:07 katarynka go-librespot[19918]: go-librespot daemon starting... Mar 25 17:48:07 katarynka go-librespot[19919]: time="2026-03-25T17:48:07+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 17:48:07 katarynka go-librespot[19919]: time="2026-03-25T17:48:07+01:00" level=debug msg="app state loaded" Mar 25 17:48:07 katarynka go-librespot[19919]: time="2026-03-25T17:48:07+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 17:48:08 katarynka volumio[19556]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Mar 25 17:48:08 katarynka volumio[19556]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Mar 25 17:48:08 katarynka volumio[19556]: info: Streaming services startup Mar 25 17:48:08 katarynka volumio[19556]: info: Starting Streaming Daemon Mar 25 17:48:08 katarynka go-librespot[19919]: time="2026-03-25T17:48: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-gew1.spotify.com:80]" Mar 25 17:48:08 katarynka go-librespot[19919]: time="2026-03-25T17:48:08+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 17:48:08 katarynka go-librespot[19919]: time="2026-03-25T17:48:08+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 17:48:08 katarynka sudo[19927]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Mar 25 17:48:08 katarynka sudo[19927]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 17:48:08 katarynka volumio[19556]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Mar 25 17:48:08 katarynka go-librespot[19919]: time="2026-03-25T17:48:08+01:00" level=info msg="zeroconf server listening on port 35807" Mar 25 17:48:08 katarynka sudo[19927]: pam_unix(sudo:session): session closed for user root Mar 25 17:48:08 katarynka volumio[19556]: info: Getting Spotify volume Mar 25 17:48:08 katarynka go-librespot[19919]: time="2026-03-25T17:48:08+01:00" level=debug msg="obtained new client token: AAA+i+s39OMMlM5RVybls7SzfvxXCDsWms1PQovduqYm6ePHOUSkJyZiWEmAHi4+80iNlkoSsPY4ptDZNF+9jP3+QNS5QTwhwp/k1HbchGaRL5kjmhAwFYI+2c6GYHjkbeusoT4d/Pk4YkqK6Vzdcd58pgePm7tlfSn7uw8UVAj5HmBlTF7fFyTOWdTas2sn0rTHwZORSZzG9pWACakYFN3ZhqC6gzYE+BrBCIXhCjNeYAjR/JEfTe8gImE=" Mar 25 17:48:08 katarynka volumio[19556]: info: Connection to go-librespot Websocket closed Mar 25 17:48:08 katarynka volumio[19556]: error: Cannot start Volumio Streaming Daemon Mar 25 17:48:08 katarynka volumio[19556]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Mar 25 17:48:08 katarynka volumio[19556]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Mar 25 17:48:08 katarynka go-librespot[19919]: time="2026-03-25T17:48:08+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 17:48:08 katarynka volumio[19556]: 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 17:48:08 katarynka go-librespot[19919]: time="2026-03-25T17:48:08+01:00" level=debug msg="completed keyexchange" Mar 25 17:48:08 katarynka go-librespot[19919]: time="2026-03-25T17:48:08+01:00" level=debug msg="completed challenge" Mar 25 17:48:08 katarynka go-librespot[19919]: time="2026-03-25T17:48: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 17:48:08 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 17:48:08 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 17:48:08 katarynka volumio[19556]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 25 17:48:08 katarynka volumio[19556]: Error: socket hang up Mar 25 17:48:08 katarynka volumio[19556]: at connResetException (node:internal/errors:720:14) Mar 25 17:48:08 katarynka volumio[19556]: at Socket.socketOnEnd (node:_http_client:519:23) Mar 25 17:48:08 katarynka volumio[19556]: at Socket.emit (node:events:526:35) Mar 25 17:48:08 katarynka volumio[19556]: at endReadableNT (node:internal/streams/readable:1376:12) Mar 25 17:48:08 katarynka volumio[19556]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Mar 25 17:48:08 katarynka volumio[19556]: code: 'ECONNRESET', Mar 25 17:48:08 katarynka volumio[19556]: response: undefined Mar 25 17:48:08 katarynka volumio[19556]: } Mar 25 17:48:08 katarynka volumio[19556]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 25 17:48:10 katarynka sudo[19961]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-03-25 17:47' Mar 25 17:48:10 katarynka sudo[19961]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 17:48:10 katarynka sudo[19961]: pam_unix(sudo:session): session closed for user root Mar 25 17:48:11 katarynka volumio-remote-updater[665]: [2026-03-25 17:48:11] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Mar 25 17:48:11 katarynka volumio-remote-updater[665]: [2026-03-25 17:48:11] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Mar 25 17:48:11 katarynka systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Mar 25 17:48:11 katarynka systemd[1]: volumio.service: Failed with result 'exit-code'. Mar 25 17:48:11 katarynka systemd[1]: volumio.service: Consumed 46.064s CPU time. Mar 25 17:48:11 katarynka systemd[1]: Started dynamicswap.service - dynamicswap service. Mar 25 17:48:11 katarynka systemd[1]: dynamicswap.service: Deactivated successfully. Mar 25 17:48:11 katarynka systemd[1]: volumio.service: Scheduled restart job, restart counter is at 38. Mar 25 17:48:11 katarynka systemd[1]: Started dynamicswap.service - dynamicswap service. Mar 25 17:48:11 katarynka systemd[1]: Stopped volumio.service - Volumio Backend Module. Mar 25 17:48:11 katarynka systemd[1]: volumio.service: Consumed 46.064s CPU time. Mar 25 17:48:11 katarynka systemd[1]: Started volumio.service - Volumio Backend Module. Mar 25 17:48:11 katarynka systemd[1]: dynamicswap.service: Deactivated successfully. Mar 25 17:48:11 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 17. Mar 25 17:48:11 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 17:48:11 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 17:48:11 katarynka go-librespot[19991]: go-librespot daemon starting... Mar 25 17:48:11 katarynka go-librespot[19992]: time="2026-03-25T17:48:11+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 17:48:11 katarynka go-librespot[19992]: time="2026-03-25T17:48:11+01:00" level=debug msg="app state loaded" Mar 25 17:48:11 katarynka go-librespot[19992]: time="2026-03-25T17:48:11+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 17:48:12 katarynka go-librespot[19992]: time="2026-03-25T17:48:12+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 25 17:48:12 katarynka go-librespot[19992]: time="2026-03-25T17:48:12+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 17:48:12 katarynka go-librespot[19992]: time="2026-03-25T17:48:12+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 17:48:12 katarynka go-librespot[19992]: time="2026-03-25T17:48:12+01:00" level=info msg="zeroconf server listening on port 34979" Mar 25 17:48:12 katarynka go-librespot[19992]: time="2026-03-25T17:48:12+01:00" level=debug msg="obtained new client token: AACqKo08jhV4l120WBN/zPFlKjDMI0spYYX3qi+4/qiiSGy2RvsUwQ1p1SdsukksS4CV3gL8eiaZGvl0Z3AzivELHV4GpGoPmXQt/SIcmZDaKeuqSizRRJq1UJ+nR5hmr4w17uhsG1NUWgELhV6mIDuOL3kWmTAtSAQAWt7FQyqsTIKNJS6i9W3UC/UgowRxd0dDGBJZw9r9lCOzCV8txTposjb+haVJPPCiSHJq2Qf79EmPVtDmX2aVmFg=" Mar 25 17:48:12 katarynka go-librespot[19992]: time="2026-03-25T17:48:12+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 17:48:12 katarynka go-librespot[19992]: time="2026-03-25T17:48:12+01:00" level=debug msg="completed keyexchange" Mar 25 17:48:12 katarynka go-librespot[19992]: time="2026-03-25T17:48:12+01:00" level=debug msg="completed challenge" Mar 25 17:48:12 katarynka go-librespot[19992]: time="2026-03-25T17:48: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 17:48:12 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 17:48:12 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 17:48:14 katarynka volumio[19976]: info: ------------------------------------------- Mar 25 17:48:14 katarynka volumio[19976]: info: ----- Volumio3 ---- Mar 25 17:48:14 katarynka volumio[19976]: info: ------------------------------------------- Mar 25 17:48:14 katarynka volumio[19976]: info: ----- System startup ---- Mar 25 17:48:14 katarynka volumio[19976]: info: ------------------------------------------- Mar 25 17:48:15 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 18. Mar 25 17:48:15 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 17:48:15 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 17:48:15 katarynka go-librespot[20007]: go-librespot daemon starting... Mar 25 17:48:15 katarynka go-librespot[20008]: time="2026-03-25T17:48:15+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 17:48:15 katarynka go-librespot[20008]: time="2026-03-25T17:48:15+01:00" level=debug msg="app state loaded" Mar 25 17:48:15 katarynka go-librespot[20008]: time="2026-03-25T17:48:15+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 17:48:16 katarynka volumio-remote-updater[665]: [2026-03-25 17:48:16] [connect] Successful connection Mar 25 17:48:16 katarynka volumio[19976]: info: MYVOLUMIO Environment detected Mar 25 17:48:16 katarynka go-librespot[20008]: time="2026-03-25T17:48: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-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 25 17:48:16 katarynka go-librespot[20008]: time="2026-03-25T17:48:16+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 17:48:16 katarynka go-librespot[20008]: time="2026-03-25T17:48:16+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 17:48:16 katarynka volumio[19976]: info: Plugin folders cleanup Mar 25 17:48:16 katarynka volumio[19976]: info: Scanning into folder /volumio/app/plugins/ Mar 25 17:48:16 katarynka volumio[19976]: info: Scanning category audio_interface Mar 25 17:48:16 katarynka volumio[19976]: info: Scanning category miscellanea Mar 25 17:48:16 katarynka go-librespot[20008]: time="2026-03-25T17:48:16+01:00" level=info msg="zeroconf server listening on port 42081" Mar 25 17:48:16 katarynka volumio[19976]: info: Scanning category music_service Mar 25 17:48:16 katarynka volumio[19976]: info: Scanning category plugins.json Mar 25 17:48:16 katarynka volumio[19976]: info: Scanning category system_controller Mar 25 17:48:16 katarynka volumio[19976]: info: Scanning category user_interface Mar 25 17:48:16 katarynka volumio[19976]: info: Scanning into folder /data/plugins/ Mar 25 17:48:16 katarynka volumio[19976]: info: Scanning category music_service Mar 25 17:48:16 katarynka volumio[19976]: info: Plugin folders cleanup completed Mar 25 17:48:16 katarynka volumio[19976]: info: ------------------------------------------- Mar 25 17:48:16 katarynka volumio[19976]: info: ----- Core plugins startup ---- Mar 25 17:48:16 katarynka volumio[19976]: info: ------------------------------------------- Mar 25 17:48:16 katarynka volumio[19976]: info: Loading plugins from folder /volumio/app/plugins/ Mar 25 17:48:16 katarynka volumio[19976]: info: Adding plugin upnp to MyMusic Plugins Mar 25 17:48:16 katarynka volumio[19976]: info: Adding plugin airplay_emulation to MyMusic Plugins Mar 25 17:48:16 katarynka volumio[19976]: info: Adding plugin upnp_browser to MyMusic Plugins Mar 25 17:48:16 katarynka volumio[19976]: info: Loading plugins from folder /data/plugins/ Mar 25 17:48:16 katarynka volumio[19976]: info: Loading plugin "system"... Mar 25 17:48:16 katarynka go-librespot[20008]: time="2026-03-25T17:48:16+01:00" level=debug msg="obtained new client token: AAB+TJo9eSB16xEtz0zf994n9j0DTC0f9oENFv58lwCbQNsUn0jwaKF3bGAUCa9qoY8t1Q6PtfBh3/3Z6Ty4Pih+bVv4J/C6q2jGGumZAfzqHTEfs1F6lgkXirvD2XMMIvPY5QEaue2FGQ2dk9UDrFk6A7aO9/x54ClhfxLARF1XapjPysW24lKkaiIl911IkBBaYzcg/EyzvbNzO3MGFF2CI/MkAhi6KRtXZkciAcFYcmMzED7I19EvtDU=" Mar 25 17:48:16 katarynka volumio[19976]: info: Loading plugin "appearance"... Mar 25 17:48:16 katarynka go-librespot[20008]: time="2026-03-25T17:48:16+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 17:48:16 katarynka go-librespot[20008]: time="2026-03-25T17:48:16+01:00" level=debug msg="completed keyexchange" Mar 25 17:48:16 katarynka go-librespot[20008]: time="2026-03-25T17:48:16+01:00" level=debug msg="completed challenge" Mar 25 17:48:16 katarynka go-librespot[20008]: time="2026-03-25T17:48: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 17:48:16 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 17:48:16 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 17:48:18 katarynka volumio[19976]: info: Loading plugin "network"... Mar 25 17:48:18 katarynka volumio[19976]: info: Refreshing Cached IP Addresses Mar 25 17:48:18 katarynka sudo[20023]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 25 17:48:18 katarynka sudo[20023]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 17:48:18 katarynka sudo[20025]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 25 17:48:18 katarynka sudo[20025]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 17:48:18 katarynka sudo[20023]: pam_unix(sudo:session): session closed for user root Mar 25 17:48:18 katarynka volumio[19976]: info: Loading plugin "services"... Mar 25 17:48:18 katarynka volumio[19976]: info: Loading plugin "alsa_controller"... Mar 25 17:48:18 katarynka sudo[20025]: pam_unix(sudo:session): session closed for user root Mar 25 17:48:18 katarynka sudo[20037]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Mar 25 17:48:18 katarynka sudo[20037]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 17:48:18 katarynka volumio[19976]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 25 17:48:18 katarynka volumio[19976]: info: Loading plugin "wizard"... Mar 25 17:48:18 katarynka volumio[19976]: info: Loading plugin "networkfs"... Mar 25 17:48:18 katarynka volumio[19976]: info: Starting Udev Watcher for removable devices Mar 25 17:48:18 katarynka volumio[19976]: info: Ignoring mount for partition: boot Mar 25 17:48:18 katarynka volumio[19976]: info: Ignoring mount for partition: volumio Mar 25 17:48:18 katarynka volumio[19976]: info: Ignoring mount for partition: volumio_data Mar 25 17:48:18 katarynka volumio[19976]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 25 17:48:18 katarynka volumio[19976]: info: Loading plugin "volumio_command_line_client"... Mar 25 17:48:18 katarynka volumio[19976]: info: Loading plugin "upnp"... Mar 25 17:48:18 katarynka volumio[19976]: info: [1774457298851] Starting Upmpd Daemon Mar 25 17:48:18 katarynka volumio[19976]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 25 17:48:18 katarynka volumio[19976]: info: Loading plugin "my_music"... Mar 25 17:48:18 katarynka volumio[19976]: info: Loading plugin "mpd"... Mar 25 17:48:19 katarynka sudo[20037]: pam_unix(sudo:session): session closed for user root Mar 25 17:48:19 katarynka volumio[19976]: info: Loading plugin "upnp_browser"... Mar 25 17:48:19 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 19. Mar 25 17:48:19 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 17:48:19 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 17:48:19 katarynka go-librespot[20060]: go-librespot daemon starting... Mar 25 17:48:19 katarynka go-librespot[20061]: time="2026-03-25T17:48:19+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 17:48:19 katarynka go-librespot[20061]: time="2026-03-25T17:48:19+01:00" level=debug msg="app state loaded" Mar 25 17:48:19 katarynka go-librespot[20061]: time="2026-03-25T17:48:19+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 17:48:20 katarynka go-librespot[20061]: time="2026-03-25T17:48:20+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 25 17:48:20 katarynka go-librespot[20061]: time="2026-03-25T17:48:20+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 17:48:20 katarynka go-librespot[20061]: time="2026-03-25T17:48:20+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 17:48:20 katarynka go-librespot[20061]: time="2026-03-25T17:48:20+01:00" level=info msg="zeroconf server listening on port 39733" Mar 25 17:48:20 katarynka go-librespot[20061]: time="2026-03-25T17:48:20+01:00" level=debug msg="obtained new client token: AAC9pHdAANp8BDe9Hvf9ko5GqrDieHBwvsLD3IglDYmiWY/4ZpKN1NyyhyiXNnj/Z8aaePlgfpjFrdFOOwOsjHtuQIqGNzmg3W75Nw0DbjMvgW+kz4cG+kP8JWkRmOvde4ZeFOG5jszZc3QZwF4AdZVyKcP83pwIzC+OiZEouXAfVVMYhNxewikQtKlOgTjXEKrOxF5T7V9Dg/Q4wYL+vjgK2lN/G5yf+SE2yHupvk4CrPRILaaCbjH4OLM=" Mar 25 17:48:20 katarynka go-librespot[20061]: time="2026-03-25T17:48:20+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 17:48:20 katarynka go-librespot[20061]: time="2026-03-25T17:48:20+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Mar 25 17:48:20 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 17:48:20 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 17:48:22 katarynka volumio[19976]: info: Starting UPNP Browser Mar 25 17:48:22 katarynka volumio[19976]: info: Loading plugin "alarm-clock"... Mar 25 17:48:22 katarynka volumio[19976]: info: Loading plugin "airplay_emulation"... Mar 25 17:48:22 katarynka volumio[19976]: info: Starting Shairport Sync Mar 25 17:48:22 katarynka volumio[19976]: info: Loading plugin "last_100"... Mar 25 17:48:22 katarynka volumio[19976]: info: Loading plugin "webradio"... Mar 25 17:48:23 katarynka volumio[19976]: info: Loading plugin "i2s_dacs"... Mar 25 17:48:23 katarynka volumio[19976]: info: Loading plugin "volumiodiscovery"... Mar 25 17:48:23 katarynka volumio[19976]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Mar 25 17:48:23 katarynka volumio[19976]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 25 17:48:23 katarynka volumio[19976]: *** WARNING *** For more information see Mar 25 17:48:23 katarynka volumio[19976]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Mar 25 17:48:23 katarynka volumio[19976]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 25 17:48:23 katarynka volumio[19976]: *** WARNING *** For more information see Mar 25 17:48:23 katarynka node[19976]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Mar 25 17:48:23 katarynka node[19976]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 25 17:48:23 katarynka node[19976]: *** WARNING *** For more information see Mar 25 17:48:23 katarynka node[19976]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Mar 25 17:48:23 katarynka node[19976]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 25 17:48:23 katarynka node[19976]: *** WARNING *** For more information see Mar 25 17:48:23 katarynka volumio[19976]: info: Applying required configuration parameters for plugin volumiodiscovery Mar 25 17:48:23 katarynka volumio[19976]: info: Discovery: Started advertising with name: katarynka Mar 25 17:48:23 katarynka volumio[19976]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 25 17:48:23 katarynka volumio[19976]: info: Loading plugin "spop"... Mar 25 17:48:23 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 20. Mar 25 17:48:23 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 17:48:23 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 17:48:23 katarynka go-librespot[20070]: go-librespot daemon starting... Mar 25 17:48:23 katarynka go-librespot[20071]: time="2026-03-25T17:48:23+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 17:48:23 katarynka go-librespot[20071]: time="2026-03-25T17:48:23+01:00" level=debug msg="app state loaded" Mar 25 17:48:23 katarynka go-librespot[20071]: time="2026-03-25T17:48:23+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 17:48:24 katarynka go-librespot[20071]: time="2026-03-25T17:48:24+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Mar 25 17:48:24 katarynka go-librespot[20071]: time="2026-03-25T17:48:24+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Mar 25 17:48:24 katarynka go-librespot[20071]: time="2026-03-25T17:48:24+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Mar 25 17:48:24 katarynka go-librespot[20071]: time="2026-03-25T17:48:24+01:00" level=info msg="zeroconf server listening on port 44391" Mar 25 17:48:24 katarynka go-librespot[20071]: time="2026-03-25T17:48:24+01:00" level=debug msg="obtained new client token: AAAULwO3KTtPpPO45eBzw4OQxD1yImAHeq9g9ZJ5XdoijBu9p4q3mtc2erD90OQZLiTbW1Ukc6xsNZRDwyv+GwPOe8gWcfeeK6LV1wmUXfGjpoDdNqwH1HP6Jo1cWkZj0rOs6PXa43Qjf77IZThq7SqImznRHV87uhX/sCeTCF61P/FAHhoDQ6CxrM+vfFIvxO6w2ExFjjCox03fSOxEJqAfInunpW+u5kOczPC9dVtoPfgFl9Vmwpjdf8c=" Mar 25 17:48:24 katarynka go-librespot[20071]: time="2026-03-25T17:48:24+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 17:48:24 katarynka go-librespot[20071]: time="2026-03-25T17:48:24+01:00" level=warning msg="failed to connect to AP ap-gew4.spotify.com:443, retrying with a different AP" error="dial tcp 34.158.1.133:443: connect: connection refused" Mar 25 17:48:24 katarynka go-librespot[20071]: time="2026-03-25T17:48:24+01:00" level=debug msg="connected to ap-gew4.spotify.com:80" Mar 25 17:48:25 katarynka volumio[19976]: info: Loading plugin "outputs"... Mar 25 17:48:25 katarynka volumio[19976]: info: Loading plugin "albumart"... Mar 25 17:48:25 katarynka volumio[19976]: info: Plugin example_plugin is not enabled Mar 25 17:48:25 katarynka volumio[19976]: info: Loading plugin "inputs"... Mar 25 17:48:25 katarynka go-librespot[20071]: time="2026-03-25T17:48:25+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Mar 25 17:48:25 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 17:48:25 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 17:48:25 katarynka volumio[19976]: info: Loading plugin "updater_comm"... Mar 25 17:48:25 katarynka volumio[19976]: info: Plugin mpdemulation is not enabled Mar 25 17:48:25 katarynka volumio[19976]: info: Loading plugin "rest_api"... Mar 25 17:48:25 katarynka volumio[19976]: info: Loading plugin "websocket"... Mar 25 17:48:25 katarynka volumio[19976]: info: Starting Socket.io Server version 1.7.4 Mar 25 17:48:25 katarynka volumio[19976]: info: Loading i18n strings for locale pl Mar 25 17:48:25 katarynka volumio[19976]: Updating browse sources language Mar 25 17:48:25 katarynka volumio[19976]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 25 17:48:25 katarynka volumio[19976]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 25 17:48:25 katarynka volumio[19976]: info: CoreCommandRouter::initPlayerControls Mar 25 17:48:25 katarynka volumio[19976]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 17:48:25 katarynka volumio[19976]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 17:48:25 katarynka volumio[19976]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 17:48:25 katarynka volumio[19976]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 17:48:25 katarynka volumio[19976]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 17:48:25 katarynka volumio[19976]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 17:48:25 katarynka volumio[19976]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 17:48:25 katarynka volumio[19976]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 17:48:25 katarynka volumio[19976]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 25 17:48:25 katarynka volumio[19976]: Express server listening on port 3000 Mar 25 17:48:25 katarynka volumio[19976]: [Metrics] WebUI: 11s 820.97ms Mar 25 17:48:25 katarynka volumio[19976]: info: CoreStateMachine::resetVolumioState Mar 25 17:48:25 katarynka volumio[19976]: info: CoreStateMachine::getcurrentVolume Mar 25 17:48:25 katarynka volumio[19976]: info: CoreCommandRouter::volumioRetrievevolume Mar 25 17:48:25 katarynka volumio[19976]: info: Cannot read play queue from file Mar 25 17:48:25 katarynka volumio[19976]: info: Volumio Network Manager: Network status updated: 2 Mar 25 17:48:26 katarynka volumio[20078]: Forking 3 albumart workers Mar 25 17:48:26 katarynka volumio[19976]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 17:48:26 katarynka volumio[19976]: info: CoreStateMachine::setRepeat null single undefined Mar 25 17:48:26 katarynka volumio[19976]: info: CoreStateMachine::pushState Mar 25 17:48:26 katarynka volumio[19976]: info: CorePlayQueue::getTrack 0 Mar 25 17:48:26 katarynka volumio[19976]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 25 17:48:26 katarynka volumio[19976]: info: CoreCommandRouter::volumioPushState Mar 25 17:48:26 katarynka volumio[19976]: info: CoreStateMachine::setRandom null Mar 25 17:48:26 katarynka volumio[19976]: info: CoreStateMachine::pushState Mar 25 17:48:26 katarynka volumio[19976]: info: CorePlayQueue::getTrack 0 Mar 25 17:48:26 katarynka volumio[19976]: info: CoreCommandRouter::volumioPushState Mar 25 17:48:26 katarynka volumio[19976]: info: Setting Device type: Raspberry PI Mar 25 17:48:26 katarynka volumio[19976]: info: Completed loading Core Plugins Mar 25 17:48:26 katarynka volumio[19976]: info: Preparing to generate the ALSA configuration file Mar 25 17:48:26 katarynka volumio[19976]: info: VolumeController:: Volume=96 Mute =false Mar 25 17:48:26 katarynka volumio[19976]: info: CoreStateMachine::pushState Mar 25 17:48:26 katarynka volumio[19976]: info: CorePlayQueue::getTrack 0 Mar 25 17:48:26 katarynka volumio[19976]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 25 17:48:26 katarynka volumio[19976]: info: CoreCommandRouter::volumioPushState Mar 25 17:48:26 katarynka volumio[19976]: info: CoreStateMachine::updateTrackBlock Mar 25 17:48:26 katarynka volumio[19976]: info: CorePlayQueue::getTrackBlock Mar 25 17:48:26 katarynka volumio[19976]: info: CoreCommandRouter::volumioRetrievevolume Mar 25 17:48:26 katarynka volumio[19976]: info: Asound.conf file unchanged, so no further update is needed Mar 25 17:48:26 katarynka volumio[19976]: info: Output device has changed, restarting MPD Mar 25 17:48:26 katarynka volumio[19976]: info: Output device has changed, restarting Shairport Sync Mar 25 17:48:26 katarynka volumio[19976]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 17:48:26 katarynka volumio[19976]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 17:48:26 katarynka sudo[20129]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 25 17:48:26 katarynka sudo[20129]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 17:48:26 katarynka volumio[19976]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 25 17:48:26 katarynka volumio[19976]: info: ___________ START PLUGINS ___________ Mar 25 17:48:26 katarynka volumio[19976]: info: ControllerMpd::onStart: Initializing MPD Mar 25 17:48:26 katarynka sudo[20129]: pam_unix(sudo:session): session closed for user root Mar 25 17:48:26 katarynka volumio[19976]: info: Creating MPD Configuration file Mar 25 17:48:26 katarynka sudo[20132]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 25 17:48:26 katarynka sudo[20132]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 17:48:26 katarynka volumio[19976]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 25 17:48:26 katarynka volumio[19976]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 25 17:48:26 katarynka volumio[19976]: info: [1774457306656] CoreMusicLibrary::Adding element Serwery Mediów Mar 25 17:48:26 katarynka volumio[19976]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 25 17:48:26 katarynka sudo[20140]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 25 17:48:26 katarynka volumio[19976]: info: UPNP Browser: Client initialized successfully Mar 25 17:48:26 katarynka sudo[20140]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 17:48:26 katarynka sudo[20140]: pam_unix(sudo:session): session closed for user root Mar 25 17:48:26 katarynka systemd[1]: Stopping mpd.service - Music Player Daemon... Mar 25 17:48:26 katarynka sudo[20143]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 25 17:48:26 katarynka sudo[20143]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 17:48:26 katarynka volumio[19976]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 17:48:26 katarynka volumio[19976]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 17:48:26 katarynka systemd[1]: mpd.service: Deactivated successfully. Mar 25 17:48:26 katarynka systemd[1]: Stopped mpd.service - Music Player Daemon. Mar 25 17:48:26 katarynka systemd[1]: mpd.service: Consumed 7.023s CPU time. Mar 25 17:48:26 katarynka systemd[1]: mpd.socket: Deactivated successfully. Mar 25 17:48:26 katarynka systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Mar 25 17:48:26 katarynka systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Mar 25 17:48:26 katarynka volumio[19976]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 25 17:48:26 katarynka volumio[19976]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 17:48:26 katarynka volumio[19976]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 17:48:26 katarynka systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Mar 25 17:48:26 katarynka volumio[19976]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 25 17:48:26 katarynka volumio[19976]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 25 17:48:26 katarynka volumio[19976]: info: [1774457306979] CoreMusicLibrary::Adding element Last_100 Mar 25 17:48:26 katarynka volumio[19976]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 25 17:48:26 katarynka systemd[1]: Starting mpd.service - Music Player Daemon... Mar 25 17:48:26 katarynka volumio[19976]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 25 17:48:26 katarynka volumio[19976]: info: [1774457306998] CoreMusicLibrary::Adding element Webradio Mar 25 17:48:26 katarynka volumio[19976]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 25 17:48:27 katarynka volumio[19976]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 25 17:48:27 katarynka volumio[19976]: info: Initializing BBC Radios Mar 25 17:48:27 katarynka volumio[19976]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 25 17:48:27 katarynka volumio[19976]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 17:48:27 katarynka volumio[19976]: info: Creating Spotify config file Mar 25 17:48:27 katarynka volumio[19976]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 17:48:27 katarynka sudo[20155]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Mar 25 17:48:27 katarynka sudo[20155]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Mar 25 17:48:27 katarynka sudo[20155]: pam_unix(sudo:session): session closed for user root Mar 25 17:48:28 katarynka volumio[19976]: info: Volumio Calling Home Mar 25 17:48:28 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 21. Mar 25 17:48:28 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 17:48:28 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 17:48:28 katarynka go-librespot[20173]: go-librespot daemon starting... Mar 25 17:48:28 katarynka go-librespot[20175]: time="2026-03-25T17:48:28+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 17:48:28 katarynka volumio-remote-updater[665]: [2026-03-25 17:48:28] [connect] Successful connection Mar 25 17:48:29 katarynka go-librespot[20175]: time="2026-03-25T17:48:29+01:00" level=info msg="zeroconf server listening on port 36413" Mar 25 17:48:29 katarynka volumio[19976]: info: Discovery: adding 4d616d77-6a8c-4da2-85a4-840d70f98e51 Mar 25 17:48:29 katarynka volumio[19976]: info: Discovery: Found device katarynka Mar 25 17:48:29 katarynka volumio[19976]: info: CoreCommandRouter::volumioGetState Mar 25 17:48:29 katarynka volumio[19976]: info: CorePlayQueue::getTrack 0 Mar 25 17:48:29 katarynka volumio[19976]: info: Discovery: this is already registered, 4d616d77-6a8c-4da2-85a4-840d70f98e51 Mar 25 17:48:29 katarynka sudo[20200]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 25 17:48:29 katarynka volumio[19976]: info: Discovery: Found device katarynka Mar 25 17:48:29 katarynka volumio[19976]: info: CoreCommandRouter::volumioGetState Mar 25 17:48:29 katarynka sudo[20200]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 17:48:29 katarynka volumio[19976]: info: CorePlayQueue::getTrack 0 Mar 25 17:48:29 katarynka sudo[20198]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 25 17:48:29 katarynka sudo[20198]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 17:48:29 katarynka sudo[20200]: pam_unix(sudo:session): session closed for user root Mar 25 17:48:29 katarynka sudo[20198]: pam_unix(sudo:session): session closed for user root Mar 25 17:48:29 katarynka volumio[19976]: info: MPD Permissions set Mar 25 17:48:29 katarynka volumio[19976]: info: MPD Permissions set Mar 25 17:48:29 katarynka volumio-remote-updater[665]: [2026-03-25 17:48:29] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1774457308 101 Mar 25 17:48:29 katarynka volumio[19976]: 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 17:48:29 katarynka volumio[19976]: info: Volumio called home Mar 25 17:48:29 katarynka volumio[19976]: info: Spotify config file written Mar 25 17:48:29 katarynka sudo[20205]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Mar 25 17:48:29 katarynka sudo[20205]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 17:48:30 katarynka volumio[20097]: Starting albumart workers Mar 25 17:48:30 katarynka volumio[20098]: Starting albumart workers Mar 25 17:48:30 katarynka systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Mar 25 17:48:30 katarynka systemd[1]: go-librespot-daemon.service: Deactivated successfully. Mar 25 17:48:30 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 17:48:30 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 17:48:30 katarynka go-librespot[20207]: go-librespot daemon starting... Mar 25 17:48:30 katarynka volumio[19976]: 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 17:48:30 katarynka sudo[20205]: pam_unix(sudo:session): session closed for user root Mar 25 17:48:30 katarynka volumio[19976]: info: VolumeController:: Volume=96 Mute =false Mar 25 17:48:30 katarynka volumio[19976]: info: CoreStateMachine::pushState Mar 25 17:48:30 katarynka volumio[19976]: info: CorePlayQueue::getTrack 0 Mar 25 17:48:30 katarynka volumio[19976]: info: CoreCommandRouter::volumioPushState Mar 25 17:48:30 katarynka volumio[19976]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 17:48:30 katarynka volumio[19976]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 17:48:30 katarynka volumio[19976]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 17:48:30 katarynka volumio[19976]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 17:48:30 katarynka volumio[19976]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 17:48:30 katarynka volumio[19976]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 17:48:30 katarynka volumio[19976]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 17:48:30 katarynka volumio[19976]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 17:48:30 katarynka go-librespot[20208]: time="2026-03-25T17:48:30+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 17:48:30 katarynka go-librespot[20208]: time="2026-03-25T17:48:30+01:00" level=debug msg="app state loaded" Mar 25 17:48:30 katarynka go-librespot[20208]: time="2026-03-25T17:48:30+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 17:48:30 katarynka volumio[19976]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 17:48:30 katarynka volumio[19976]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 17:48:30 katarynka volumio[19976]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 17:48:30 katarynka volumio[19976]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 17:48:30 katarynka volumio[19976]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 17:48:30 katarynka volumio[19976]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 17:48:30 katarynka volumio[19976]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 17:48:30 katarynka volumio[19976]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 17:48:30 katarynka volumio[19976]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 17:48:30 katarynka volumio[19976]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 17:48:30 katarynka volumio[19976]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 17:48:30 katarynka volumio[19976]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 17:48:30 katarynka volumio[19976]: info: No need to fix Spotify hosts Mar 25 17:48:30 katarynka volumio[20099]: Starting albumart workers Mar 25 17:48:30 katarynka go-librespot[20208]: time="2026-03-25T17:48: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 17:48:30 katarynka go-librespot[20208]: time="2026-03-25T17:48: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 17:48:30 katarynka go-librespot[20208]: time="2026-03-25T17:48: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 17:48:30 katarynka go-librespot[20208]: time="2026-03-25T17:48:30+01:00" level=info msg="zeroconf server listening on port 33385" Mar 25 17:48:30 katarynka volumio[19976]: info: Starting Shairport Sync Mar 25 17:48:31 katarynka volumio[19976]: info: Starting Shairport Sync Mar 25 17:48:31 katarynka volumio[19976]: info: Starting Shairport Sync Mar 25 17:48:31 katarynka sudo[20226]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 25 17:48:31 katarynka sudo[20226]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 17:48:31 katarynka go-librespot[20208]: time="2026-03-25T17:48:31+01:00" level=debug msg="obtained new client token: AAB2yC0LQpdL+86DIypHLcDhiiDnWRiQgvAVeClsivCzf1Zvhs46qeRx3nG4t6GjO68rKdUwlzwV8wEHEkDy1f87GfuYlPNvOGRUAUzSrsPffWWgJdBSaCgAzYdw9Yl6nchD0RPiKG8Yp+bzXuJeHyzvwMdu8yoj2U0LRq2woNFGru+P6RNkVIXwZwojjgeZmW6moDkTjyaQ1SwaBr1iJAYV+LAx9AOBVhPluVt5wgNaId8GSng8nRys" Mar 25 17:48:31 katarynka sudo[20230]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 25 17:48:31 katarynka sudo[20230]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 17:48:31 katarynka sudo[20228]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 25 17:48:31 katarynka sudo[20228]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 17:48:31 katarynka sudo[20233]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Mar 25 17:48:31 katarynka sudo[20233]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 17:48:31 katarynka go-librespot[20208]: time="2026-03-25T17:48:31+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 17:48:31 katarynka go-librespot[20208]: time="2026-03-25T17:48:31+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Mar 25 17:48:31 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 17:48:31 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 17:48:31 katarynka systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Mar 25 17:48:31 katarynka sudo[20233]: pam_unix(sudo:session): session closed for user root Mar 25 17:48:31 katarynka systemd[1]: shairport-sync.service: Deactivated successfully. Mar 25 17:48:31 katarynka systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 25 17:48:31 katarynka systemd[1]: shairport-sync.service: Consumed 2.240s CPU time. Mar 25 17:48:31 katarynka volumio[19976]: info: An error occurred while refreshing Spotify Token Error: Bad Request Mar 25 17:48:31 katarynka systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 25 17:48:31 katarynka sudo[20228]: pam_unix(sudo:session): session closed for user root Mar 25 17:48:31 katarynka sudo[20230]: pam_unix(sudo:session): session closed for user root Mar 25 17:48:31 katarynka sudo[20226]: pam_unix(sudo:session): session closed for user root Mar 25 17:48:31 katarynka volumio[19976]: info: Upmpdcli Daemon Started Mar 25 17:48:31 katarynka volumio[19976]: info: Shairport-Sync Started Mar 25 17:48:31 katarynka volumio[19976]: Error adding Membership: Error: addMembership EINVAL Mar 25 17:48:31 katarynka volumio[19976]: info: Shairport-Sync Started Mar 25 17:48:31 katarynka volumio[19976]: info: Shairport-Sync Started Mar 25 17:48:31 katarynka volumio[19976]: info: CoreCommandRouter::volumioGetState Mar 25 17:48:31 katarynka volumio[19976]: info: CorePlayQueue::getTrack 0 Mar 25 17:48:33 katarynka volumio[19976]: info: go-librespot daemon successfully initialized Mar 25 17:48:34 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Mar 25 17:48:34 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 17:48:34 katarynka mpd[20170]: 2026-03-25T17:48:34 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Mar 25 17:48:34 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 17:48:34 katarynka go-librespot[20275]: go-librespot daemon starting... Mar 25 17:48:34 katarynka systemd[1]: Started mpd.service - Music Player Daemon. Mar 25 17:48:34 katarynka sudo[20143]: pam_unix(sudo:session): session closed for user root Mar 25 17:48:34 katarynka sudo[20132]: pam_unix(sudo:session): session closed for user root Mar 25 17:48:34 katarynka go-librespot[20278]: time="2026-03-25T17:48:34+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 17:48:34 katarynka go-librespot[20278]: time="2026-03-25T17:48:34+01:00" level=debug msg="app state loaded" Mar 25 17:48:34 katarynka go-librespot[20278]: time="2026-03-25T17:48:34+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 17:48:34 katarynka volumio[19976]: info: Completed starting Core Plugins Mar 25 17:48:34 katarynka volumio[19976]: info: ------------------------------------------- Mar 25 17:48:34 katarynka volumio[19976]: info: ----- MyVolumio plugins startup ---- Mar 25 17:48:34 katarynka volumio[19976]: info: ------------------------------------------- Mar 25 17:48:34 katarynka volumio[19976]: info: [MyVolumio PluginManager] Fetching plans data.... Mar 25 17:48:34 katarynka volumio[19976]: error: MPD error: The expression evaluated to a falsy value: Mar 25 17:48:34 katarynka volumio[19976]: assert.ok(self.idling) Mar 25 17:48:34 katarynka volumio[19976]: error: The expression evaluated to a falsy value: Mar 25 17:48:34 katarynka volumio[19976]: assert.ok(self.idling) Mar 25 17:48:34 katarynka volumio[19976]: info: MPD running with PID20170 Mar 25 17:48:34 katarynka volumio[19976]: ,establishing connection Mar 25 17:48:34 katarynka volumio[19976]: error: updateQueue error: null Mar 25 17:48:34 katarynka volumio[19976]: error: updateQueue error: null Mar 25 17:48:35 katarynka go-librespot[20278]: time="2026-03-25T17:48:35+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 25 17:48:35 katarynka go-librespot[20278]: time="2026-03-25T17:48:35+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 25 17:48:35 katarynka go-librespot[20278]: time="2026-03-25T17:48:35+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 25 17:48:35 katarynka go-librespot[20278]: time="2026-03-25T17:48:35+01:00" level=info msg="zeroconf server listening on port 39067" Mar 25 17:48:35 katarynka go-librespot[20278]: time="2026-03-25T17:48:35+01:00" level=debug msg="obtained new client token: AADCVxM3J8veq71k8IdMxNByNfwOmwLmDku7Vw6WtMHnQ8+OXjvtdI/9K8pFyuXW5T9UGpeE6MsRVxgs8G9z4+hsBchZzrBBkr0tsn8c/XWiuZfsjAkAvt0Rd7n+/Z0WFql2dhF01WFoBiitWBqiwI700c4TdiG25kmviGxOHE8sfSLcwNv8Q63ZxltXRqmPEn9YLSNhjMmfqbmn8ztjmO2y+g40wXSh2dnt+bnyTTh4Jzb8WUCgnVtwACw=" Mar 25 17:48:35 katarynka go-librespot[20278]: time="2026-03-25T17:48:35+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 17:48:35 katarynka go-librespot[20278]: time="2026-03-25T17:48:35+01:00" level=debug msg="connected to ap-gew4.spotify.com:443" Mar 25 17:48:35 katarynka go-librespot[20278]: time="2026-03-25T17:48:35+01:00" level=debug msg="completed keyexchange" Mar 25 17:48:35 katarynka go-librespot[20278]: time="2026-03-25T17:48:35+01:00" level=debug msg="completed challenge" Mar 25 17:48:35 katarynka go-librespot[20278]: time="2026-03-25T17:48: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 17:48:35 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 17:48:35 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 17:48:36 katarynka volumio[19976]: info: Initializing connection to go-librespot Websocket Mar 25 17:48:36 katarynka volumio[19976]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 25 17:48:37 katarynka sudo[20289]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Mar 25 17:48:37 katarynka sudo[20289]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 17:48:37 katarynka sudo[20291]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Mar 25 17:48:37 katarynka sudo[20291]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 17:48:37 katarynka systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Mar 25 17:48:37 katarynka systemd[1]: mpd_monitor.service: Deactivated successfully. Mar 25 17:48:37 katarynka systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Mar 25 17:48:37 katarynka systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Mar 25 17:48:37 katarynka sudo[20289]: pam_unix(sudo:session): session closed for user root Mar 25 17:48:37 katarynka sudo[20291]: pam_unix(sudo:session): session closed for user root Mar 25 17:48:37 katarynka volumio[19976]: info: Successfully started MPD Monitor Mar 25 17:48:37 katarynka mpd_monitor.sh[20294]: MPD Monitor Service: Starting MPD Monitor Service Mar 25 17:48:37 katarynka volumio[19976]: info: Successfully started MPD Monitor Mar 25 17:48:38 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Mar 25 17:48:38 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 17:48:38 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 17:48:38 katarynka go-librespot[20298]: go-librespot daemon starting... Mar 25 17:48:38 katarynka go-librespot[20312]: time="2026-03-25T17:48:38+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 17:48:38 katarynka go-librespot[20312]: time="2026-03-25T17:48:38+01:00" level=debug msg="app state loaded" Mar 25 17:48:38 katarynka go-librespot[20312]: time="2026-03-25T17:48:38+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 17:48:39 katarynka go-librespot[20312]: time="2026-03-25T17:48: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-gew1.spotify.com:80]" Mar 25 17:48:39 katarynka go-librespot[20312]: time="2026-03-25T17:48:39+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 17:48:39 katarynka go-librespot[20312]: time="2026-03-25T17:48:39+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 17:48:39 katarynka go-librespot[20312]: time="2026-03-25T17:48:39+01:00" level=info msg="zeroconf server listening on port 38835" Mar 25 17:48:39 katarynka go-librespot[20312]: time="2026-03-25T17:48:39+01:00" level=debug msg="obtained new client token: AAAitaRIR0dfuFtdaddURFcbWnhO/MFHApUdh6SM4RiVT6+Sk0O4Y0CrLhmGpSwYEtSJRh842RDquhnnsgYBOf0kSaS4vBXrCcYk7lrFp0X8OmeAS9dPfFklG4ewkW8xFKqtLmGZAhaAepK02Wkqfw3EzyHnMPz3HDx9HQsKUABEl3jU5SWVgGGrh+MeNM7zYK9B7vovcu2FrjywHPINYnPh/XB7JES6oCVAWj53iMPY4/FKJUh8aJ8s/Nk=" Mar 25 17:48:39 katarynka go-librespot[20312]: time="2026-03-25T17:48:39+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 17:48:39 katarynka go-librespot[20312]: time="2026-03-25T17:48:39+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: read tcp 192.168.100.107:54604->34.158.1.133:4070: read: connection reset by peer" Mar 25 17:48:39 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 17:48:39 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 17:48:39 katarynka volumio[19976]: info: Initializing connection to go-librespot Websocket Mar 25 17:48:39 katarynka volumio[19976]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 25 17:48:39 katarynka volumio[19976]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Mar 25 17:48:42 katarynka volumio[19976]: info: Initializing connection to go-librespot Websocket Mar 25 17:48:42 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Mar 25 17:48:42 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 17:48:42 katarynka volumio[19976]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 25 17:48:42 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 17:48:42 katarynka go-librespot[20320]: go-librespot daemon starting... Mar 25 17:48:42 katarynka go-librespot[20321]: time="2026-03-25T17:48:42+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 17:48:42 katarynka go-librespot[20321]: time="2026-03-25T17:48:42+01:00" level=debug msg="app state loaded" Mar 25 17:48:42 katarynka go-librespot[20321]: time="2026-03-25T17:48:42+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 17:48:43 katarynka go-librespot[20321]: time="2026-03-25T17:48:43+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 25 17:48:43 katarynka go-librespot[20321]: time="2026-03-25T17:48:43+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 25 17:48:43 katarynka go-librespot[20321]: time="2026-03-25T17:48:43+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 25 17:48:43 katarynka volumio[19976]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Mar 25 17:48:43 katarynka volumio[19976]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Mar 25 17:48:43 katarynka volumio[19976]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Mar 25 17:48:43 katarynka volumio[19976]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Mar 25 17:48:43 katarynka volumio[19976]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Mar 25 17:48:43 katarynka volumio[19976]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Mar 25 17:48:43 katarynka volumio[19976]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Mar 25 17:48:43 katarynka volumio[19976]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Mar 25 17:48:43 katarynka volumio[19976]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Mar 25 17:48:43 katarynka volumio[19976]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Mar 25 17:48:43 katarynka volumio[19976]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Mar 25 17:48:43 katarynka volumio[19976]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Mar 25 17:48:43 katarynka volumio[19976]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Mar 25 17:48:43 katarynka go-librespot[20321]: time="2026-03-25T17:48:43+01:00" level=info msg="zeroconf server listening on port 40329" Mar 25 17:48:43 katarynka volumio[19976]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Mar 25 17:48:43 katarynka volumio[19976]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Mar 25 17:48:43 katarynka volumio[19976]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Mar 25 17:48:43 katarynka volumio[19976]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Mar 25 17:48:43 katarynka volumio[19976]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Mar 25 17:48:43 katarynka volumio[19976]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Mar 25 17:48:43 katarynka volumio[19976]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Mar 25 17:48:43 katarynka volumio[19976]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Mar 25 17:48:43 katarynka volumio[19976]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Mar 25 17:48:43 katarynka volumio[19976]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Mar 25 17:48:43 katarynka volumio[19976]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Mar 25 17:48:43 katarynka volumio[19976]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Mar 25 17:48:43 katarynka volumio[19976]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Mar 25 17:48:43 katarynka volumio[19976]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Mar 25 17:48:43 katarynka volumio[19976]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Mar 25 17:48:43 katarynka volumio[19976]: info: Adding plugin bluetooth to MyMusic Plugins Mar 25 17:48:43 katarynka volumio[19976]: info: Adding plugin multiroom to MyMusic Plugins Mar 25 17:48:43 katarynka volumio[19976]: info: Adding plugin metavolumio to MyMusic Plugins Mar 25 17:48:43 katarynka volumio[19976]: info: Adding plugin cd_controller to MyMusic Plugins Mar 25 17:48:43 katarynka volumio[19976]: info: Adding plugin qobuzconnect to MyMusic Plugins Mar 25 17:48:43 katarynka volumio[19976]: info: Adding plugin smart_inputs to MyMusic Plugins Mar 25 17:48:43 katarynka volumio[19976]: info: Adding plugin tidalconnect to MyMusic Plugins Mar 25 17:48:43 katarynka volumio[19976]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Mar 25 17:48:43 katarynka go-librespot[20321]: time="2026-03-25T17:48:43+01:00" level=debug msg="obtained new client token: AADfGvnPJKq+/Lh4fUSgx5BYazffso+umshI6q/eOkq2gIRy9ACSabQPYu/21SHwldI+l0D4ct9TVf5CmpLsYP0EhKs5wPwezr0coh5KahpJDgmceqdnS+Yb5XkX2L4yN6HU+QMpXscUIn4/09tn1Me8Egtpl/6tfWVF6HvjzqxwS4Ddl2voI3+U3mnq0qaws6AQSm0+bOaKq+Ybw3ym/iGgVNmvMEUrci5x2aPxqzvRltUSlptRUSLk0Ks=" Mar 25 17:48:43 katarynka go-librespot[20321]: time="2026-03-25T17:48:43+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 17:48:43 katarynka go-librespot[20321]: time="2026-03-25T17:48:43+01:00" level=debug msg="completed keyexchange" Mar 25 17:48:43 katarynka go-librespot[20321]: time="2026-03-25T17:48:43+01:00" level=debug msg="completed challenge" Mar 25 17:48:43 katarynka go-librespot[20321]: time="2026-03-25T17:48:43+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 25 17:48:43 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 17:48:43 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 17:48:45 katarynka volumio[19976]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Mar 25 17:48:45 katarynka volumio[19976]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Mar 25 17:48:45 katarynka volumio[19976]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 17:48:45 katarynka volumio[19976]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 17:48:45 katarynka volumio[19976]: info: Starting MyVolumio Remote Streaming Endpoints Mar 25 17:48:45 katarynka volumio[19976]: info: MyVolumio login type: Token Mar 25 17:48:45 katarynka volumio[19976]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Mar 25 17:48:45 katarynka volumio[19976]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Mar 25 17:48:46 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Mar 25 17:48:46 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 17:48:46 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 17:48:46 katarynka go-librespot[20328]: go-librespot daemon starting... Mar 25 17:48:46 katarynka go-librespot[20329]: time="2026-03-25T17:48:46+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 17:48:46 katarynka go-librespot[20329]: time="2026-03-25T17:48:46+01:00" level=debug msg="app state loaded" Mar 25 17:48:47 katarynka go-librespot[20329]: time="2026-03-25T17:48:47+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 17:48:47 katarynka volumio[19976]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Mar 25 17:48:47 katarynka volumio[19976]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Mar 25 17:48:47 katarynka volumio[19976]: info: Streaming services startup Mar 25 17:48:47 katarynka volumio[19976]: info: Starting Streaming Daemon Mar 25 17:48:47 katarynka volumio[19976]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Mar 25 17:48:47 katarynka sudo[20337]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Mar 25 17:48:47 katarynka sudo[20337]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 17:48:47 katarynka sudo[20337]: pam_unix(sudo:session): session closed for user root Mar 25 17:48:47 katarynka volumio[19976]: info: Initializing connection to go-librespot Websocket Mar 25 17:48:47 katarynka volumio[19976]: error: Cannot start Volumio Streaming Daemon Mar 25 17:48:47 katarynka volumio[19976]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Mar 25 17:48:47 katarynka volumio[19976]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Mar 25 17:48:47 katarynka go-librespot[20329]: time="2026-03-25T17:48:47+01:00" level=debug msg="new websocket client" Mar 25 17:48:47 katarynka volumio[19976]: info: Connection to go-librespot Websocket established Mar 25 17:48:47 katarynka go-librespot[20329]: time="2026-03-25T17:48:47+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 25 17:48:47 katarynka go-librespot[20329]: time="2026-03-25T17:48:47+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 17:48:47 katarynka go-librespot[20329]: time="2026-03-25T17:48:47+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 17:48:47 katarynka go-librespot[20329]: time="2026-03-25T17:48:47+01:00" level=info msg="zeroconf server listening on port 33325" Mar 25 17:48:47 katarynka go-librespot[20329]: time="2026-03-25T17:48:47+01:00" level=debug msg="obtained new client token: AACwT+W+batRwPUAsmNPwAOGpiHmUilt/SLCDFSvHVLe+tRDjsBlmsjlJUul+y06yOLe4lrCj0c2CeKJC1slL3MZGAj4lQ18Mr8CUjFM2BmGfuocG29tRbmOeWGTS5fHxSU2iZ1iRKXe6mxvsbEKaxtMO/x9uss387gcmZ0I3+77tQjr/81xOgN66xkUysNmoMOyTX/xkbxPjSTzAr5znIMSIJWQbnKATo3oyabwpMrI5/AzUJFhpeqikro=" Mar 25 17:48:47 katarynka go-librespot[20329]: time="2026-03-25T17:48:47+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 17:48:47 katarynka go-librespot[20329]: time="2026-03-25T17:48:47+01:00" level=debug msg="completed keyexchange" Mar 25 17:48:47 katarynka go-librespot[20329]: time="2026-03-25T17:48:47+01:00" level=debug msg="completed challenge" Mar 25 17:48:47 katarynka go-librespot[20329]: time="2026-03-25T17:48: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 17:48:47 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 17:48:47 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 17:48:47 katarynka volumio[19976]: info: Connection to go-librespot Websocket closed Mar 25 17:48:47 katarynka volumio[19976]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Mar 25 17:48:48 katarynka volumio[19976]: info: MyVolumio token set successfully Mar 25 17:48:48 katarynka volumio[19976]: info: MYVOLUMIO: Adding device Mar 25 17:48:48 katarynka volumio[19976]: info: MYVOLUMIO: Evaluating Server Mar 25 17:48:48 katarynka volumio[19976]: info: MyVolumio status changed Mar 25 17:48:48 katarynka volumio[19976]: info: Streaming services startup Mar 25 17:48:48 katarynka volumio[19976]: info: Starting Streaming Daemon Mar 25 17:48:48 katarynka volumio[19976]: info: Removing browser output: myVolumio user plan is not superstar Mar 25 17:48:48 katarynka volumio[19976]: info: Removing audio output: Mar 25 17:48:48 katarynka volumio[19976]: info: Stoppping Tunnel 1 Mar 25 17:48:48 katarynka sudo[20367]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Mar 25 17:48:48 katarynka sudo[20367]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 17:48:49 katarynka sudo[20369]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Mar 25 17:48:49 katarynka sudo[20369]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 17:48:49 katarynka sudo[20367]: pam_unix(sudo:session): session closed for user root Mar 25 17:48:49 katarynka volumio[19976]: error: Cannot start Volumio Streaming Daemon Mar 25 17:48:49 katarynka volumio[19976]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Mar 25 17:48:49 katarynka volumio[19976]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Mar 25 17:48:49 katarynka systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Mar 25 17:48:49 katarynka systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Mar 25 17:48:49 katarynka systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Mar 25 17:48:49 katarynka systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Mar 25 17:48:49 katarynka systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Mar 25 17:48:49 katarynka systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Mar 25 17:48:49 katarynka systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Mar 25 17:48:49 katarynka systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Mar 25 17:48:49 katarynka sudo[20369]: pam_unix(sudo:session): session closed for user root Mar 25 17:48:49 katarynka volumio[19976]: info: Remote SSH Stopped Mar 25 17:48:49 katarynka volumio[19976]: info: Setting Geolocation for MyVolumio to eu11 Mar 25 17:48:49 katarynka volumio[19976]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 17:48:49 katarynka volumio[19976]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 17:48:49 katarynka volumio[19976]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 17:48:49 katarynka volumio[19976]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Mar 25 17:48:50 katarynka volumio[19976]: info: Updating MyVolumio device info Mar 25 17:48:50 katarynka volumio[19976]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 17:48:50 katarynka volumio[19976]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 17:48:50 katarynka volumio[19976]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 17:48:50 katarynka volumio[19976]: info: Getting Spotify volume Mar 25 17:48:50 katarynka volumio[19976]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 25 17:48:50 katarynka volumio[19976]: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 25 17:48:50 katarynka volumio[19976]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Mar 25 17:48:50 katarynka volumio[19976]: errno: -111, Mar 25 17:48:50 katarynka volumio[19976]: code: 'ECONNREFUSED', Mar 25 17:48:50 katarynka volumio[19976]: syscall: 'connect', Mar 25 17:48:50 katarynka volumio[19976]: address: '127.0.0.1', Mar 25 17:48:50 katarynka volumio[19976]: port: 9879, Mar 25 17:48:50 katarynka volumio[19976]: response: undefined Mar 25 17:48:50 katarynka volumio[19976]: } Mar 25 17:48:50 katarynka volumio[19976]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 25 17:48:50 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Mar 25 17:48:50 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 17:48:50 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 17:48:50 katarynka go-librespot[20399]: go-librespot daemon starting... Mar 25 17:48:50 katarynka go-librespot[20400]: time="2026-03-25T17:48:50+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 17:48:50 katarynka go-librespot[20400]: time="2026-03-25T17:48:50+01:00" level=debug msg="app state loaded" Mar 25 17:48:50 katarynka go-librespot[20400]: time="2026-03-25T17:48:50+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 17:48:51 katarynka go-librespot[20400]: time="2026-03-25T17:48: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 17:48:51 katarynka go-librespot[20400]: time="2026-03-25T17:48: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 17:48:51 katarynka go-librespot[20400]: time="2026-03-25T17:48: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 17:48:51 katarynka go-librespot[20400]: time="2026-03-25T17:48:51+01:00" level=info msg="zeroconf server listening on port 33493" Mar 25 17:48:51 katarynka go-librespot[20400]: time="2026-03-25T17:48:51+01:00" level=debug msg="obtained new client token: AAC+//Uz9HY2MmBKLwMuUqeoNka6XYxx75p+cA8NgejPmIxDDjJHiT5z1SmMNTp+NyhtfjRQqbzBW7lVVPn+rNNUzIr1geYjk3grjc8+eSOlm1WXyTTtSQwV1UADHBoGXSslonG58ZuSmMiEt25/CK//gBMzdcX1D2Je1uhHBFaPhccflbIiliUgY1yTAxFBAy1XHfXeOJTvViAQdzQKFEPdAjnLK5snXpZWKQBDcSiG13C+nNpmC3cAHXo=" Mar 25 17:48:51 katarynka go-librespot[20400]: time="2026-03-25T17:48:51+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 17:48:51 katarynka go-librespot[20400]: time="2026-03-25T17:48:51+01:00" level=debug msg="connected to ap-gew4.spotify.com:443" Mar 25 17:48:51 katarynka go-librespot[20400]: time="2026-03-25T17:48:51+01:00" level=debug msg="completed keyexchange" Mar 25 17:48:51 katarynka go-librespot[20400]: time="2026-03-25T17:48:51+01:00" level=debug msg="completed challenge" Mar 25 17:48:51 katarynka go-librespot[20400]: time="2026-03-25T17:48: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 17:48:51 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 17:48:51 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 17:48:51 katarynka sudo[20409]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-03-25 17:47' Mar 25 17:48:51 katarynka sudo[20409]: 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"