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) 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"