Mar 24 03:58:00 katarynka systemd[1]: setdatetime-helper.service: Deactivated successfully. Mar 24 03:58:00 katarynka systemd[1]: Finished setdatetime-helper.service - Time Synchronization Helper Service. Mar 24 03:58:00 katarynka systemd[1]: setdatetime-helper.service: Consumed 2.163s CPU time. Mar 24 03:58:01 katarynka volumio[17347]: info: go-librespot daemon successfully initialized Mar 24 03:58:01 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Mar 24 03:58:01 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 24 03:58:01 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 24 03:58:01 katarynka go-librespot[17672]: go-librespot daemon starting... Mar 24 03:58:01 katarynka go-librespot[17673]: time="2026-03-24T03:58:01+01:00" level=info msg="running go-librespot 0.4.0" Mar 24 03:58:01 katarynka go-librespot[17673]: time="2026-03-24T03:58:01+01:00" level=debug msg="app state loaded" Mar 24 03:58:01 katarynka go-librespot[17673]: time="2026-03-24T03:58:01+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 24 03:58:01 katarynka go-librespot[17673]: time="2026-03-24T03:58:01+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 24 03:58:01 katarynka go-librespot[17673]: time="2026-03-24T03:58:01+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 24 03:58:01 katarynka go-librespot[17673]: time="2026-03-24T03:58:01+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 24 03:58:01 katarynka go-librespot[17673]: time="2026-03-24T03:58:01+01:00" level=info msg="zeroconf server listening on port 43369" Mar 24 03:58:01 katarynka go-librespot[17673]: time="2026-03-24T03:58:01+01:00" level=debug msg="obtained new client token: AAAwypwyxq3zO1M+A6z4w/aNdiXjisbVaiCuIfFRKbZpD4851tCMioXJpYVJZNflRw3jd8I994d+CNp6h5XdEoUDYvNFNJJRJddzOVEVbckvQPc6A7uV3P4GfEatVilTdvFTeB+vMYfpkPLgki8FLEgJY00ebCuTl36Ir8X7OVATPmRHvxHXe7Pj/81QPD7ZTRhYHd0/uTMPONgzgjnfe+hRmkhacR6VrOz6KrpAfxWLMxyI1SNy11iTj68=" Mar 24 03:58:01 katarynka go-librespot[17673]: time="2026-03-24T03:58:01+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 24 03:58:01 katarynka go-librespot[17673]: time="2026-03-24T03:58:01+01:00" level=debug msg="completed keyexchange" Mar 24 03:58:01 katarynka go-librespot[17673]: time="2026-03-24T03:58:01+01:00" level=debug msg="completed challenge" Mar 24 03:58:02 katarynka go-librespot[17673]: time="2026-03-24T03:58:02+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 24 03:58:02 katarynka mpd[17544]: 2026-03-24T03:58:02 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Mar 24 03:58:02 katarynka systemd[1]: Started mpd.service - Music Player Daemon. Mar 24 03:58:02 katarynka sudo[17503]: pam_unix(sudo:session): session closed for user root Mar 24 03:58:02 katarynka sudo[17514]: pam_unix(sudo:session): session closed for user root Mar 24 03:58:02 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 24 03:58:02 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 24 03:58:02 katarynka volumio[17347]: info: Completed starting Core Plugins Mar 24 03:58:02 katarynka volumio[17347]: info: ------------------------------------------- Mar 24 03:58:02 katarynka volumio[17347]: info: ----- MyVolumio plugins startup ---- Mar 24 03:58:02 katarynka volumio[17347]: info: ------------------------------------------- Mar 24 03:58:02 katarynka volumio[17347]: info: [MyVolumio PluginManager] Fetching plans data.... Mar 24 03:58:02 katarynka volumio[17347]: error: MPD error: The expression evaluated to a falsy value: Mar 24 03:58:02 katarynka volumio[17347]: assert.ok(self.idling) Mar 24 03:58:02 katarynka volumio[17347]: error: The expression evaluated to a falsy value: Mar 24 03:58:02 katarynka volumio[17347]: assert.ok(self.idling) Mar 24 03:58:02 katarynka volumio[17347]: error: updateQueue error: null Mar 24 03:58:02 katarynka volumio[17347]: info: MPD running with PID17544 Mar 24 03:58:02 katarynka volumio[17347]: ,establishing connection Mar 24 03:58:02 katarynka volumio[17347]: error: updateQueue error: null Mar 24 03:58:04 katarynka volumio[17347]: info: Initializing connection to go-librespot Websocket Mar 24 03:58:04 katarynka volumio[17347]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 24 03:58:05 katarynka sudo[17703]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Mar 24 03:58:05 katarynka sudo[17703]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 03:58:05 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Mar 24 03:58:05 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 24 03:58:05 katarynka sudo[17705]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Mar 24 03:58:05 katarynka sudo[17705]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 03:58:05 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 24 03:58:05 katarynka go-librespot[17707]: go-librespot daemon starting... Mar 24 03:58:05 katarynka go-librespot[17709]: time="2026-03-24T03:58:05+01:00" level=info msg="running go-librespot 0.4.0" Mar 24 03:58:05 katarynka go-librespot[17709]: time="2026-03-24T03:58:05+01:00" level=debug msg="app state loaded" Mar 24 03:58:05 katarynka go-librespot[17709]: time="2026-03-24T03:58:05+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 24 03:58:05 katarynka systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Mar 24 03:58:05 katarynka systemd[1]: mpd_monitor.service: Deactivated successfully. Mar 24 03:58:05 katarynka systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Mar 24 03:58:05 katarynka systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Mar 24 03:58:05 katarynka sudo[17705]: pam_unix(sudo:session): session closed for user root Mar 24 03:58:05 katarynka sudo[17703]: pam_unix(sudo:session): session closed for user root Mar 24 03:58:05 katarynka mpd_monitor.sh[17715]: MPD Monitor Service: Starting MPD Monitor Service Mar 24 03:58:05 katarynka volumio[17347]: info: Successfully started MPD Monitor Mar 24 03:58:05 katarynka volumio[17347]: info: Successfully started MPD Monitor Mar 24 03:58:05 katarynka go-librespot[17709]: time="2026-03-24T03:58:05+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 24 03:58:05 katarynka go-librespot[17709]: time="2026-03-24T03:58:05+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 24 03:58:05 katarynka go-librespot[17709]: time="2026-03-24T03:58:05+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 24 03:58:05 katarynka go-librespot[17709]: time="2026-03-24T03:58:05+01:00" level=info msg="zeroconf server listening on port 44463" Mar 24 03:58:05 katarynka go-librespot[17709]: time="2026-03-24T03:58:05+01:00" level=debug msg="obtained new client token: AADHjHZgNwvcZfsAIEDeNHE8qNlktC1r6kIfRP38BXTMmiQ/iYzHDHqrvlZt9v+p6bfJFLLacs5VvovqZQ7yuQoJgEQpaZVlLSRLlS9Y6HvH+RM7cltw9DFiGV92Mu90QTzfoOdiFJxeWBKYdm0MeV/PNfK2jYK6PnFPF3NTjJITAPZRfJLSQVyZmd4uJT8Z7a2StqkoU4f9LMfOwBVOXufkv2Lvp4X+QWzqawsrUFjVQ4K2WcDVGHQRRZI=" Mar 24 03:58:05 katarynka go-librespot[17709]: time="2026-03-24T03:58:05+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 24 03:58:05 katarynka go-librespot[17709]: time="2026-03-24T03:58:05+01:00" level=debug msg="completed keyexchange" Mar 24 03:58:05 katarynka go-librespot[17709]: time="2026-03-24T03:58:05+01:00" level=debug msg="completed challenge" Mar 24 03:58:06 katarynka go-librespot[17709]: time="2026-03-24T03:58:06+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 24 03:58:06 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 24 03:58:06 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 24 03:58:07 katarynka volumio[17347]: info: Initializing connection to go-librespot Websocket Mar 24 03:58:07 katarynka volumio[17347]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 24 03:58:07 katarynka volumio[17347]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Mar 24 03:58:09 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Mar 24 03:58:09 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 24 03:58:09 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 24 03:58:09 katarynka go-librespot[17720]: go-librespot daemon starting... Mar 24 03:58:09 katarynka go-librespot[17721]: time="2026-03-24T03:58:09+01:00" level=info msg="running go-librespot 0.4.0" Mar 24 03:58:09 katarynka go-librespot[17721]: time="2026-03-24T03:58:09+01:00" level=debug msg="app state loaded" Mar 24 03:58:09 katarynka go-librespot[17721]: time="2026-03-24T03:58:09+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 24 03:58:09 katarynka go-librespot[17721]: time="2026-03-24T03:58:09+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 24 03:58:09 katarynka go-librespot[17721]: time="2026-03-24T03:58:09+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 24 03:58:09 katarynka go-librespot[17721]: time="2026-03-24T03:58:09+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 24 03:58:09 katarynka go-librespot[17721]: time="2026-03-24T03:58:09+01:00" level=info msg="zeroconf server listening on port 45651" Mar 24 03:58:09 katarynka go-librespot[17721]: time="2026-03-24T03:58:09+01:00" level=debug msg="obtained new client token: AAAr3lr+6GQAJ6YA8FYv9rX1srJxZ6TS2fBNtYbfSTRp9SZmrc5Dgl+kYWaHitANPGpaUFZNxxcjf90R4t10rC4hczvjWDYIrqR0HJvh1aFnZ3KY+RJHrHsV5IgS4tBWjoYjEA0NqM8uTG5EZR6hqqY7s+HIhA1vTiXKgRHmf2nx0l+zKPMwQ28tEOuRCsm+G2+pb0uW4bkBvN86AgFQa/pz8P3g38uNzBaOY90ItakXkfR6TvVaXJTc/XI=" Mar 24 03:58:09 katarynka go-librespot[17721]: time="2026-03-24T03:58:09+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 24 03:58:09 katarynka go-librespot[17721]: time="2026-03-24T03:58:09+01:00" level=debug msg="completed keyexchange" Mar 24 03:58:09 katarynka go-librespot[17721]: time="2026-03-24T03:58:09+01:00" level=debug msg="completed challenge" Mar 24 03:58:09 katarynka go-librespot[17721]: time="2026-03-24T03:58:09+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 24 03:58:10 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 24 03:58:10 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 24 03:58:10 katarynka volumio[17347]: info: Initializing connection to go-librespot Websocket Mar 24 03:58:10 katarynka volumio[17347]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 24 03:58:10 katarynka volumio[17347]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Mar 24 03:58:10 katarynka volumio[17347]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Mar 24 03:58:10 katarynka volumio[17347]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Mar 24 03:58:10 katarynka volumio[17347]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Mar 24 03:58:10 katarynka volumio[17347]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Mar 24 03:58:10 katarynka volumio[17347]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Mar 24 03:58:10 katarynka volumio[17347]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Mar 24 03:58:10 katarynka volumio[17347]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Mar 24 03:58:10 katarynka volumio[17347]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Mar 24 03:58:10 katarynka volumio[17347]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Mar 24 03:58:10 katarynka volumio[17347]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Mar 24 03:58:10 katarynka volumio[17347]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Mar 24 03:58:10 katarynka volumio[17347]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Mar 24 03:58:10 katarynka volumio[17347]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Mar 24 03:58:10 katarynka volumio[17347]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Mar 24 03:58:10 katarynka volumio[17347]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Mar 24 03:58:10 katarynka volumio[17347]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Mar 24 03:58:10 katarynka volumio[17347]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Mar 24 03:58:10 katarynka volumio[17347]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Mar 24 03:58:10 katarynka volumio[17347]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Mar 24 03:58:10 katarynka volumio[17347]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Mar 24 03:58:10 katarynka volumio[17347]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Mar 24 03:58:10 katarynka volumio[17347]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Mar 24 03:58:10 katarynka volumio[17347]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Mar 24 03:58:10 katarynka volumio[17347]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Mar 24 03:58:10 katarynka volumio[17347]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Mar 24 03:58:10 katarynka volumio[17347]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Mar 24 03:58:10 katarynka volumio[17347]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Mar 24 03:58:10 katarynka volumio[17347]: info: Adding plugin bluetooth to MyMusic Plugins Mar 24 03:58:10 katarynka volumio[17347]: info: Adding plugin multiroom to MyMusic Plugins Mar 24 03:58:10 katarynka volumio[17347]: info: Adding plugin metavolumio to MyMusic Plugins Mar 24 03:58:10 katarynka volumio[17347]: info: Adding plugin cd_controller to MyMusic Plugins Mar 24 03:58:10 katarynka volumio[17347]: info: Adding plugin qobuzconnect to MyMusic Plugins Mar 24 03:58:10 katarynka volumio[17347]: info: Adding plugin smart_inputs to MyMusic Plugins Mar 24 03:58:10 katarynka volumio[17347]: info: Adding plugin tidalconnect to MyMusic Plugins Mar 24 03:58:10 katarynka volumio[17347]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Mar 24 03:58:12 katarynka volumio[17347]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Mar 24 03:58:12 katarynka volumio[17347]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Mar 24 03:58:12 katarynka volumio[17347]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 24 03:58:12 katarynka volumio[17347]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 24 03:58:12 katarynka volumio[17347]: info: Starting MyVolumio Remote Streaming Endpoints Mar 24 03:58:12 katarynka volumio[17347]: info: MyVolumio login type: Token Mar 24 03:58:12 katarynka volumio[17347]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Mar 24 03:58:12 katarynka volumio[17347]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Mar 24 03:58:13 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Mar 24 03:58:13 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 24 03:58:13 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 24 03:58:13 katarynka go-librespot[17729]: go-librespot daemon starting... Mar 24 03:58:13 katarynka go-librespot[17730]: time="2026-03-24T03:58:13+01:00" level=info msg="running go-librespot 0.4.0" Mar 24 03:58:13 katarynka go-librespot[17730]: time="2026-03-24T03:58:13+01:00" level=debug msg="app state loaded" Mar 24 03:58:13 katarynka go-librespot[17730]: time="2026-03-24T03:58:13+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 24 03:58:13 katarynka go-librespot[17730]: time="2026-03-24T03:58:13+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 24 03:58:13 katarynka go-librespot[17730]: time="2026-03-24T03:58:13+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 24 03:58:13 katarynka go-librespot[17730]: time="2026-03-24T03:58:13+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 24 03:58:13 katarynka go-librespot[17730]: time="2026-03-24T03:58:13+01:00" level=info msg="zeroconf server listening on port 40525" Mar 24 03:58:13 katarynka go-librespot[17730]: time="2026-03-24T03:58:13+01:00" level=debug msg="obtained new client token: AACDS72KqICNedaOIzr/NLFjCWPRjYBW1X6ohBlnzsarMqXWPugSSqly8MA8PxpSJzOsHAAM6vQriik5TUVn0Tyns5IOD2PSYg+HMpDFx1r1Cx17GhjA2X40mvNXx/tlfGE2gcynAf1QxiJ3MITsnthkoJG996UnN5b7ZpsGsqWRUrcGfidCe4oaJCcMRi+ffaywbEIRfvOdC1kIpEyGUGmtRsNXwr+FzW2KNJSPps+DtEs+BAFaWHmC48M=" Mar 24 03:58:13 katarynka go-librespot[17730]: time="2026-03-24T03:58:13+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 24 03:58:14 katarynka go-librespot[17730]: time="2026-03-24T03:58:14+01:00" level=debug msg="completed keyexchange" Mar 24 03:58:14 katarynka go-librespot[17730]: time="2026-03-24T03:58:14+01:00" level=debug msg="completed challenge" Mar 24 03:58:14 katarynka go-librespot[17730]: time="2026-03-24T03:58:14+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 24 03:58:14 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 24 03:58:14 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 24 03:58:14 katarynka volumio[17347]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Mar 24 03:58:14 katarynka volumio[17347]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Mar 24 03:58:14 katarynka volumio[17347]: info: Streaming services startup Mar 24 03:58:14 katarynka volumio[17347]: info: Starting Streaming Daemon Mar 24 03:58:14 katarynka sudo[17738]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Mar 24 03:58:14 katarynka sudo[17738]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 03:58:14 katarynka volumio[17347]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Mar 24 03:58:14 katarynka sudo[17738]: pam_unix(sudo:session): session closed for user root Mar 24 03:58:14 katarynka volumio[17347]: info: Initializing connection to go-librespot Websocket Mar 24 03:58:14 katarynka volumio[17347]: error: Cannot start Volumio Streaming Daemon Mar 24 03:58:14 katarynka volumio[17347]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Mar 24 03:58:14 katarynka volumio[17347]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Mar 24 03:58:14 katarynka volumio[17347]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 24 03:58:15 katarynka volumio[17347]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Mar 24 03:58:15 katarynka volumio[17347]: info: MyVolumio token set successfully Mar 24 03:58:15 katarynka volumio[17347]: info: MYVOLUMIO: Adding device Mar 24 03:58:15 katarynka volumio[17347]: info: MYVOLUMIO: Evaluating Server Mar 24 03:58:16 katarynka volumio[17347]: info: MyVolumio status changed Mar 24 03:58:16 katarynka volumio[17347]: info: Streaming services startup Mar 24 03:58:16 katarynka volumio[17347]: info: Starting Streaming Daemon Mar 24 03:58:16 katarynka volumio[17347]: info: Removing browser output: myVolumio user plan is not superstar Mar 24 03:58:16 katarynka volumio[17347]: info: Removing audio output: Mar 24 03:58:16 katarynka volumio[17347]: info: Stoppping Tunnel 1 Mar 24 03:58:16 katarynka sudo[17780]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Mar 24 03:58:16 katarynka sudo[17780]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 03:58:16 katarynka sudo[17782]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Mar 24 03:58:16 katarynka sudo[17782]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 03:58:16 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 24 03:58:16 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 24 03:58:16 katarynka sudo[17780]: pam_unix(sudo:session): session closed for user root Mar 24 03:58:16 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 24 03:58:16 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 24 03:58:16 katarynka volumio[17347]: error: Cannot start Volumio Streaming Daemon Mar 24 03:58:16 katarynka volumio[17347]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Mar 24 03:58:16 katarynka volumio[17347]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Mar 24 03:58:16 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 24 03:58:16 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 24 03:58:16 katarynka sudo[17782]: pam_unix(sudo:session): session closed for user root Mar 24 03:58:16 katarynka volumio[17347]: info: Remote SSH Stopped Mar 24 03:58:16 katarynka volumio[17347]: info: Setting Geolocation for MyVolumio to eu7 Mar 24 03:58:16 katarynka volumio[17347]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 24 03:58:16 katarynka volumio[17347]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 24 03:58:16 katarynka volumio[17347]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 24 03:58:16 katarynka volumio[17347]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Mar 24 03:58:17 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Mar 24 03:58:17 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 24 03:58:17 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 24 03:58:17 katarynka go-librespot[17785]: go-librespot daemon starting... Mar 24 03:58:17 katarynka go-librespot[17786]: time="2026-03-24T03:58:17+01:00" level=info msg="running go-librespot 0.4.0" Mar 24 03:58:17 katarynka go-librespot[17786]: time="2026-03-24T03:58:17+01:00" level=debug msg="app state loaded" Mar 24 03:58:17 katarynka go-librespot[17786]: time="2026-03-24T03:58:17+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 24 03:58:17 katarynka go-librespot[17786]: time="2026-03-24T03:58:17+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 24 03:58:17 katarynka go-librespot[17786]: time="2026-03-24T03:58:17+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 24 03:58:17 katarynka go-librespot[17786]: time="2026-03-24T03:58:17+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 24 03:58:17 katarynka volumio[17347]: info: Initializing connection to go-librespot Websocket Mar 24 03:58:17 katarynka go-librespot[17786]: time="2026-03-24T03:58:17+01:00" level=debug msg="new websocket client" Mar 24 03:58:17 katarynka go-librespot[17786]: time="2026-03-24T03:58:17+01:00" level=info msg="zeroconf server listening on port 41079" Mar 24 03:58:17 katarynka volumio[17347]: info: Connection to go-librespot Websocket established Mar 24 03:58:17 katarynka volumio[17347]: info: Updating MyVolumio device info Mar 24 03:58:17 katarynka volumio[17347]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 24 03:58:17 katarynka volumio[17347]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 24 03:58:17 katarynka volumio[17347]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 24 03:58:17 katarynka go-librespot[17786]: time="2026-03-24T03:58:17+01:00" level=debug msg="obtained new client token: AAALTXfXiXB3UtMosJ6ibUrdbGwTyZRWtfK/jmRghUqV9rjakCAry/eW+QyruLJcL27AtJIlI+JEqdXfcXR8ZpVwcsB1eBJIy11UcWn/3DE40bhMjP7xAZBodMbU1HITn92Jdf4hhS7RQjxCtVsuCTBGPv6VopyaClbzrI7PQ03VbRU6pgDqaiPARrvHg5S08LBbEiqILnPBxli90IJQ7ZvJcqMXeGZ0/Yl49S63i9dvyDSjH8bX10hO2b8=" Mar 24 03:58:17 katarynka go-librespot[17786]: time="2026-03-24T03:58:17+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 24 03:58:17 katarynka go-librespot[17786]: time="2026-03-24T03:58:17+01:00" level=debug msg="completed keyexchange" Mar 24 03:58:17 katarynka go-librespot[17786]: time="2026-03-24T03:58:17+01:00" level=debug msg="completed challenge" Mar 24 03:58:17 katarynka volumio[17347]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Mar 24 03:58:17 katarynka go-librespot[17786]: time="2026-03-24T03:58:17+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 24 03:58:17 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 24 03:58:18 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 24 03:58:18 katarynka volumio[17347]: info: Connection to go-librespot Websocket closed Mar 24 03:58:20 katarynka volumio[17347]: info: Getting Spotify volume Mar 24 03:58:20 katarynka volumio[17347]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 24 03:58:20 katarynka volumio[17347]: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 24 03:58:20 katarynka volumio[17347]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Mar 24 03:58:20 katarynka volumio[17347]: errno: -111, Mar 24 03:58:20 katarynka volumio[17347]: code: 'ECONNREFUSED', Mar 24 03:58:20 katarynka volumio[17347]: syscall: 'connect', Mar 24 03:58:20 katarynka volumio[17347]: address: '127.0.0.1', Mar 24 03:58:20 katarynka volumio[17347]: port: 9879, Mar 24 03:58:20 katarynka volumio[17347]: response: undefined Mar 24 03:58:20 katarynka volumio[17347]: } Mar 24 03:58:20 katarynka volumio[17347]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 24 03:58:21 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Mar 24 03:58:21 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 24 03:58:21 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 24 03:58:21 katarynka go-librespot[17806]: go-librespot daemon starting... Mar 24 03:58:21 katarynka go-librespot[17807]: time="2026-03-24T03:58:21+01:00" level=info msg="running go-librespot 0.4.0" Mar 24 03:58:21 katarynka go-librespot[17807]: time="2026-03-24T03:58:21+01:00" level=debug msg="app state loaded" Mar 24 03:58:21 katarynka go-librespot[17807]: time="2026-03-24T03:58:21+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 24 03:58:21 katarynka go-librespot[17807]: time="2026-03-24T03:58:21+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 24 03:58:21 katarynka go-librespot[17807]: time="2026-03-24T03:58:21+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 24 03:58:21 katarynka go-librespot[17807]: time="2026-03-24T03:58:21+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 24 03:58:21 katarynka go-librespot[17807]: time="2026-03-24T03:58:21+01:00" level=info msg="zeroconf server listening on port 33245" Mar 24 03:58:21 katarynka go-librespot[17807]: time="2026-03-24T03:58:21+01:00" level=debug msg="obtained new client token: AAARFy0PFsCsRGS8vHnJICWMgrvqOC09BV0fSvNUAYgC59eY1CfkqXA5TV2QGCYaiuB/4mTyYXqD5PY6z1cyz3ubgAGQjySpdSje63PfRAMIbu7Do4Qhjvu4mzQ9nxIqmXGbhqCsPn4j3ecX4fazyxWUw38ZILYi+tjw03f4mvocgb4M3paTCdhIWfIU1ILczJMkPSfNMph255OvDJ+3NGZEsRtSaYchen7wG5JLuJLE6kWNNg5YijgtKzU=" Mar 24 03:58:21 katarynka go-librespot[17807]: time="2026-03-24T03:58:21+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 24 03:58:22 katarynka go-librespot[17807]: time="2026-03-24T03:58:22+01:00" level=debug msg="completed keyexchange" Mar 24 03:58:22 katarynka go-librespot[17807]: time="2026-03-24T03:58:22+01:00" level=debug msg="completed challenge" Mar 24 03:58:22 katarynka go-librespot[17807]: time="2026-03-24T03:58:22+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 24 03:58:22 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 24 03:58:22 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 24 03:58:22 katarynka sudo[17816]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-03-24 03:57' Mar 24 03:58:22 katarynka sudo[17816]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 03:58:22 katarynka sudo[17816]: pam_unix(sudo:session): session closed for user root Mar 24 03:58:22 katarynka volumio-remote-updater[622]: [2026-03-24 03:58:22] [error] handle_read_frame error: asio.system:104 (Connection reset by peer) Mar 24 03:58:22 katarynka volumio-remote-updater[622]: [2026-03-24 03:58:22] [disconnect] Disconnect close local:[1006,Connection reset by peer] remote:[1006] Mar 24 03:58:22 katarynka systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Mar 24 03:58:22 katarynka systemd[1]: volumio.service: Failed with result 'exit-code'. Mar 24 03:58:22 katarynka systemd[1]: volumio.service: Consumed 50.746s CPU time. Mar 24 03:58:22 katarynka systemd[1]: Started dynamicswap.service - dynamicswap service. Mar 24 03:58:22 katarynka systemd[1]: dynamicswap.service: Deactivated successfully. Mar 24 03:58:22 katarynka systemd[1]: volumio.service: Scheduled restart job, restart counter is at 24361. Mar 24 03:58:23 katarynka systemd[1]: Started dynamicswap.service - dynamicswap service. Mar 24 03:58:23 katarynka systemd[1]: Stopped volumio.service - Volumio Backend Module. Mar 24 03:58:23 katarynka systemd[1]: volumio.service: Consumed 50.746s CPU time. Mar 24 03:58:23 katarynka systemd[1]: Started volumio.service - Volumio Backend Module. Mar 24 03:58:23 katarynka systemd[1]: dynamicswap.service: Deactivated successfully. Mar 24 03:58:25 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Mar 24 03:58:25 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 24 03:58:25 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 24 03:58:25 katarynka go-librespot[17844]: go-librespot daemon starting... Mar 24 03:58:25 katarynka go-librespot[17845]: time="2026-03-24T03:58:25+01:00" level=info msg="running go-librespot 0.4.0" Mar 24 03:58:25 katarynka go-librespot[17845]: time="2026-03-24T03:58:25+01:00" level=debug msg="app state loaded" Mar 24 03:58:25 katarynka go-librespot[17845]: time="2026-03-24T03:58:25+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 24 03:58:25 katarynka go-librespot[17845]: time="2026-03-24T03:58:25+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Mar 24 03:58:25 katarynka go-librespot[17845]: time="2026-03-24T03:58:25+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 24 03:58:25 katarynka go-librespot[17845]: time="2026-03-24T03:58:25+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 24 03:58:25 katarynka go-librespot[17845]: time="2026-03-24T03:58:25+01:00" level=info msg="zeroconf server listening on port 35207" Mar 24 03:58:25 katarynka go-librespot[17845]: time="2026-03-24T03:58:25+01:00" level=debug msg="obtained new client token: AABXboZsPhs3dYG0UZBmHOC5dc5nHTs5ysgpoiqys+zw2AkmnGQsKBOGUNaZGBp4gE1EmKU66iMAILYX4lj43LnqRERyk2dSWxMYO8yJiP58/sGCUM6Z3N65NFgZ/4Sjnms7t1nm7Bh+MwrslRUV7nabcRzpdOheT6EJor1iByGbsg3lL8QWucyOHPsbJxFxGFHpUZEjVilEZ7HvvudbDcjUMhnSsMlw+t+KWpo28hTqHhj1SpzK6fT0Ujo=" Mar 24 03:58:25 katarynka go-librespot[17845]: time="2026-03-24T03:58:25+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 24 03:58:26 katarynka go-librespot[17845]: time="2026-03-24T03:58:26+01:00" level=debug msg="completed keyexchange" Mar 24 03:58:26 katarynka go-librespot[17845]: time="2026-03-24T03:58:26+01:00" level=debug msg="completed challenge" Mar 24 03:58:26 katarynka go-librespot[17845]: time="2026-03-24T03:58:26+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 24 03:58:26 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 24 03:58:26 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 24 03:58:26 katarynka volumio[17829]: info: ------------------------------------------- Mar 24 03:58:26 katarynka volumio[17829]: info: ----- Volumio3 ---- Mar 24 03:58:26 katarynka volumio[17829]: info: ------------------------------------------- Mar 24 03:58:26 katarynka volumio[17829]: info: ----- System startup ---- Mar 24 03:58:26 katarynka volumio[17829]: info: ------------------------------------------- Mar 24 03:58:27 katarynka volumio-remote-updater[622]: [2026-03-24 03:58:27] [connect] Successful connection Mar 24 03:58:28 katarynka volumio[17829]: info: MYVOLUMIO Environment detected Mar 24 03:58:28 katarynka volumio[17829]: info: Plugin folders cleanup Mar 24 03:58:28 katarynka volumio[17829]: info: Scanning into folder /volumio/app/plugins/ Mar 24 03:58:28 katarynka volumio[17829]: info: Scanning category audio_interface Mar 24 03:58:28 katarynka volumio[17829]: info: Scanning category miscellanea Mar 24 03:58:28 katarynka volumio[17829]: info: Scanning category music_service Mar 24 03:58:28 katarynka volumio[17829]: info: Scanning category plugins.json Mar 24 03:58:28 katarynka volumio[17829]: info: Scanning category system_controller Mar 24 03:58:28 katarynka volumio[17829]: info: Scanning category user_interface Mar 24 03:58:28 katarynka volumio[17829]: info: Scanning into folder /data/plugins/ Mar 24 03:58:28 katarynka volumio[17829]: info: Scanning category music_service Mar 24 03:58:28 katarynka volumio[17829]: info: Plugin folders cleanup completed Mar 24 03:58:28 katarynka volumio[17829]: info: ------------------------------------------- Mar 24 03:58:28 katarynka volumio[17829]: info: ----- Core plugins startup ---- Mar 24 03:58:28 katarynka volumio[17829]: info: ------------------------------------------- Mar 24 03:58:28 katarynka volumio[17829]: info: Loading plugins from folder /volumio/app/plugins/ Mar 24 03:58:28 katarynka volumio[17829]: info: Adding plugin upnp to MyMusic Plugins Mar 24 03:58:28 katarynka volumio[17829]: info: Adding plugin airplay_emulation to MyMusic Plugins Mar 24 03:58:28 katarynka volumio[17829]: info: Adding plugin upnp_browser to MyMusic Plugins Mar 24 03:58:28 katarynka volumio[17829]: info: Loading plugins from folder /data/plugins/ Mar 24 03:58:28 katarynka volumio[17829]: info: Loading plugin "system"... Mar 24 03:58:28 katarynka volumio[17829]: info: Loading plugin "appearance"... Mar 24 03:58:29 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Mar 24 03:58:29 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 24 03:58:29 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 24 03:58:29 katarynka go-librespot[17867]: go-librespot daemon starting... Mar 24 03:58:29 katarynka go-librespot[17868]: time="2026-03-24T03:58:29+01:00" level=info msg="running go-librespot 0.4.0" Mar 24 03:58:29 katarynka go-librespot[17868]: time="2026-03-24T03:58:29+01:00" level=debug msg="app state loaded" Mar 24 03:58:29 katarynka go-librespot[17868]: time="2026-03-24T03:58:29+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 24 03:58:29 katarynka go-librespot[17868]: time="2026-03-24T03:58:29+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 24 03:58:29 katarynka go-librespot[17868]: time="2026-03-24T03:58:29+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 24 03:58:29 katarynka go-librespot[17868]: time="2026-03-24T03:58:29+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 24 03:58:29 katarynka go-librespot[17868]: time="2026-03-24T03:58:29+01:00" level=info msg="zeroconf server listening on port 45707" Mar 24 03:58:29 katarynka go-librespot[17868]: time="2026-03-24T03:58:29+01:00" level=debug msg="obtained new client token: AACeIIFmUxgoJ6CXknkxhQwb/UXoEmCwmiXkYL+dvLhzarfO+l0A2ex+1PvvqZ/bNRHE4fG/ThWfJYpTBZwBoFUTDgp81XuNqoFIY6hyPM9FVEHF0zfJeyQkcvjpZGirO2cNgTs+8py+/XmgqufBoo5mXTaGd0f9hF8g5/OfHVUvCeRc4Y3BHUoJL35YZ51G7MU8HqjBFdwX114bsLjyWPIedDLWyXGnWgXNmsEYR0h+v7qZcRy5+gsv0wM=" Mar 24 03:58:29 katarynka go-librespot[17868]: time="2026-03-24T03:58:29+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 24 03:58:30 katarynka go-librespot[17868]: time="2026-03-24T03:58:30+01:00" level=debug msg="completed keyexchange" Mar 24 03:58:30 katarynka go-librespot[17868]: time="2026-03-24T03:58:30+01:00" level=debug msg="completed challenge" Mar 24 03:58:30 katarynka go-librespot[17868]: time="2026-03-24T03:58:30+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 24 03:58:30 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 24 03:58:30 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 24 03:58:30 katarynka volumio[17829]: info: Loading plugin "network"... Mar 24 03:58:30 katarynka volumio[17829]: info: Refreshing Cached IP Addresses Mar 24 03:58:30 katarynka sudo[17876]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 24 03:58:30 katarynka sudo[17876]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 03:58:30 katarynka sudo[17876]: pam_unix(sudo:session): session closed for user root Mar 24 03:58:30 katarynka sudo[17878]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 24 03:58:30 katarynka sudo[17878]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 03:58:30 katarynka volumio[17829]: info: Loading plugin "services"... Mar 24 03:58:30 katarynka volumio[17829]: info: Loading plugin "alsa_controller"... Mar 24 03:58:30 katarynka sudo[17878]: pam_unix(sudo:session): session closed for user root Mar 24 03:58:30 katarynka sudo[17886]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Mar 24 03:58:30 katarynka sudo[17886]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 03:58:30 katarynka volumio[17829]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 24 03:58:30 katarynka volumio[17829]: info: Loading plugin "wizard"... Mar 24 03:58:30 katarynka volumio[17829]: info: Loading plugin "networkfs"... Mar 24 03:58:30 katarynka volumio[17829]: info: Starting Udev Watcher for removable devices Mar 24 03:58:30 katarynka volumio[17829]: info: Ignoring mount for partition: boot Mar 24 03:58:30 katarynka volumio[17829]: info: Ignoring mount for partition: volumio Mar 24 03:58:30 katarynka volumio[17829]: info: Ignoring mount for partition: volumio_data Mar 24 03:58:30 katarynka volumio[17829]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 24 03:58:30 katarynka volumio[17829]: info: Loading plugin "volumio_command_line_client"... Mar 24 03:58:31 katarynka volumio[17829]: info: Loading plugin "upnp"... Mar 24 03:58:31 katarynka volumio[17829]: info: [1774321111024] Starting Upmpd Daemon Mar 24 03:58:31 katarynka volumio[17829]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 24 03:58:31 katarynka volumio[17829]: info: Loading plugin "my_music"... Mar 24 03:58:31 katarynka volumio[17829]: info: Loading plugin "mpd"... Mar 24 03:58:31 katarynka sudo[17886]: pam_unix(sudo:session): session closed for user root Mar 24 03:58:31 katarynka volumio[17829]: info: Loading plugin "upnp_browser"... Mar 24 03:58:33 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Mar 24 03:58:33 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 24 03:58:33 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 24 03:58:33 katarynka go-librespot[17909]: go-librespot daemon starting... Mar 24 03:58:33 katarynka go-librespot[17910]: time="2026-03-24T03:58:33+01:00" level=info msg="running go-librespot 0.4.0" Mar 24 03:58:33 katarynka go-librespot[17910]: time="2026-03-24T03:58:33+01:00" level=debug msg="app state loaded" Mar 24 03:58:33 katarynka go-librespot[17910]: time="2026-03-24T03:58:33+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 24 03:58:33 katarynka go-librespot[17910]: time="2026-03-24T03:58:33+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 24 03:58:33 katarynka go-librespot[17910]: time="2026-03-24T03:58:33+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 24 03:58:33 katarynka go-librespot[17910]: time="2026-03-24T03:58:33+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 24 03:58:33 katarynka go-librespot[17910]: time="2026-03-24T03:58:33+01:00" level=info msg="zeroconf server listening on port 32949" Mar 24 03:58:33 katarynka go-librespot[17910]: time="2026-03-24T03:58:33+01:00" level=debug msg="obtained new client token: AADS2uB2sAfkrjZSGJtbl0Kw7Hwwd4m0XfoEcwaJOEMRsPY2vDz3aPLydpFQyH8I8J1tXze0hRYtdpSYWNlVFuYLI1378RKREvHArR8CPM6OLqIz6TBWUDaExsn0KjWNyXLKheXmVrBgclgURZdnJhBOCehX608WacGaX14wuegpCWqw2RMvCzcxeoyzGco1a0/nCWj3KM3xkX7t2kX4a43yeDyMifaiRbnn7+3lS7FKTlwhGw55E4ZgWrg=" Mar 24 03:58:33 katarynka go-librespot[17910]: time="2026-03-24T03:58:33+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 24 03:58:34 katarynka go-librespot[17910]: time="2026-03-24T03:58:34+01:00" level=debug msg="completed keyexchange" Mar 24 03:58:34 katarynka go-librespot[17910]: time="2026-03-24T03:58:34+01:00" level=debug msg="completed challenge" Mar 24 03:58:34 katarynka go-librespot[17910]: time="2026-03-24T03:58:34+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 24 03:58:34 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 24 03:58:34 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 24 03:58:34 katarynka volumio[17829]: info: Starting UPNP Browser Mar 24 03:58:34 katarynka volumio[17829]: info: Loading plugin "alarm-clock"... Mar 24 03:58:35 katarynka volumio[17829]: info: Loading plugin "airplay_emulation"... Mar 24 03:58:35 katarynka volumio[17829]: info: Starting Shairport Sync Mar 24 03:58:35 katarynka volumio[17829]: info: Loading plugin "last_100"... Mar 24 03:58:35 katarynka volumio[17829]: info: Loading plugin "webradio"... Mar 24 03:58:35 katarynka volumio[17829]: info: Loading plugin "i2s_dacs"... Mar 24 03:58:35 katarynka volumio[17829]: info: Loading plugin "volumiodiscovery"... Mar 24 03:58:35 katarynka volumio[17829]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Mar 24 03:58:35 katarynka volumio[17829]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 24 03:58:35 katarynka volumio[17829]: *** WARNING *** For more information see Mar 24 03:58:35 katarynka volumio[17829]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Mar 24 03:58:35 katarynka volumio[17829]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 24 03:58:35 katarynka volumio[17829]: *** WARNING *** For more information see Mar 24 03:58:35 katarynka node[17829]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Mar 24 03:58:35 katarynka node[17829]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 24 03:58:35 katarynka node[17829]: *** WARNING *** For more information see Mar 24 03:58:35 katarynka node[17829]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Mar 24 03:58:35 katarynka node[17829]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 24 03:58:35 katarynka node[17829]: *** WARNING *** For more information see Mar 24 03:58:35 katarynka volumio[17829]: info: Applying required configuration parameters for plugin volumiodiscovery Mar 24 03:58:35 katarynka volumio[17829]: info: Discovery: Started advertising with name: katarynka Mar 24 03:58:35 katarynka volumio[17829]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 24 03:58:35 katarynka volumio[17829]: info: Loading plugin "spop"... Mar 24 03:58:37 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Mar 24 03:58:37 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 24 03:58:37 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 24 03:58:37 katarynka go-librespot[17919]: go-librespot daemon starting... Mar 24 03:58:37 katarynka go-librespot[17920]: time="2026-03-24T03:58:37+01:00" level=info msg="running go-librespot 0.4.0" Mar 24 03:58:37 katarynka go-librespot[17920]: time="2026-03-24T03:58:37+01:00" level=debug msg="app state loaded" Mar 24 03:58:37 katarynka go-librespot[17920]: time="2026-03-24T03:58:37+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 24 03:58:37 katarynka volumio[17829]: info: Loading plugin "outputs"... Mar 24 03:58:37 katarynka volumio[17829]: info: Loading plugin "albumart"... Mar 24 03:58:37 katarynka volumio[17829]: info: Plugin example_plugin is not enabled Mar 24 03:58:37 katarynka volumio[17829]: info: Loading plugin "inputs"... Mar 24 03:58:37 katarynka volumio[17829]: info: Loading plugin "updater_comm"... Mar 24 03:58:37 katarynka go-librespot[17920]: time="2026-03-24T03:58:37+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 24 03:58:37 katarynka go-librespot[17920]: time="2026-03-24T03:58:37+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 24 03:58:37 katarynka go-librespot[17920]: time="2026-03-24T03:58:37+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 24 03:58:37 katarynka go-librespot[17920]: time="2026-03-24T03:58:37+01:00" level=info msg="zeroconf server listening on port 42237" Mar 24 03:58:37 katarynka volumio[17829]: info: Plugin mpdemulation is not enabled Mar 24 03:58:37 katarynka volumio[17829]: info: Loading plugin "rest_api"... Mar 24 03:58:37 katarynka volumio[17829]: info: Loading plugin "websocket"... Mar 24 03:58:37 katarynka volumio[17829]: info: Starting Socket.io Server version 1.7.4 Mar 24 03:58:37 katarynka volumio[17829]: info: Loading i18n strings for locale pl Mar 24 03:58:37 katarynka go-librespot[17920]: time="2026-03-24T03:58:37+01:00" level=debug msg="obtained new client token: AAABN6AYD/dpVDyF/ZQtzQ7sFfaEKOtQYX2Ol8fHdwgv4hMK+ojDyb1710Ivhv2DmJLBP4fIHvfcLUJea+apEaC5/1s2ZFw68V4rI23HLNqzUMztcamCOUwLBOb8aCD94EToxR3ZWQhNNTVzKopxzTOa2D2jLEySgGwR2U/q6UaynSEvHJB/yvMMhllDC2OfYt6PXUqG5IOjRdMVbtsxQtnCZkGkYZPFUEJnS9ScIBHU0iq2Li0VFikdxXM=" Mar 24 03:58:38 katarynka volumio[17829]: Updating browse sources language Mar 24 03:58:38 katarynka volumio[17829]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 24 03:58:38 katarynka go-librespot[17920]: time="2026-03-24T03:58:38+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 24 03:58:38 katarynka go-librespot[17920]: time="2026-03-24T03:58:38+01:00" level=debug msg="completed keyexchange" Mar 24 03:58:38 katarynka go-librespot[17920]: time="2026-03-24T03:58:38+01:00" level=debug msg="completed challenge" Mar 24 03:58:38 katarynka go-librespot[17920]: time="2026-03-24T03:58:38+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 24 03:58:38 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 24 03:58:38 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 24 03:58:38 katarynka volumio[17829]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 24 03:58:38 katarynka volumio[17829]: info: CoreCommandRouter::initPlayerControls Mar 24 03:58:38 katarynka volumio[17829]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 03:58:38 katarynka volumio[17829]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 03:58:38 katarynka volumio[17829]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 03:58:38 katarynka volumio[17829]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 03:58:38 katarynka volumio[17829]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 03:58:38 katarynka volumio[17829]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 03:58:38 katarynka volumio[17829]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 03:58:38 katarynka volumio[17829]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 03:58:38 katarynka volumio[17829]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 24 03:58:38 katarynka volumio[17829]: Express server listening on port 3000 Mar 24 03:58:38 katarynka volumio[17829]: [Metrics] WebUI: 12s 521.59ms Mar 24 03:58:38 katarynka volumio[17829]: info: CoreStateMachine::resetVolumioState Mar 24 03:58:38 katarynka volumio[17829]: info: CoreStateMachine::getcurrentVolume Mar 24 03:58:38 katarynka volumio[17829]: info: CoreCommandRouter::volumioRetrievevolume Mar 24 03:58:38 katarynka volumio[17829]: info: Cannot read play queue from file Mar 24 03:58:38 katarynka volumio[17829]: info: Volumio Network Manager: Network status updated: 2 Mar 24 03:58:38 katarynka volumio[17927]: Forking 3 albumart workers Mar 24 03:58:38 katarynka volumio[17829]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 24 03:58:38 katarynka volumio[17829]: info: CoreStateMachine::setRepeat null single undefined Mar 24 03:58:38 katarynka volumio[17829]: info: CoreStateMachine::pushState Mar 24 03:58:38 katarynka volumio[17829]: info: CorePlayQueue::getTrack 0 Mar 24 03:58:38 katarynka volumio[17829]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 24 03:58:38 katarynka volumio[17829]: info: CoreCommandRouter::volumioPushState Mar 24 03:58:38 katarynka volumio[17829]: info: CoreStateMachine::setRandom null Mar 24 03:58:38 katarynka volumio[17829]: info: CoreStateMachine::pushState Mar 24 03:58:38 katarynka volumio[17829]: info: CorePlayQueue::getTrack 0 Mar 24 03:58:38 katarynka volumio[17829]: info: CoreCommandRouter::volumioPushState Mar 24 03:58:38 katarynka volumio[17829]: info: Setting Device type: Raspberry PI Mar 24 03:58:38 katarynka volumio[17829]: info: Completed loading Core Plugins Mar 24 03:58:38 katarynka volumio[17829]: info: Preparing to generate the ALSA configuration file Mar 24 03:58:38 katarynka volumio[17829]: info: VolumeController:: Volume=96 Mute =false Mar 24 03:58:38 katarynka volumio[17829]: info: CoreStateMachine::pushState Mar 24 03:58:38 katarynka volumio[17829]: info: CorePlayQueue::getTrack 0 Mar 24 03:58:38 katarynka volumio[17829]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 24 03:58:38 katarynka volumio[17829]: info: CoreCommandRouter::volumioPushState Mar 24 03:58:38 katarynka volumio[17829]: info: CoreStateMachine::updateTrackBlock Mar 24 03:58:38 katarynka volumio[17829]: info: CorePlayQueue::getTrackBlock Mar 24 03:58:38 katarynka volumio[17829]: info: CoreCommandRouter::volumioRetrievevolume Mar 24 03:58:39 katarynka volumio[17829]: info: Asound.conf file unchanged, so no further update is needed Mar 24 03:58:39 katarynka volumio[17829]: info: Output device has changed, restarting MPD Mar 24 03:58:39 katarynka volumio[17829]: info: Output device has changed, restarting Shairport Sync Mar 24 03:58:39 katarynka volumio[17829]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 03:58:39 katarynka volumio[17829]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 24 03:58:39 katarynka sudo[17982]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 24 03:58:39 katarynka sudo[17982]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 03:58:39 katarynka sudo[17982]: pam_unix(sudo:session): session closed for user root Mar 24 03:58:39 katarynka sudo[17985]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 24 03:58:39 katarynka sudo[17985]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 03:58:39 katarynka volumio[17829]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 24 03:58:39 katarynka volumio[17829]: info: ___________ START PLUGINS ___________ Mar 24 03:58:39 katarynka volumio[17829]: info: ControllerMpd::onStart: Initializing MPD Mar 24 03:58:39 katarynka volumio[17829]: info: Creating MPD Configuration file Mar 24 03:58:39 katarynka systemd[1]: Stopping mpd.service - Music Player Daemon... Mar 24 03:58:39 katarynka volumio[17829]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 24 03:58:39 katarynka volumio[17829]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 24 03:58:39 katarynka volumio[17829]: info: [1774321119465] CoreMusicLibrary::Adding element Serwery Mediów Mar 24 03:58:39 katarynka volumio[17829]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 24 03:58:39 katarynka systemd[1]: mpd.service: Deactivated successfully. Mar 24 03:58:39 katarynka systemd[1]: Stopped mpd.service - Music Player Daemon. Mar 24 03:58:39 katarynka systemd[1]: mpd.service: Consumed 8.041s CPU time. Mar 24 03:58:39 katarynka systemd[1]: mpd.socket: Deactivated successfully. Mar 24 03:58:39 katarynka systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Mar 24 03:58:39 katarynka systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Mar 24 03:58:39 katarynka sudo[17993]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 24 03:58:39 katarynka volumio[17829]: info: UPNP Browser: Client initialized successfully Mar 24 03:58:39 katarynka sudo[17993]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 03:58:39 katarynka sudo[17995]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 24 03:58:39 katarynka sudo[17995]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 03:58:39 katarynka systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Mar 24 03:58:39 katarynka sudo[17993]: pam_unix(sudo:session): session closed for user root Mar 24 03:58:39 katarynka systemd[1]: Starting mpd.service - Music Player Daemon... Mar 24 03:58:39 katarynka volumio[17829]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 03:58:39 katarynka volumio[17829]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 24 03:58:39 katarynka systemd[1]: mpd.service: Deactivated successfully. Mar 24 03:58:39 katarynka systemd[1]: Stopped mpd.service - Music Player Daemon. Mar 24 03:58:39 katarynka systemd[1]: mpd.socket: Deactivated successfully. Mar 24 03:58:39 katarynka systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Mar 24 03:58:39 katarynka systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Mar 24 03:58:39 katarynka systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Mar 24 03:58:39 katarynka systemd[1]: Starting mpd.service - Music Player Daemon... Mar 24 03:58:39 katarynka volumio[17829]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 24 03:58:39 katarynka volumio[17829]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 03:58:39 katarynka volumio[17829]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 24 03:58:39 katarynka volumio[17829]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 24 03:58:39 katarynka volumio[17829]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 24 03:58:39 katarynka volumio[17829]: info: [1774321119853] CoreMusicLibrary::Adding element Last_100 Mar 24 03:58:39 katarynka volumio[17829]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 24 03:58:39 katarynka volumio[17829]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 24 03:58:39 katarynka volumio[17829]: info: [1774321119871] CoreMusicLibrary::Adding element Webradio Mar 24 03:58:39 katarynka volumio[17829]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 24 03:58:39 katarynka volumio[17829]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 24 03:58:39 katarynka volumio[17829]: info: Initializing BBC Radios Mar 24 03:58:40 katarynka volumio[17829]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 24 03:58:40 katarynka volumio[17829]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 24 03:58:40 katarynka volumio[17829]: info: Creating Spotify config file Mar 24 03:58:40 katarynka volumio[17829]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 03:58:40 katarynka sudo[18005]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Mar 24 03:58:40 katarynka sudo[18005]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Mar 24 03:58:40 katarynka sudo[18005]: pam_unix(sudo:session): session closed for user root Mar 24 03:58:40 katarynka volumio-remote-updater[622]: [2026-03-24 03:58:40] [connect] Successful connection Mar 24 03:58:41 katarynka volumio[17829]: info: Volumio Calling Home Mar 24 03:58:41 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 11. Mar 24 03:58:41 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 24 03:58:41 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 24 03:58:41 katarynka go-librespot[18041]: go-librespot daemon starting... Mar 24 03:58:41 katarynka go-librespot[18042]: time="2026-03-24T03:58:41+01:00" level=info msg="running go-librespot 0.4.0" Mar 24 03:58:42 katarynka go-librespot[18042]: time="2026-03-24T03:58:42+01:00" level=info msg="zeroconf server listening on port 46319" Mar 24 03:58:42 katarynka sudo[18051]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 24 03:58:42 katarynka sudo[18051]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 03:58:42 katarynka sudo[18051]: pam_unix(sudo:session): session closed for user root Mar 24 03:58:42 katarynka volumio[17829]: info: Discovery: adding 4d616d77-6a8c-4da2-85a4-840d70f98e51 Mar 24 03:58:42 katarynka volumio[17829]: info: Discovery: Found device katarynka Mar 24 03:58:42 katarynka volumio[17949]: Starting albumart workers Mar 24 03:58:42 katarynka volumio[17829]: info: CoreCommandRouter::volumioGetState Mar 24 03:58:42 katarynka volumio[17829]: info: CorePlayQueue::getTrack 0 Mar 24 03:58:42 katarynka sudo[18053]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 24 03:58:42 katarynka sudo[18053]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 03:58:42 katarynka sudo[18053]: pam_unix(sudo:session): session closed for user root Mar 24 03:58:42 katarynka volumio[17829]: info: Discovery: this is already registered, 4d616d77-6a8c-4da2-85a4-840d70f98e51 Mar 24 03:58:42 katarynka volumio[17829]: info: Discovery: Found device katarynka Mar 24 03:58:42 katarynka volumio[17829]: info: CoreCommandRouter::volumioGetState Mar 24 03:58:42 katarynka volumio[17829]: info: CorePlayQueue::getTrack 0 Mar 24 03:58:42 katarynka volumio[17948]: Starting albumart workers Mar 24 03:58:42 katarynka volumio[17950]: Starting albumart workers Mar 24 03:58:42 katarynka volumio[17829]: info: MPD Permissions set Mar 24 03:58:42 katarynka volumio[17829]: info: MPD Permissions set Mar 24 03:58:42 katarynka volumio[17829]: info: VolumeController:: Volume=96 Mute =false Mar 24 03:58:42 katarynka volumio[17829]: info: CoreStateMachine::pushState Mar 24 03:58:42 katarynka volumio[17829]: info: CorePlayQueue::getTrack 0 Mar 24 03:58:42 katarynka volumio[17829]: info: CoreCommandRouter::volumioPushState Mar 24 03:58:42 katarynka volumio-remote-updater[622]: [2026-03-24 03:58:42] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1774321120 101 Mar 24 03:58:43 katarynka volumio[17829]: 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 24 03:58:43 katarynka volumio[17829]: info: Volumio called home Mar 24 03:58:43 katarynka volumio[17829]: info: Spotify config file written Mar 24 03:58:43 katarynka volumio[17829]: 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 24 03:58:43 katarynka sudo[18057]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Mar 24 03:58:43 katarynka sudo[18057]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 03:58:43 katarynka volumio[17829]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 03:58:43 katarynka volumio[17829]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 03:58:43 katarynka volumio[17829]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 03:58:43 katarynka volumio[17829]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 03:58:43 katarynka volumio[17829]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 03:58:43 katarynka volumio[17829]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 03:58:43 katarynka volumio[17829]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 03:58:43 katarynka volumio[17829]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 03:58:43 katarynka volumio[17829]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 24 03:58:43 katarynka volumio[17829]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 03:58:43 katarynka systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Mar 24 03:58:43 katarynka systemd[1]: go-librespot-daemon.service: Killing process 18047 (go-librespot) with signal SIGKILL. Mar 24 03:58:43 katarynka systemd[1]: go-librespot-daemon.service: Deactivated successfully. Mar 24 03:58:43 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 24 03:58:43 katarynka volumio[17829]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 03:58:43 katarynka volumio[17829]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 03:58:43 katarynka volumio[17829]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 03:58:43 katarynka volumio[17829]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 03:58:43 katarynka volumio[17829]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 03:58:43 katarynka volumio[17829]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 03:58:43 katarynka volumio[17829]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 03:58:43 katarynka volumio[17829]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 03:58:43 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 24 03:58:43 katarynka go-librespot[18064]: go-librespot daemon starting... Mar 24 03:58:43 katarynka sudo[18057]: pam_unix(sudo:session): session closed for user root Mar 24 03:58:43 katarynka go-librespot[18065]: time="2026-03-24T03:58:43+01:00" level=info msg="running go-librespot 0.4.0" Mar 24 03:58:43 katarynka go-librespot[18065]: time="2026-03-24T03:58:43+01:00" level=debug msg="app state loaded" Mar 24 03:58:43 katarynka go-librespot[18065]: time="2026-03-24T03:58:43+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 24 03:58:43 katarynka volumio[17829]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 24 03:58:43 katarynka volumio[17829]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 03:58:43 katarynka volumio[17829]: info: No need to fix Spotify hosts Mar 24 03:58:44 katarynka go-librespot[18065]: time="2026-03-24T03:58: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-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 24 03:58:44 katarynka go-librespot[18065]: time="2026-03-24T03:58:44+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 24 03:58:44 katarynka go-librespot[18065]: time="2026-03-24T03:58:44+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 24 03:58:44 katarynka go-librespot[18065]: time="2026-03-24T03:58:44+01:00" level=info msg="zeroconf server listening on port 40469" Mar 24 03:58:44 katarynka go-librespot[18065]: time="2026-03-24T03:58:44+01:00" level=debug msg="obtained new client token: AAABrTz967bPivX7aGGCd/1pChZXns/v/tshhOAoHR9CmtISoN7vKzPawa+ADZMKuAUJqLRM2xnPVTkvUKivgSW4ZTGjNvg3MK6FG1nt4n4YSkptIvm5WCv7i3hE9k5xOFFQKi24xIVTl3m1E4nvsaexku5SBlZD0XapQzpfxKLB0ZA3Rd3n/oDDoi2V+R3A0khUAV2Ir2A6mcNxcRymf9y9hvP0Tr1rduSktZgOpTWP+6JXUegv8HQnp6Y=" Mar 24 03:58:44 katarynka go-librespot[18065]: time="2026-03-24T03:58:44+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 24 03:58:44 katarynka go-librespot[18065]: time="2026-03-24T03:58:44+01:00" level=debug msg="completed keyexchange" Mar 24 03:58:44 katarynka go-librespot[18065]: time="2026-03-24T03:58:44+01:00" level=debug msg="completed challenge" Mar 24 03:58:44 katarynka go-librespot[18065]: time="2026-03-24T03:58: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 24 03:58:44 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 24 03:58:44 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 24 03:58:44 katarynka volumio[17829]: info: Starting Shairport Sync Mar 24 03:58:44 katarynka volumio[17829]: info: Starting Shairport Sync Mar 24 03:58:45 katarynka volumio[17829]: info: Starting Shairport Sync Mar 24 03:58:45 katarynka sudo[18084]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 24 03:58:45 katarynka sudo[18084]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 03:58:45 katarynka sudo[18086]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 24 03:58:45 katarynka sudo[18086]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 03:58:45 katarynka sudo[18091]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Mar 24 03:58:45 katarynka sudo[18091]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 03:58:45 katarynka sudo[18089]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 24 03:58:45 katarynka sudo[18089]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 03:58:45 katarynka volumio[17829]: info: An error occurred while refreshing Spotify Token Error: Bad Request Mar 24 03:58:45 katarynka systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Mar 24 03:58:45 katarynka systemd[1]: shairport-sync.service: Deactivated successfully. Mar 24 03:58:45 katarynka systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 24 03:58:45 katarynka systemd[1]: shairport-sync.service: Consumed 2.419s CPU time. Mar 24 03:58:45 katarynka systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 24 03:58:45 katarynka sudo[18084]: pam_unix(sudo:session): session closed for user root Mar 24 03:58:45 katarynka systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Mar 24 03:58:45 katarynka systemd[1]: shairport-sync.service: Deactivated successfully. Mar 24 03:58:45 katarynka systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 24 03:58:45 katarynka volumio[17829]: info: Shairport-Sync Started Mar 24 03:58:45 katarynka sudo[18091]: pam_unix(sudo:session): session closed for user root Mar 24 03:58:45 katarynka volumio[17829]: Error adding Membership: Error: addMembership EINVAL Mar 24 03:58:45 katarynka volumio[17829]: info: Upmpdcli Daemon Started Mar 24 03:58:45 katarynka systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 24 03:58:45 katarynka sudo[18089]: pam_unix(sudo:session): session closed for user root Mar 24 03:58:45 katarynka sudo[18086]: pam_unix(sudo:session): session closed for user root Mar 24 03:58:45 katarynka volumio[17829]: info: CoreCommandRouter::volumioGetState Mar 24 03:58:45 katarynka volumio[17829]: info: CorePlayQueue::getTrack 0 Mar 24 03:58:45 katarynka volumio[17829]: info: Shairport-Sync Started Mar 24 03:58:45 katarynka volumio[17829]: info: Shairport-Sync Started Mar 24 03:58:47 katarynka volumio[17829]: info: go-librespot daemon successfully initialized Mar 24 03:58:47 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Mar 24 03:58:47 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 24 03:58:47 katarynka mpd[18024]: 2026-03-24T03:58:47 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Mar 24 03:58:47 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 24 03:58:47 katarynka go-librespot[18138]: go-librespot daemon starting... Mar 24 03:58:47 katarynka systemd[1]: Started mpd.service - Music Player Daemon. Mar 24 03:58:47 katarynka sudo[17995]: pam_unix(sudo:session): session closed for user root Mar 24 03:58:47 katarynka sudo[17985]: pam_unix(sudo:session): session closed for user root Mar 24 03:58:48 katarynka go-librespot[18141]: time="2026-03-24T03:58:48+01:00" level=info msg="running go-librespot 0.4.0" Mar 24 03:58:48 katarynka go-librespot[18141]: time="2026-03-24T03:58:48+01:00" level=debug msg="app state loaded" Mar 24 03:58:48 katarynka go-librespot[18141]: time="2026-03-24T03:58:48+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 24 03:58:48 katarynka volumio[17829]: info: Completed starting Core Plugins Mar 24 03:58:48 katarynka volumio[17829]: info: ------------------------------------------- Mar 24 03:58:48 katarynka volumio[17829]: info: ----- MyVolumio plugins startup ---- Mar 24 03:58:48 katarynka volumio[17829]: info: ------------------------------------------- Mar 24 03:58:48 katarynka volumio[17829]: info: [MyVolumio PluginManager] Fetching plans data.... Mar 24 03:58:48 katarynka volumio[17829]: error: MPD error: The expression evaluated to a falsy value: Mar 24 03:58:48 katarynka volumio[17829]: assert.ok(self.idling) Mar 24 03:58:48 katarynka volumio[17829]: error: The expression evaluated to a falsy value: Mar 24 03:58:48 katarynka volumio[17829]: assert.ok(self.idling) Mar 24 03:58:48 katarynka volumio[17829]: error: updateQueue error: null Mar 24 03:58:48 katarynka volumio[17829]: info: MPD running with PID18024 Mar 24 03:58:48 katarynka volumio[17829]: ,establishing connection Mar 24 03:58:48 katarynka volumio[17829]: error: updateQueue error: null Mar 24 03:58:48 katarynka go-librespot[18141]: time="2026-03-24T03:58: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-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 24 03:58:48 katarynka go-librespot[18141]: time="2026-03-24T03:58:48+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 24 03:58:48 katarynka go-librespot[18141]: time="2026-03-24T03:58:48+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 24 03:58:48 katarynka go-librespot[18141]: time="2026-03-24T03:58:48+01:00" level=info msg="zeroconf server listening on port 41927" Mar 24 03:58:48 katarynka go-librespot[18141]: time="2026-03-24T03:58:48+01:00" level=debug msg="obtained new client token: AAATcCIxMscrOaku/wtQctTVeyiBZrqJNVfTPuQtyu5bt8+TVzi9ul9Vp5dAehnf0kWU7F/LjJZYxr7siuuaZo/yLipWapV3CQV2U8p6zqPoIjmlB69hFvOnUiASPLRX+jivVsFpnvWmsK7azcuxjqbI6v7EHsxZbL2al4i4rHZYJu9X+C2GSeZhcaaSmWcNfaoN2js967RoL4lnDZmoim5HAs1smLoN3ik+VUHMiklw2yPmmr/SmkUOYGo=" Mar 24 03:58:48 katarynka go-librespot[18141]: time="2026-03-24T03:58:48+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 24 03:58:48 katarynka go-librespot[18141]: time="2026-03-24T03:58:48+01:00" level=debug msg="completed keyexchange" Mar 24 03:58:48 katarynka go-librespot[18141]: time="2026-03-24T03:58:48+01:00" level=debug msg="completed challenge" Mar 24 03:58:48 katarynka go-librespot[18141]: time="2026-03-24T03:58: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 24 03:58:48 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 24 03:58:48 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 24 03:58:50 katarynka volumio[17829]: info: Initializing connection to go-librespot Websocket Mar 24 03:58:50 katarynka volumio[17829]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 24 03:58:51 katarynka sudo[18157]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Mar 24 03:58:51 katarynka sudo[18157]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 03:58:51 katarynka sudo[18162]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Mar 24 03:58:51 katarynka sudo[18162]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 03:58:51 katarynka systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Mar 24 03:58:51 katarynka systemd[1]: mpd_monitor.service: Deactivated successfully. Mar 24 03:58:51 katarynka systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Mar 24 03:58:51 katarynka systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Mar 24 03:58:51 katarynka sudo[18157]: pam_unix(sudo:session): session closed for user root Mar 24 03:58:51 katarynka sudo[18162]: pam_unix(sudo:session): session closed for user root Mar 24 03:58:51 katarynka volumio[17829]: info: Successfully started MPD Monitor Mar 24 03:58:51 katarynka volumio[17829]: info: Successfully started MPD Monitor Mar 24 03:58:51 katarynka mpd_monitor.sh[18171]: MPD Monitor Service: Starting MPD Monitor Service Mar 24 03:58:51 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Mar 24 03:58:51 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 24 03:58:51 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 24 03:58:51 katarynka go-librespot[18175]: go-librespot daemon starting... Mar 24 03:58:52 katarynka go-librespot[18176]: time="2026-03-24T03:58:52+01:00" level=info msg="running go-librespot 0.4.0" Mar 24 03:58:52 katarynka go-librespot[18176]: time="2026-03-24T03:58:52+01:00" level=debug msg="app state loaded" Mar 24 03:58:52 katarynka go-librespot[18176]: time="2026-03-24T03:58:52+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 24 03:58:52 katarynka go-librespot[18176]: time="2026-03-24T03:58: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 24 03:58:52 katarynka go-librespot[18176]: time="2026-03-24T03:58:52+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 24 03:58:52 katarynka go-librespot[18176]: time="2026-03-24T03:58:52+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 24 03:58:52 katarynka go-librespot[18176]: time="2026-03-24T03:58:52+01:00" level=info msg="zeroconf server listening on port 44005" Mar 24 03:58:52 katarynka go-librespot[18176]: time="2026-03-24T03:58:52+01:00" level=debug msg="obtained new client token: AACmJTqXqemI92iyaEc2b9xQfH04V8NgzAd0ysrq1R1kqUB6abqOBcwz7CG7nkzp+Zlu5MmXx7zaU3ZMIDJLyi41Oj4VMORSXLBU1BcyupS3cn18tkHQk2LNU2T37kkmGeBeoBqS5QTDgNNzV/BLtqqjcq1Oto15+qBdaznM0eh2FJBva/sw0O5m8PGeK9g+RTE7Fik6O5rsdt9+BYdyAcRzYEASiVaD15kA8YG/MJXpDJ/c+W5dd9n/ako=" Mar 24 03:58:52 katarynka go-librespot[18176]: time="2026-03-24T03:58:52+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 24 03:58:52 katarynka go-librespot[18176]: time="2026-03-24T03:58:52+01:00" level=debug msg="completed keyexchange" Mar 24 03:58:52 katarynka go-librespot[18176]: time="2026-03-24T03:58:52+01:00" level=debug msg="completed challenge" Mar 24 03:58:52 katarynka go-librespot[18176]: time="2026-03-24T03:58:52+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 24 03:58:52 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 24 03:58:52 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 24 03:58:53 katarynka volumio[17829]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Mar 24 03:58:53 katarynka volumio[17829]: info: Initializing connection to go-librespot Websocket Mar 24 03:58:53 katarynka volumio[17829]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 24 03:58:55 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Mar 24 03:58:55 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 24 03:58:55 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 24 03:58:55 katarynka go-librespot[18183]: go-librespot daemon starting... Mar 24 03:58:56 katarynka go-librespot[18184]: time="2026-03-24T03:58:56+01:00" level=info msg="running go-librespot 0.4.0" Mar 24 03:58:56 katarynka go-librespot[18184]: time="2026-03-24T03:58:56+01:00" level=debug msg="app state loaded" Mar 24 03:58:56 katarynka go-librespot[18184]: time="2026-03-24T03:58:56+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 24 03:58:56 katarynka go-librespot[18184]: time="2026-03-24T03:58: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 24 03:58:56 katarynka go-librespot[18184]: time="2026-03-24T03:58: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 24 03:58:56 katarynka go-librespot[18184]: time="2026-03-24T03:58: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 24 03:58:56 katarynka go-librespot[18184]: time="2026-03-24T03:58:56+01:00" level=info msg="zeroconf server listening on port 45559" Mar 24 03:58:56 katarynka volumio[17829]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Mar 24 03:58:56 katarynka volumio[17829]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Mar 24 03:58:56 katarynka volumio[17829]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Mar 24 03:58:56 katarynka volumio[17829]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Mar 24 03:58:56 katarynka volumio[17829]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Mar 24 03:58:56 katarynka volumio[17829]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Mar 24 03:58:56 katarynka volumio[17829]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Mar 24 03:58:56 katarynka volumio[17829]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Mar 24 03:58:56 katarynka volumio[17829]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Mar 24 03:58:56 katarynka volumio[17829]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Mar 24 03:58:56 katarynka volumio[17829]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Mar 24 03:58:56 katarynka volumio[17829]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Mar 24 03:58:56 katarynka volumio[17829]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Mar 24 03:58:56 katarynka volumio[17829]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Mar 24 03:58:56 katarynka volumio[17829]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Mar 24 03:58:56 katarynka volumio[17829]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Mar 24 03:58:56 katarynka volumio[17829]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Mar 24 03:58:56 katarynka volumio[17829]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Mar 24 03:58:56 katarynka volumio[17829]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Mar 24 03:58:56 katarynka volumio[17829]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Mar 24 03:58:56 katarynka volumio[17829]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Mar 24 03:58:56 katarynka volumio[17829]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Mar 24 03:58:56 katarynka volumio[17829]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Mar 24 03:58:56 katarynka volumio[17829]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Mar 24 03:58:56 katarynka volumio[17829]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Mar 24 03:58:56 katarynka volumio[17829]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Mar 24 03:58:56 katarynka volumio[17829]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Mar 24 03:58:56 katarynka volumio[17829]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Mar 24 03:58:56 katarynka volumio[17829]: info: Adding plugin bluetooth to MyMusic Plugins Mar 24 03:58:56 katarynka volumio[17829]: info: Adding plugin multiroom to MyMusic Plugins Mar 24 03:58:56 katarynka volumio[17829]: info: Adding plugin metavolumio to MyMusic Plugins Mar 24 03:58:56 katarynka volumio[17829]: info: Adding plugin cd_controller to MyMusic Plugins Mar 24 03:58:56 katarynka volumio[17829]: info: Adding plugin qobuzconnect to MyMusic Plugins Mar 24 03:58:56 katarynka volumio[17829]: info: Adding plugin smart_inputs to MyMusic Plugins Mar 24 03:58:56 katarynka volumio[17829]: info: Adding plugin tidalconnect to MyMusic Plugins Mar 24 03:58:56 katarynka volumio[17829]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Mar 24 03:58:56 katarynka go-librespot[18184]: time="2026-03-24T03:58:56+01:00" level=debug msg="obtained new client token: AABx51a1O/zYDp6LRy+7s2w4kXCNzf/feesf13yLh3sB5BTu49F9pEinEmhtLG2cl4yn/ivS3uZdq5acp+RBi54mliwLvzY+EkN14nYKhNWDija6IhZf+CIAUx23fp2SzbPd5mbSXkeoQ56oc5yV/85EoOdSF0Zq9WiP8t33G4vv3aN1lTy1nHpZzo8wBS33HanxvwD2JLX6YfOW2fYFSt+68LUHqIia7t+F/xtZYZMa2V5lWJ3V7isMLP8=" Mar 24 03:58:56 katarynka go-librespot[18184]: time="2026-03-24T03:58:56+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 24 03:58:56 katarynka go-librespot[18184]: time="2026-03-24T03:58:56+01:00" level=debug msg="completed keyexchange" Mar 24 03:58:56 katarynka go-librespot[18184]: time="2026-03-24T03:58:56+01:00" level=debug msg="completed challenge" Mar 24 03:58:56 katarynka go-librespot[18184]: time="2026-03-24T03:58:56+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 24 03:58:56 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 24 03:58:56 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 24 03:58:58 katarynka volumio[17829]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Mar 24 03:58:58 katarynka volumio[17829]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Mar 24 03:58:58 katarynka volumio[17829]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 24 03:58:58 katarynka volumio[17829]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 24 03:58:58 katarynka volumio[17829]: info: Starting MyVolumio Remote Streaming Endpoints Mar 24 03:58:58 katarynka volumio[17829]: info: MyVolumio login type: Token Mar 24 03:58:58 katarynka volumio[17829]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Mar 24 03:58:58 katarynka volumio[17829]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Mar 24 03:58:59 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Mar 24 03:58:59 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 24 03:58:59 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 24 03:59:00 katarynka go-librespot[18192]: go-librespot daemon starting... Mar 24 03:59:00 katarynka go-librespot[18193]: time="2026-03-24T03:59:00+01:00" level=info msg="running go-librespot 0.4.0" Mar 24 03:59:00 katarynka go-librespot[18193]: time="2026-03-24T03:59:00+01:00" level=debug msg="app state loaded" Mar 24 03:59:00 katarynka go-librespot[18193]: time="2026-03-24T03:59:00+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 24 03:59:00 katarynka volumio[17829]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Mar 24 03:59:00 katarynka volumio[17829]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Mar 24 03:59:00 katarynka volumio[17829]: info: Streaming services startup Mar 24 03:59:00 katarynka volumio[17829]: info: Starting Streaming Daemon Mar 24 03:59:00 katarynka go-librespot[18193]: time="2026-03-24T03:59: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 24 03:59:00 katarynka go-librespot[18193]: time="2026-03-24T03:59: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 24 03:59:00 katarynka go-librespot[18193]: time="2026-03-24T03:59: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 24 03:59:00 katarynka sudo[18201]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Mar 24 03:59:00 katarynka go-librespot[18193]: time="2026-03-24T03:59:00+01:00" level=info msg="zeroconf server listening on port 37333" Mar 24 03:59:00 katarynka volumio[17829]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Mar 24 03:59:00 katarynka sudo[18201]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 03:59:00 katarynka sudo[18201]: pam_unix(sudo:session): session closed for user root Mar 24 03:59:00 katarynka volumio[17829]: info: Initializing connection to go-librespot Websocket Mar 24 03:59:00 katarynka go-librespot[18193]: time="2026-03-24T03:59:00+01:00" level=debug msg="obtained new client token: AAAMagoEzQN2dwBc5sdlQ4G6AHb2Qr3gxK8RBrLTKJYU3v1Zq2f2GRw9YxWqn8yzy0/zBmRv8dno8UmWsxVW0iGuThnfF9Oi4ADA3xn0/CWjGpBX1nA/VcCSV5SQXK76L9h5VlnkQHUhUY+/WRHGQvIPyx0bGT30OeMDOG2J2wHp6j8Pzmf9+zSB/exuUU3Nx2A35sue7/XEizBDDvjnXYaWsqkD6Pq1q8RoS45l1ZyC3cohWZNHOvb2snk=" Mar 24 03:59:00 katarynka volumio[17829]: error: Cannot start Volumio Streaming Daemon Mar 24 03:59:00 katarynka volumio[17829]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Mar 24 03:59:00 katarynka volumio[17829]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Mar 24 03:59:00 katarynka go-librespot[18193]: time="2026-03-24T03:59:00+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 24 03:59:00 katarynka go-librespot[18193]: time="2026-03-24T03:59:00+01:00" level=debug msg="new websocket client" Mar 24 03:59:00 katarynka volumio[17829]: info: Connection to go-librespot Websocket established Mar 24 03:59:00 katarynka go-librespot[18193]: time="2026-03-24T03:59:00+01:00" level=debug msg="completed keyexchange" Mar 24 03:59:00 katarynka go-librespot[18193]: time="2026-03-24T03:59:00+01:00" level=debug msg="completed challenge" Mar 24 03:59:00 katarynka go-librespot[18193]: time="2026-03-24T03:59:00+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 24 03:59:00 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 24 03:59:00 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 24 03:59:00 katarynka volumio[17829]: info: Connection to go-librespot Websocket closed Mar 24 03:59:01 katarynka volumio[17829]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Mar 24 03:59:02 katarynka volumio[17829]: info: MyVolumio token set successfully Mar 24 03:59:02 katarynka volumio[17829]: info: MYVOLUMIO: Adding device Mar 24 03:59:02 katarynka volumio[17829]: info: MYVOLUMIO: Evaluating Server Mar 24 03:59:03 katarynka volumio[17829]: info: MyVolumio status changed Mar 24 03:59:03 katarynka volumio[17829]: info: Streaming services startup Mar 24 03:59:03 katarynka volumio[17829]: info: Starting Streaming Daemon Mar 24 03:59:03 katarynka volumio[17829]: info: Removing browser output: myVolumio user plan is not superstar Mar 24 03:59:03 katarynka volumio[17829]: info: Removing audio output: Mar 24 03:59:03 katarynka volumio[17829]: info: Stoppping Tunnel 1 Mar 24 03:59:03 katarynka sudo[18243]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Mar 24 03:59:03 katarynka sudo[18243]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 03:59:03 katarynka sudo[18245]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Mar 24 03:59:03 katarynka sudo[18245]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 03:59:03 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 24 03:59:03 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 24 03:59:03 katarynka sudo[18243]: pam_unix(sudo:session): session closed for user root Mar 24 03:59:03 katarynka volumio[17829]: error: Cannot start Volumio Streaming Daemon Mar 24 03:59:03 katarynka volumio[17829]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Mar 24 03:59:03 katarynka volumio[17829]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Mar 24 03:59:03 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 24 03:59:03 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 24 03:59:03 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 24 03:59:03 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 24 03:59:03 katarynka sudo[18245]: pam_unix(sudo:session): session closed for user root Mar 24 03:59:03 katarynka volumio[17829]: info: Remote SSH Stopped Mar 24 03:59:03 katarynka volumio[17829]: info: Setting Geolocation for MyVolumio to eu10 Mar 24 03:59:03 katarynka volumio[17829]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 24 03:59:03 katarynka volumio[17829]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 24 03:59:03 katarynka volumio[17829]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 24 03:59:03 katarynka volumio[17829]: info: Getting Spotify volume Mar 24 03:59:03 katarynka volumio[17829]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 24 03:59:03 katarynka volumio[17829]: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 24 03:59:03 katarynka volumio[17829]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Mar 24 03:59:03 katarynka volumio[17829]: errno: -111, Mar 24 03:59:03 katarynka volumio[17829]: code: 'ECONNREFUSED', Mar 24 03:59:03 katarynka volumio[17829]: syscall: 'connect', Mar 24 03:59:03 katarynka volumio[17829]: address: '127.0.0.1', Mar 24 03:59:03 katarynka volumio[17829]: port: 9879, Mar 24 03:59:03 katarynka volumio[17829]: response: undefined Mar 24 03:59:03 katarynka volumio[17829]: } Mar 24 03:59:03 katarynka volumio[17829]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 24 03:59:03 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Mar 24 03:59:03 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 24 03:59:03 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 24 03:59:03 katarynka go-librespot[18259]: go-librespot daemon starting... Mar 24 03:59:04 katarynka go-librespot[18260]: time="2026-03-24T03:59:04+01:00" level=info msg="running go-librespot 0.4.0" Mar 24 03:59:04 katarynka go-librespot[18260]: time="2026-03-24T03:59:04+01:00" level=debug msg="app state loaded" Mar 24 03:59:04 katarynka go-librespot[18260]: time="2026-03-24T03:59:04+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 24 03:59:04 katarynka go-librespot[18260]: time="2026-03-24T03:59: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 24 03:59:04 katarynka go-librespot[18260]: time="2026-03-24T03:59: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 24 03:59:04 katarynka go-librespot[18260]: time="2026-03-24T03:59: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 24 03:59:04 katarynka go-librespot[18260]: time="2026-03-24T03:59:04+01:00" level=info msg="zeroconf server listening on port 33581" Mar 24 03:59:04 katarynka go-librespot[18260]: time="2026-03-24T03:59:04+01:00" level=debug msg="obtained new client token: AACh9pSEm6z7NuXmmcfYs5nLxYoQG34asDRZcUMz6P2Hgo2MX2tjCxokHTFJWA7jpqufGTQ5u2XRpsX5o6+uCjWRBP8WBf2306LEeUgKK9ozRqPMqtNw5BaW9xWuxFCJYn6HNdKSLKCVRb5eOZCLZzAwx0Scj91YAVgawRTGK2cQLOLt1C0vBsE1cHMY6KH2DCqawHeleEl6JPSEVHnKf+lSXwHQDO+DrCWvnhnMo3xtgc428tGhsjFgu3M=" Mar 24 03:59:04 katarynka go-librespot[18260]: time="2026-03-24T03:59:04+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 24 03:59:04 katarynka go-librespot[18260]: time="2026-03-24T03:59:04+01:00" level=debug msg="completed keyexchange" Mar 24 03:59:04 katarynka go-librespot[18260]: time="2026-03-24T03:59:04+01:00" level=debug msg="completed challenge" Mar 24 03:59:04 katarynka go-librespot[18260]: time="2026-03-24T03:59: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 24 03:59:04 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 24 03:59:04 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 24 03:59:05 katarynka sudo[18271]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-03-24 03:58' Mar 24 03:59:05 katarynka sudo[18271]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 03:59:05 katarynka sudo[18271]: pam_unix(sudo:session): session closed for user root Mar 24 03:59:05 katarynka volumio-remote-updater[622]: [2026-03-24 03:59:05] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Mar 24 03:59:05 katarynka volumio-remote-updater[622]: [2026-03-24 03:59:05] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Mar 24 03:59:05 katarynka systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Mar 24 03:59:05 katarynka systemd[1]: volumio.service: Failed with result 'exit-code'. Mar 24 03:59:05 katarynka systemd[1]: volumio.service: Consumed 50.677s CPU time. Mar 24 03:59:05 katarynka systemd[1]: Started dynamicswap.service - dynamicswap service. Mar 24 03:59:05 katarynka systemd[1]: dynamicswap.service: Deactivated successfully. Mar 24 03:59:05 katarynka systemd[1]: volumio.service: Scheduled restart job, restart counter is at 24362. Mar 24 03:59:05 katarynka systemd[1]: Started dynamicswap.service - dynamicswap service. Mar 24 03:59:05 katarynka systemd[1]: Stopped volumio.service - Volumio Backend Module. Mar 24 03:59:05 katarynka systemd[1]: volumio.service: Consumed 50.677s CPU time. Mar 24 03:59:05 katarynka systemd[1]: Started volumio.service - Volumio Backend Module. Mar 24 03:59:06 katarynka systemd[1]: dynamicswap.service: Deactivated successfully. Mar 24 03:59:07 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Mar 24 03:59:07 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 24 03:59:07 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 24 03:59:07 katarynka go-librespot[18299]: go-librespot daemon starting... Mar 24 03:59:08 katarynka go-librespot[18300]: time="2026-03-24T03:59:08+01:00" level=info msg="running go-librespot 0.4.0" Mar 24 03:59:08 katarynka go-librespot[18300]: time="2026-03-24T03:59:08+01:00" level=debug msg="app state loaded" Mar 24 03:59:08 katarynka go-librespot[18300]: time="2026-03-24T03:59:08+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 24 03:59:08 katarynka go-librespot[18300]: time="2026-03-24T03:59: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-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 24 03:59:08 katarynka go-librespot[18300]: time="2026-03-24T03:59:08+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 24 03:59:08 katarynka go-librespot[18300]: time="2026-03-24T03:59:08+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 24 03:59:08 katarynka go-librespot[18300]: time="2026-03-24T03:59:08+01:00" level=info msg="zeroconf server listening on port 43745" Mar 24 03:59:08 katarynka go-librespot[18300]: time="2026-03-24T03:59:08+01:00" level=debug msg="obtained new client token: AABOPf3QLrk8ANDLJME7YulpLbP+Xz8+nwmvu3F0+1g9nOHoGGtwkBjLOqcmSra42wnKRmlN1FzYuXL/Zin+sPCJEjX5XGWQQ9B7SlC1lirP5Ly9DuBVTxjBZZA1UNFfmzu+VruhCLe6Clw7gIddzLjZobMDvkFXT7/1AfcSWOPJKUzq9bVLd8aHU24TZR0wbs3bgI4B+lmb9UYWu6N4xlK5l1z5e6n59d31ijFztKNVGdhE11DtyPXMPmM=" Mar 24 03:59:08 katarynka go-librespot[18300]: time="2026-03-24T03:59:08+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 24 03:59:08 katarynka go-librespot[18300]: time="2026-03-24T03:59:08+01:00" level=debug msg="completed keyexchange" Mar 24 03:59:08 katarynka go-librespot[18300]: time="2026-03-24T03:59:08+01:00" level=debug msg="completed challenge" Mar 24 03:59:08 katarynka go-librespot[18300]: time="2026-03-24T03:59: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 24 03:59:08 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 24 03:59:08 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 24 03:59:09 katarynka volumio[18284]: info: ------------------------------------------- Mar 24 03:59:09 katarynka volumio[18284]: info: ----- Volumio3 ---- Mar 24 03:59:09 katarynka volumio[18284]: info: ------------------------------------------- Mar 24 03:59:09 katarynka volumio[18284]: info: ----- System startup ---- Mar 24 03:59:09 katarynka volumio[18284]: info: ------------------------------------------- Mar 24 03:59:10 katarynka volumio-remote-updater[622]: [2026-03-24 03:59:10] [connect] Successful connection Mar 24 03:59:11 katarynka volumio[18284]: info: MYVOLUMIO Environment detected Mar 24 03:59:11 katarynka volumio[18284]: info: Plugin folders cleanup Mar 24 03:59:11 katarynka volumio[18284]: info: Scanning into folder /volumio/app/plugins/ Mar 24 03:59:11 katarynka volumio[18284]: info: Scanning category audio_interface Mar 24 03:59:11 katarynka volumio[18284]: info: Scanning category miscellanea Mar 24 03:59:11 katarynka volumio[18284]: info: Scanning category music_service Mar 24 03:59:11 katarynka volumio[18284]: info: Scanning category plugins.json Mar 24 03:59:11 katarynka volumio[18284]: info: Scanning category system_controller Mar 24 03:59:11 katarynka volumio[18284]: info: Scanning category user_interface Mar 24 03:59:11 katarynka volumio[18284]: info: Scanning into folder /data/plugins/ Mar 24 03:59:11 katarynka volumio[18284]: info: Scanning category music_service Mar 24 03:59:11 katarynka volumio[18284]: info: Plugin folders cleanup completed Mar 24 03:59:11 katarynka volumio[18284]: info: ------------------------------------------- Mar 24 03:59:11 katarynka volumio[18284]: info: ----- Core plugins startup ---- Mar 24 03:59:11 katarynka volumio[18284]: info: ------------------------------------------- Mar 24 03:59:11 katarynka volumio[18284]: info: Loading plugins from folder /volumio/app/plugins/ Mar 24 03:59:11 katarynka volumio[18284]: info: Adding plugin upnp to MyMusic Plugins Mar 24 03:59:11 katarynka volumio[18284]: info: Adding plugin airplay_emulation to MyMusic Plugins Mar 24 03:59:11 katarynka volumio[18284]: info: Adding plugin upnp_browser to MyMusic Plugins Mar 24 03:59:11 katarynka volumio[18284]: info: Loading plugins from folder /data/plugins/ Mar 24 03:59:11 katarynka volumio[18284]: info: Loading plugin "system"... Mar 24 03:59:11 katarynka volumio[18284]: info: Loading plugin "appearance"... Mar 24 03:59:11 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Mar 24 03:59:11 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 24 03:59:11 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 24 03:59:11 katarynka go-librespot[18322]: go-librespot daemon starting... Mar 24 03:59:12 katarynka go-librespot[18323]: time="2026-03-24T03:59:12+01:00" level=info msg="running go-librespot 0.4.0" Mar 24 03:59:12 katarynka go-librespot[18323]: time="2026-03-24T03:59:12+01:00" level=debug msg="app state loaded" Mar 24 03:59:12 katarynka go-librespot[18323]: time="2026-03-24T03:59:12+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 24 03:59:12 katarynka go-librespot[18323]: time="2026-03-24T03:59:12+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 24 03:59:12 katarynka go-librespot[18323]: time="2026-03-24T03:59:12+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 24 03:59:12 katarynka go-librespot[18323]: time="2026-03-24T03:59:12+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 24 03:59:12 katarynka go-librespot[18323]: time="2026-03-24T03:59:12+01:00" level=info msg="zeroconf server listening on port 36507" Mar 24 03:59:12 katarynka go-librespot[18323]: time="2026-03-24T03:59:12+01:00" level=debug msg="obtained new client token: AAATG4Kl1JOEhzxj7MlzNW2pqK8990TLD9AafsYzWxH8ztipcoZTSIrPjtfNgSlldedssCb3SmjTDkpSSehj96qCouwf4DzPmi9IxyGXhE3H/eJpREofg3lFeHN8x9mpRmS2R0oEsgqadOiqC2KTdQGY7x/P6teFO2RHPbJ2pGYf73mWIkywB4HczcqpNAOBqlcSxT0H5FwiZiKfsB7IQjJXCckfS5tUiTcT+A69T5oZsJoZBS54AIbmPtQ=" Mar 24 03:59:12 katarynka go-librespot[18323]: time="2026-03-24T03:59:12+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 24 03:59:13 katarynka go-librespot[18323]: time="2026-03-24T03:59:13+01:00" level=debug msg="completed keyexchange" Mar 24 03:59:13 katarynka go-librespot[18323]: time="2026-03-24T03:59:13+01:00" level=debug msg="completed challenge" Mar 24 03:59:13 katarynka go-librespot[18323]: time="2026-03-24T03:59:13+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 24 03:59:13 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 24 03:59:13 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 24 03:59:13 katarynka volumio[18284]: info: Loading plugin "network"... Mar 24 03:59:13 katarynka volumio[18284]: info: Refreshing Cached IP Addresses Mar 24 03:59:13 katarynka sudo[18331]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 24 03:59:13 katarynka sudo[18331]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 03:59:13 katarynka sudo[18333]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 24 03:59:13 katarynka sudo[18331]: pam_unix(sudo:session): session closed for user root Mar 24 03:59:13 katarynka volumio[18284]: info: Loading plugin "services"... Mar 24 03:59:13 katarynka sudo[18333]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 03:59:13 katarynka volumio[18284]: info: Loading plugin "alsa_controller"... Mar 24 03:59:13 katarynka sudo[18333]: pam_unix(sudo:session): session closed for user root Mar 24 03:59:13 katarynka sudo[18341]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Mar 24 03:59:13 katarynka sudo[18341]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 03:59:13 katarynka volumio[18284]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 24 03:59:13 katarynka volumio[18284]: info: Loading plugin "wizard"... Mar 24 03:59:13 katarynka volumio[18284]: info: Loading plugin "networkfs"... Mar 24 03:59:13 katarynka volumio[18284]: info: Starting Udev Watcher for removable devices Mar 24 03:59:13 katarynka volumio[18284]: info: Ignoring mount for partition: boot Mar 24 03:59:13 katarynka volumio[18284]: info: Ignoring mount for partition: volumio Mar 24 03:59:13 katarynka volumio[18284]: info: Ignoring mount for partition: volumio_data Mar 24 03:59:13 katarynka volumio[18284]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 24 03:59:13 katarynka volumio[18284]: info: Loading plugin "volumio_command_line_client"... Mar 24 03:59:14 katarynka volumio[18284]: info: Loading plugin "upnp"... Mar 24 03:59:14 katarynka volumio[18284]: info: [1774321154020] Starting Upmpd Daemon Mar 24 03:59:14 katarynka volumio[18284]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 24 03:59:14 katarynka volumio[18284]: info: Loading plugin "my_music"... Mar 24 03:59:14 katarynka volumio[18284]: info: Loading plugin "mpd"... Mar 24 03:59:14 katarynka sudo[18341]: pam_unix(sudo:session): session closed for user root Mar 24 03:59:14 katarynka volumio[18284]: info: Loading plugin "upnp_browser"... Mar 24 03:59:16 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Mar 24 03:59:16 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 24 03:59:16 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 24 03:59:16 katarynka go-librespot[18364]: go-librespot daemon starting... Mar 24 03:59:16 katarynka go-librespot[18365]: time="2026-03-24T03:59:16+01:00" level=info msg="running go-librespot 0.4.0" Mar 24 03:59:16 katarynka go-librespot[18365]: time="2026-03-24T03:59:16+01:00" level=debug msg="app state loaded" Mar 24 03:59:16 katarynka go-librespot[18365]: time="2026-03-24T03:59:16+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 24 03:59:17 katarynka go-librespot[18365]: time="2026-03-24T03:59:17+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Mar 24 03:59:17 katarynka go-librespot[18365]: time="2026-03-24T03:59:17+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 24 03:59:17 katarynka go-librespot[18365]: time="2026-03-24T03:59:17+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 24 03:59:17 katarynka go-librespot[18365]: time="2026-03-24T03:59:17+01:00" level=info msg="zeroconf server listening on port 41339" Mar 24 03:59:17 katarynka go-librespot[18365]: time="2026-03-24T03:59:17+01:00" level=debug msg="obtained new client token: AAAgZhhR3d/HRjTXWFeMYmpEZP/nphJ6yKNmA42VSUZQo08oaL97aXibtpclZ28EV+001BQX9j4F5UoeubdgCAa/7WERz10Qq76+yMKLzaNCsHfoKWeyEpC8kDWjcu2+uvkyjMeBvr5egZSMvqdDFEFwMQvzaj6lfw70rAJK+8QYpNh/VZwlxtIIZj17L48FbkKHgbp6n8wDPot/N1+ro+IoYgWt5ZNirPbhVyy+tc7yR+ANWuYKSj3Xa38=" Mar 24 03:59:17 katarynka go-librespot[18365]: time="2026-03-24T03:59:17+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 24 03:59:17 katarynka go-librespot[18365]: time="2026-03-24T03:59:17+01:00" level=debug msg="completed keyexchange" Mar 24 03:59:17 katarynka go-librespot[18365]: time="2026-03-24T03:59:17+01:00" level=debug msg="completed challenge" Mar 24 03:59:17 katarynka go-librespot[18365]: time="2026-03-24T03:59:17+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 24 03:59:17 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 24 03:59:17 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 24 03:59:17 katarynka volumio[18284]: info: Starting UPNP Browser Mar 24 03:59:17 katarynka volumio[18284]: info: Loading plugin "alarm-clock"... Mar 24 03:59:18 katarynka volumio[18284]: info: Loading plugin "airplay_emulation"... Mar 24 03:59:18 katarynka volumio[18284]: info: Starting Shairport Sync Mar 24 03:59:18 katarynka volumio[18284]: info: Loading plugin "last_100"... Mar 24 03:59:18 katarynka volumio[18284]: info: Loading plugin "webradio"... Mar 24 03:59:18 katarynka volumio[18284]: info: Loading plugin "i2s_dacs"... Mar 24 03:59:18 katarynka volumio[18284]: info: Loading plugin "volumiodiscovery"... Mar 24 03:59:18 katarynka volumio[18284]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Mar 24 03:59:18 katarynka volumio[18284]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 24 03:59:18 katarynka volumio[18284]: *** WARNING *** For more information see Mar 24 03:59:18 katarynka volumio[18284]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Mar 24 03:59:18 katarynka volumio[18284]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 24 03:59:18 katarynka volumio[18284]: *** WARNING *** For more information see Mar 24 03:59:18 katarynka node[18284]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Mar 24 03:59:18 katarynka node[18284]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 24 03:59:18 katarynka node[18284]: *** WARNING *** For more information see Mar 24 03:59:18 katarynka node[18284]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Mar 24 03:59:18 katarynka node[18284]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 24 03:59:18 katarynka node[18284]: *** WARNING *** For more information see Mar 24 03:59:18 katarynka volumio[18284]: info: Applying required configuration parameters for plugin volumiodiscovery Mar 24 03:59:18 katarynka volumio[18284]: info: Discovery: Started advertising with name: katarynka Mar 24 03:59:18 katarynka volumio[18284]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 24 03:59:18 katarynka volumio[18284]: info: Loading plugin "spop"... Mar 24 03:59:20 katarynka volumio[18284]: info: Loading plugin "outputs"... Mar 24 03:59:20 katarynka volumio[18284]: info: Loading plugin "albumart"... Mar 24 03:59:20 katarynka volumio[18284]: info: Plugin example_plugin is not enabled Mar 24 03:59:20 katarynka volumio[18284]: info: Loading plugin "inputs"... Mar 24 03:59:20 katarynka volumio[18284]: info: Loading plugin "updater_comm"... Mar 24 03:59:20 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Mar 24 03:59:20 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 24 03:59:20 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 24 03:59:20 katarynka go-librespot[18384]: go-librespot daemon starting... Mar 24 03:59:20 katarynka go-librespot[18386]: time="2026-03-24T03:59:20+01:00" level=info msg="running go-librespot 0.4.0" Mar 24 03:59:20 katarynka go-librespot[18386]: time="2026-03-24T03:59:20+01:00" level=debug msg="app state loaded" Mar 24 03:59:20 katarynka go-librespot[18386]: time="2026-03-24T03:59:20+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 24 03:59:20 katarynka volumio[18284]: info: Plugin mpdemulation is not enabled Mar 24 03:59:20 katarynka volumio[18284]: info: Loading plugin "rest_api"... Mar 24 03:59:20 katarynka volumio[18284]: info: Loading plugin "websocket"... Mar 24 03:59:20 katarynka volumio[18284]: info: Starting Socket.io Server version 1.7.4 Mar 24 03:59:20 katarynka volumio[18284]: info: Loading i18n strings for locale pl Mar 24 03:59:20 katarynka volumio[18284]: Updating browse sources language Mar 24 03:59:20 katarynka volumio[18284]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 24 03:59:21 katarynka volumio[18284]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 24 03:59:21 katarynka volumio[18284]: info: CoreCommandRouter::initPlayerControls Mar 24 03:59:21 katarynka volumio[18284]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 03:59:21 katarynka volumio[18284]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 03:59:21 katarynka volumio[18284]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 03:59:21 katarynka volumio[18284]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 03:59:21 katarynka volumio[18284]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 03:59:21 katarynka volumio[18284]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 03:59:21 katarynka volumio[18284]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 03:59:21 katarynka volumio[18284]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 03:59:21 katarynka go-librespot[18386]: time="2026-03-24T03:59:21+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Mar 24 03:59:21 katarynka go-librespot[18386]: time="2026-03-24T03:59:21+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 24 03:59:21 katarynka go-librespot[18386]: time="2026-03-24T03:59:21+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 24 03:59:21 katarynka volumio[18284]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 24 03:59:21 katarynka volumio[18284]: Express server listening on port 3000 Mar 24 03:59:21 katarynka volumio[18284]: [Metrics] WebUI: 12s 486.53ms Mar 24 03:59:21 katarynka go-librespot[18386]: time="2026-03-24T03:59:21+01:00" level=info msg="zeroconf server listening on port 42933" Mar 24 03:59:21 katarynka volumio[18284]: info: CoreStateMachine::resetVolumioState Mar 24 03:59:21 katarynka volumio[18284]: info: CoreStateMachine::getcurrentVolume Mar 24 03:59:21 katarynka volumio[18284]: info: CoreCommandRouter::volumioRetrievevolume Mar 24 03:59:21 katarynka volumio[18284]: info: Cannot read play queue from file Mar 24 03:59:21 katarynka go-librespot[18386]: time="2026-03-24T03:59:21+01:00" level=debug msg="obtained new client token: AADh1DMtgY/eWSiCrZtv31clF6iPHJmg0xqFdBlIIUoH1MAtZwHT1lFNq3v0v74WSViTs1/CGtKKR7YyynvuZkSH3EcBUtAIdTwnNU8QQ3a09K0poMNR2Gq9CZWkN9cW6Omnmyf5B36bKt7rzWpmMBny/uIiPCjL704wpV0wDtLLqxvbiJoLJtpRzzJPAhmTFH+UFHEuvI7JTRjLIFm4A43bJnHYE5u3HhlMA9Mkspw3mCuRzFWrOaZwkXo=" Mar 24 03:59:21 katarynka volumio[18284]: info: Volumio Network Manager: Network status updated: 2 Mar 24 03:59:21 katarynka go-librespot[18386]: time="2026-03-24T03:59:21+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 24 03:59:21 katarynka go-librespot[18386]: time="2026-03-24T03:59:21+01:00" level=debug msg="completed keyexchange" Mar 24 03:59:21 katarynka go-librespot[18386]: time="2026-03-24T03:59:21+01:00" level=debug msg="completed challenge" Mar 24 03:59:21 katarynka volumio[18375]: Forking 3 albumart workers Mar 24 03:59:21 katarynka go-librespot[18386]: time="2026-03-24T03:59:21+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 24 03:59:21 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 24 03:59:21 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 24 03:59:21 katarynka volumio[18284]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 24 03:59:21 katarynka volumio[18284]: info: CoreStateMachine::setRepeat null single undefined Mar 24 03:59:21 katarynka volumio[18284]: info: CoreStateMachine::pushState Mar 24 03:59:21 katarynka volumio[18284]: info: CorePlayQueue::getTrack 0 Mar 24 03:59:21 katarynka volumio[18284]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 24 03:59:21 katarynka volumio[18284]: info: CoreCommandRouter::volumioPushState Mar 24 03:59:21 katarynka volumio[18284]: info: CoreStateMachine::setRandom null Mar 24 03:59:21 katarynka volumio[18284]: info: CoreStateMachine::pushState Mar 24 03:59:21 katarynka volumio[18284]: info: CorePlayQueue::getTrack 0 Mar 24 03:59:21 katarynka volumio[18284]: info: CoreCommandRouter::volumioPushState Mar 24 03:59:21 katarynka volumio[18284]: info: Setting Device type: Raspberry PI Mar 24 03:59:21 katarynka volumio[18284]: info: Completed loading Core Plugins Mar 24 03:59:21 katarynka volumio[18284]: info: Preparing to generate the ALSA configuration file Mar 24 03:59:22 katarynka volumio[18284]: info: VolumeController:: Volume=96 Mute =false Mar 24 03:59:22 katarynka volumio[18284]: info: CoreStateMachine::pushState Mar 24 03:59:22 katarynka volumio[18284]: info: CorePlayQueue::getTrack 0 Mar 24 03:59:22 katarynka volumio[18284]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 24 03:59:22 katarynka volumio[18284]: info: CoreCommandRouter::volumioPushState Mar 24 03:59:22 katarynka volumio[18284]: info: CoreStateMachine::updateTrackBlock Mar 24 03:59:22 katarynka volumio[18284]: info: CorePlayQueue::getTrackBlock Mar 24 03:59:22 katarynka volumio[18284]: info: CoreCommandRouter::volumioRetrievevolume Mar 24 03:59:22 katarynka volumio[18284]: info: Asound.conf file unchanged, so no further update is needed Mar 24 03:59:22 katarynka volumio[18284]: info: Output device has changed, restarting MPD Mar 24 03:59:22 katarynka volumio[18284]: info: Output device has changed, restarting Shairport Sync Mar 24 03:59:22 katarynka volumio[18284]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 03:59:22 katarynka volumio[18284]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 24 03:59:22 katarynka sudo[18436]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 24 03:59:22 katarynka sudo[18436]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 03:59:22 katarynka volumio[18284]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 24 03:59:22 katarynka volumio[18284]: info: ___________ START PLUGINS ___________ Mar 24 03:59:22 katarynka sudo[18436]: pam_unix(sudo:session): session closed for user root Mar 24 03:59:22 katarynka sudo[18438]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 24 03:59:22 katarynka volumio[18284]: info: ControllerMpd::onStart: Initializing MPD Mar 24 03:59:22 katarynka volumio[18284]: info: Creating MPD Configuration file Mar 24 03:59:22 katarynka sudo[18438]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 03:59:22 katarynka volumio[18284]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 24 03:59:22 katarynka volumio[18284]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 24 03:59:22 katarynka volumio[18284]: info: [1774321162352] CoreMusicLibrary::Adding element Serwery Mediów Mar 24 03:59:22 katarynka volumio[18284]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 24 03:59:22 katarynka sudo[18446]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 24 03:59:22 katarynka sudo[18446]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 03:59:22 katarynka sudo[18446]: pam_unix(sudo:session): session closed for user root Mar 24 03:59:22 katarynka volumio[18284]: info: UPNP Browser: Client initialized successfully Mar 24 03:59:22 katarynka sudo[18448]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 24 03:59:22 katarynka sudo[18448]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 03:59:22 katarynka systemd[1]: Stopping mpd.service - Music Player Daemon... Mar 24 03:59:22 katarynka volumio[18284]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 03:59:22 katarynka volumio[18284]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 24 03:59:22 katarynka systemd[1]: mpd.service: Deactivated successfully. Mar 24 03:59:22 katarynka systemd[1]: Stopped mpd.service - Music Player Daemon. Mar 24 03:59:22 katarynka systemd[1]: mpd.service: Consumed 7.769s CPU time. Mar 24 03:59:22 katarynka systemd[1]: mpd.socket: Deactivated successfully. Mar 24 03:59:22 katarynka systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Mar 24 03:59:22 katarynka systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Mar 24 03:59:22 katarynka volumio[18284]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 24 03:59:22 katarynka volumio[18284]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 03:59:22 katarynka volumio[18284]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 24 03:59:22 katarynka volumio[18284]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 24 03:59:22 katarynka volumio[18284]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 24 03:59:22 katarynka systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Mar 24 03:59:22 katarynka volumio[18284]: info: [1774321162682] CoreMusicLibrary::Adding element Last_100 Mar 24 03:59:22 katarynka volumio[18284]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 24 03:59:22 katarynka systemd[1]: Starting mpd.service - Music Player Daemon... Mar 24 03:59:22 katarynka volumio[18284]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 24 03:59:22 katarynka volumio[18284]: info: [1774321162723] CoreMusicLibrary::Adding element Webradio Mar 24 03:59:22 katarynka volumio[18284]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 24 03:59:22 katarynka volumio[18284]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 24 03:59:22 katarynka volumio[18284]: info: Initializing BBC Radios Mar 24 03:59:22 katarynka volumio[18284]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 24 03:59:22 katarynka volumio[18284]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 24 03:59:23 katarynka volumio[18284]: info: Creating Spotify config file Mar 24 03:59:23 katarynka volumio[18284]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 03:59:23 katarynka sudo[18460]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Mar 24 03:59:23 katarynka sudo[18460]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Mar 24 03:59:23 katarynka sudo[18460]: pam_unix(sudo:session): session closed for user root Mar 24 03:59:23 katarynka volumio-remote-updater[622]: [2026-03-24 03:59:23] [connect] Successful connection Mar 24 03:59:24 katarynka volumio[18284]: info: Volumio Calling Home Mar 24 03:59:24 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Mar 24 03:59:24 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 24 03:59:25 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 24 03:59:25 katarynka go-librespot[18494]: go-librespot daemon starting... Mar 24 03:59:25 katarynka go-librespot[18495]: time="2026-03-24T03:59:25+01:00" level=info msg="running go-librespot 0.4.0" Mar 24 03:59:25 katarynka volumio[18399]: Starting albumart workers Mar 24 03:59:25 katarynka volumio[18284]: info: Discovery: adding 4d616d77-6a8c-4da2-85a4-840d70f98e51 Mar 24 03:59:25 katarynka volumio[18284]: info: Discovery: Found device katarynka Mar 24 03:59:25 katarynka volumio[18284]: info: CoreCommandRouter::volumioGetState Mar 24 03:59:25 katarynka volumio[18284]: info: CorePlayQueue::getTrack 0 Mar 24 03:59:25 katarynka sudo[18502]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 24 03:59:25 katarynka sudo[18502]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 03:59:25 katarynka volumio[18284]: info: Discovery: this is already registered, 4d616d77-6a8c-4da2-85a4-840d70f98e51 Mar 24 03:59:25 katarynka volumio[18284]: info: Discovery: Found device katarynka Mar 24 03:59:25 katarynka volumio[18284]: info: CoreCommandRouter::volumioGetState Mar 24 03:59:25 katarynka volumio[18284]: info: CorePlayQueue::getTrack 0 Mar 24 03:59:25 katarynka volumio[18397]: Starting albumart workers Mar 24 03:59:25 katarynka sudo[18504]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 24 03:59:25 katarynka sudo[18504]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 03:59:25 katarynka sudo[18502]: pam_unix(sudo:session): session closed for user root Mar 24 03:59:25 katarynka sudo[18504]: pam_unix(sudo:session): session closed for user root Mar 24 03:59:25 katarynka volumio[18284]: info: MPD Permissions set Mar 24 03:59:25 katarynka volumio[18284]: info: MPD Permissions set Mar 24 03:59:25 katarynka go-librespot[18495]: time="2026-03-24T03:59:25+01:00" level=info msg="zeroconf server listening on port 40149" Mar 24 03:59:25 katarynka volumio-remote-updater[622]: [2026-03-24 03:59:25] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1774321163 101 Mar 24 03:59:25 katarynka volumio[18284]: 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 24 03:59:25 katarynka volumio[18284]: info: Volumio called home Mar 24 03:59:25 katarynka volumio[18284]: info: Spotify config file written Mar 24 03:59:25 katarynka volumio[18398]: Starting albumart workers Mar 24 03:59:26 katarynka sudo[18511]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Mar 24 03:59:26 katarynka sudo[18511]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 03:59:26 katarynka volumio[18284]: 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 24 03:59:26 katarynka volumio[18284]: info: VolumeController:: Volume=96 Mute =false Mar 24 03:59:26 katarynka volumio[18284]: info: CoreStateMachine::pushState Mar 24 03:59:26 katarynka volumio[18284]: info: CorePlayQueue::getTrack 0 Mar 24 03:59:26 katarynka volumio[18284]: info: CoreCommandRouter::volumioPushState Mar 24 03:59:26 katarynka volumio[18284]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 03:59:26 katarynka volumio[18284]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 03:59:26 katarynka volumio[18284]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 03:59:26 katarynka volumio[18284]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 03:59:26 katarynka volumio[18284]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 03:59:26 katarynka volumio[18284]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 03:59:26 katarynka volumio[18284]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 03:59:26 katarynka volumio[18284]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 03:59:26 katarynka systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Mar 24 03:59:26 katarynka systemd[1]: go-librespot-daemon.service: Killing process 18497 (go-librespot) with signal SIGKILL. Mar 24 03:59:26 katarynka systemd[1]: go-librespot-daemon.service: Deactivated successfully. Mar 24 03:59:26 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 24 03:59:26 katarynka volumio[18284]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 24 03:59:26 katarynka volumio[18284]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 03:59:26 katarynka volumio[18284]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 03:59:26 katarynka volumio[18284]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 03:59:26 katarynka volumio[18284]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 03:59:26 katarynka volumio[18284]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 03:59:26 katarynka volumio[18284]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 03:59:26 katarynka volumio[18284]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 03:59:26 katarynka volumio[18284]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 03:59:26 katarynka volumio[18284]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 03:59:26 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 24 03:59:26 katarynka go-librespot[18518]: go-librespot daemon starting... Mar 24 03:59:26 katarynka sudo[18511]: pam_unix(sudo:session): session closed for user root Mar 24 03:59:26 katarynka go-librespot[18520]: time="2026-03-24T03:59:26+01:00" level=info msg="running go-librespot 0.4.0" Mar 24 03:59:26 katarynka go-librespot[18520]: time="2026-03-24T03:59:26+01:00" level=debug msg="app state loaded" Mar 24 03:59:26 katarynka go-librespot[18520]: time="2026-03-24T03:59:26+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 24 03:59:26 katarynka volumio[18284]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 24 03:59:26 katarynka volumio[18284]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 03:59:26 katarynka volumio[18284]: info: No need to fix Spotify hosts Mar 24 03:59:26 katarynka go-librespot[18520]: time="2026-03-24T03:59:26+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Mar 24 03:59:26 katarynka go-librespot[18520]: time="2026-03-24T03:59:26+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Mar 24 03:59:26 katarynka go-librespot[18520]: time="2026-03-24T03:59:26+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Mar 24 03:59:27 katarynka go-librespot[18520]: time="2026-03-24T03:59:27+01:00" level=info msg="zeroconf server listening on port 43719" Mar 24 03:59:27 katarynka go-librespot[18520]: time="2026-03-24T03:59:27+01:00" level=debug msg="obtained new client token: AAAkV2isH0nbA/YbaqjXDyCS23Ys8Cq4rrrJHca7+VCKt49SamUBE9TIrya8m+WTa/ZvQZp5IUBFTGpw2TYhaIMvDmjVZDL1SoBiDpUely/hDsyxlmNTSrKxuUF1BK4tkHOTBQ3W9J6/KcKr2OjR9qKA6nqxndgzqLcp8dDGJV7U0LFRteg/KE01kM1aeaQqwN18gVtasqbhn+LxIw+q6LAW1IwyCjuKaN9cfjvofu/xrxbOMEfJUa0o" Mar 24 03:59:27 katarynka go-librespot[18520]: time="2026-03-24T03:59:27+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 24 03:59:27 katarynka go-librespot[18520]: time="2026-03-24T03:59:27+01:00" level=debug msg="completed keyexchange" Mar 24 03:59:27 katarynka go-librespot[18520]: time="2026-03-24T03:59:27+01:00" level=debug msg="completed challenge" Mar 24 03:59:27 katarynka volumio[18284]: info: Starting Shairport Sync Mar 24 03:59:27 katarynka go-librespot[18520]: time="2026-03-24T03:59: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 24 03:59:27 katarynka volumio[18284]: info: Starting Shairport Sync Mar 24 03:59:27 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 24 03:59:27 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 24 03:59:27 katarynka sudo[18532]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 24 03:59:27 katarynka sudo[18532]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 03:59:27 katarynka volumio[18284]: info: Starting Shairport Sync Mar 24 03:59:27 katarynka systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Mar 24 03:59:27 katarynka systemd[1]: shairport-sync.service: Deactivated successfully. Mar 24 03:59:27 katarynka systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 24 03:59:27 katarynka systemd[1]: shairport-sync.service: Consumed 2.400s CPU time. Mar 24 03:59:27 katarynka systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 24 03:59:27 katarynka sudo[18532]: pam_unix(sudo:session): session closed for user root Mar 24 03:59:27 katarynka sudo[18535]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 24 03:59:27 katarynka sudo[18535]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 03:59:27 katarynka sudo[18537]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 24 03:59:27 katarynka sudo[18537]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 03:59:27 katarynka sudo[18540]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Mar 24 03:59:27 katarynka sudo[18540]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 03:59:28 katarynka volumio[18284]: info: Shairport-Sync Started Mar 24 03:59:28 katarynka volumio[18284]: Error adding Membership: Error: addMembership EINVAL Mar 24 03:59:28 katarynka systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Mar 24 03:59:28 katarynka systemd[1]: shairport-sync.service: Deactivated successfully. Mar 24 03:59:28 katarynka systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 24 03:59:28 katarynka volumio[18284]: info: An error occurred while refreshing Spotify Token Error: Bad Request Mar 24 03:59:28 katarynka volumio[18284]: info: CoreCommandRouter::volumioGetState Mar 24 03:59:28 katarynka volumio[18284]: info: CorePlayQueue::getTrack 0 Mar 24 03:59:28 katarynka systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 24 03:59:28 katarynka sudo[18535]: pam_unix(sudo:session): session closed for user root Mar 24 03:59:28 katarynka sudo[18537]: pam_unix(sudo:session): session closed for user root Mar 24 03:59:28 katarynka sudo[18540]: pam_unix(sudo:session): session closed for user root Mar 24 03:59:28 katarynka volumio[18284]: info: Upmpdcli Daemon Started Mar 24 03:59:28 katarynka volumio[18284]: info: Shairport-Sync Started Mar 24 03:59:28 katarynka volumio[18284]: info: Shairport-Sync Started Mar 24 03:59:30 katarynka volumio[18284]: info: go-librespot daemon successfully initialized Mar 24 03:59:30 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Mar 24 03:59:30 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 24 03:59:30 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 24 03:59:30 katarynka go-librespot[18592]: go-librespot daemon starting... Mar 24 03:59:30 katarynka go-librespot[18593]: time="2026-03-24T03:59:30+01:00" level=info msg="running go-librespot 0.4.0" Mar 24 03:59:30 katarynka go-librespot[18593]: time="2026-03-24T03:59:30+01:00" level=debug msg="app state loaded" Mar 24 03:59:30 katarynka go-librespot[18593]: time="2026-03-24T03:59:30+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 24 03:59:31 katarynka mpd[18476]: 2026-03-24T03:59:31 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Mar 24 03:59:31 katarynka systemd[1]: Started mpd.service - Music Player Daemon. Mar 24 03:59:31 katarynka sudo[18448]: pam_unix(sudo:session): session closed for user root Mar 24 03:59:31 katarynka sudo[18438]: pam_unix(sudo:session): session closed for user root Mar 24 03:59:31 katarynka volumio[18284]: info: Completed starting Core Plugins Mar 24 03:59:31 katarynka volumio[18284]: info: ------------------------------------------- Mar 24 03:59:31 katarynka volumio[18284]: info: ----- MyVolumio plugins startup ---- Mar 24 03:59:31 katarynka volumio[18284]: info: ------------------------------------------- Mar 24 03:59:31 katarynka volumio[18284]: info: [MyVolumio PluginManager] Fetching plans data.... Mar 24 03:59:31 katarynka go-librespot[18593]: time="2026-03-24T03:59: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 24 03:59:31 katarynka go-librespot[18593]: time="2026-03-24T03:59: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 24 03:59:31 katarynka go-librespot[18593]: time="2026-03-24T03:59: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 24 03:59:31 katarynka go-librespot[18593]: time="2026-03-24T03:59:31+01:00" level=info msg="zeroconf server listening on port 36549" Mar 24 03:59:31 katarynka go-librespot[18593]: time="2026-03-24T03:59:31+01:00" level=debug msg="obtained new client token: AAA7Fp/HE4MGopxMZKWVgE43rdmAYnLiRnM6BlThs3xPAYZ83M/QAy5kbd2uEAmVzbmWkkothRazNOgTJK5R1AKcsUvDBnfyS6sp8n0m79MfnINTz60k8Htx9RQCq2l0UBpLOR+8S5xETCEsAeFX93czrVmBflgrZ/kPSZakE5qaOlK2MC/SR+do2cGQqz00Db8PkBOwnFu/must9J5R6xv05tHI3w9mnzT+UBL6GgpD4KlX3cPY0sfi2mU=" Mar 24 03:59:31 katarynka volumio[18284]: error: MPD error: The expression evaluated to a falsy value: Mar 24 03:59:31 katarynka volumio[18284]: assert.ok(self.idling) Mar 24 03:59:31 katarynka volumio[18284]: error: The expression evaluated to a falsy value: Mar 24 03:59:31 katarynka volumio[18284]: assert.ok(self.idling) Mar 24 03:59:31 katarynka volumio[18284]: error: updateQueue error: null Mar 24 03:59:31 katarynka volumio[18284]: info: MPD running with PID18476 Mar 24 03:59:31 katarynka volumio[18284]: ,establishing connection Mar 24 03:59:31 katarynka volumio[18284]: error: updateQueue error: null Mar 24 03:59:31 katarynka go-librespot[18593]: time="2026-03-24T03:59:31+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 24 03:59:31 katarynka go-librespot[18593]: time="2026-03-24T03:59:31+01:00" level=debug msg="completed keyexchange" Mar 24 03:59:31 katarynka go-librespot[18593]: time="2026-03-24T03:59:31+01:00" level=debug msg="completed challenge" Mar 24 03:59:31 katarynka go-librespot[18593]: time="2026-03-24T03:59:31+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 24 03:59:31 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 24 03:59:31 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 24 03:59:33 katarynka volumio[18284]: info: Initializing connection to go-librespot Websocket Mar 24 03:59:33 katarynka volumio[18284]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 24 03:59:34 katarynka sudo[18622]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Mar 24 03:59:34 katarynka sudo[18622]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 03:59:34 katarynka sudo[18625]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Mar 24 03:59:34 katarynka sudo[18625]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 03:59:34 katarynka systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Mar 24 03:59:34 katarynka systemd[1]: mpd_monitor.service: Deactivated successfully. Mar 24 03:59:34 katarynka systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Mar 24 03:59:34 katarynka systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Mar 24 03:59:34 katarynka sudo[18622]: pam_unix(sudo:session): session closed for user root Mar 24 03:59:34 katarynka mpd_monitor.sh[18627]: MPD Monitor Service: Starting MPD Monitor Service Mar 24 03:59:34 katarynka volumio[18284]: info: Successfully started MPD Monitor Mar 24 03:59:34 katarynka systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Mar 24 03:59:34 katarynka systemd[1]: mpd_monitor.service: Deactivated successfully. Mar 24 03:59:34 katarynka systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Mar 24 03:59:34 katarynka systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Mar 24 03:59:34 katarynka sudo[18625]: pam_unix(sudo:session): session closed for user root Mar 24 03:59:34 katarynka mpd_monitor.sh[18631]: MPD Monitor Service: Starting MPD Monitor Service Mar 24 03:59:34 katarynka volumio[18284]: info: Successfully started MPD Monitor Mar 24 03:59:34 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Mar 24 03:59:34 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 24 03:59:34 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 24 03:59:34 katarynka go-librespot[18635]: go-librespot daemon starting... Mar 24 03:59:34 katarynka go-librespot[18636]: time="2026-03-24T03:59:34+01:00" level=info msg="running go-librespot 0.4.0" Mar 24 03:59:34 katarynka go-librespot[18636]: time="2026-03-24T03:59:34+01:00" level=debug msg="app state loaded" Mar 24 03:59:34 katarynka go-librespot[18636]: time="2026-03-24T03:59:34+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 24 03:59:35 katarynka go-librespot[18636]: time="2026-03-24T03:59:35+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 24 03:59:35 katarynka go-librespot[18636]: time="2026-03-24T03:59:35+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 24 03:59:35 katarynka go-librespot[18636]: time="2026-03-24T03:59:35+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 24 03:59:35 katarynka go-librespot[18636]: time="2026-03-24T03:59:35+01:00" level=info msg="zeroconf server listening on port 39289" Mar 24 03:59:35 katarynka go-librespot[18636]: time="2026-03-24T03:59:35+01:00" level=debug msg="obtained new client token: AABxSTCW/Ekc+dWONVpUXe0n+cK6yb7vAovkrh6jdeP3IF9DEROQOsd8MRDid4IXbkIm/O9CBIi8EXLGuY+AU8ulyqgQg8n8pbIWHOmJijouXJGR4FrFbToNtdvYFfr0K6smb7siEKc1o0+J+L2iOxO8kpBLltZT0ieycdBtalaUEosYcqB2nUOQFgi+y1IbV/+tObHKCE3xtOumQ80eXZHCYMUErMusIt8NhcZ/pC9xR8ovpnKn1rlaezs=" Mar 24 03:59:35 katarynka go-librespot[18636]: time="2026-03-24T03:59:35+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 24 03:59:35 katarynka go-librespot[18636]: time="2026-03-24T03:59:35+01:00" level=debug msg="completed keyexchange" Mar 24 03:59:35 katarynka go-librespot[18636]: time="2026-03-24T03:59:35+01:00" level=debug msg="completed challenge" Mar 24 03:59:35 katarynka go-librespot[18636]: time="2026-03-24T03:59:35+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 24 03:59:35 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 24 03:59:35 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 24 03:59:36 katarynka volumio[18284]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Mar 24 03:59:36 katarynka volumio[18284]: info: Initializing connection to go-librespot Websocket Mar 24 03:59:36 katarynka volumio[18284]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 24 03:59:38 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Mar 24 03:59:38 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 24 03:59:38 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 24 03:59:38 katarynka go-librespot[18643]: go-librespot daemon starting... Mar 24 03:59:38 katarynka go-librespot[18644]: time="2026-03-24T03:59:38+01:00" level=info msg="running go-librespot 0.4.0" Mar 24 03:59:38 katarynka go-librespot[18644]: time="2026-03-24T03:59:38+01:00" level=debug msg="app state loaded" Mar 24 03:59:38 katarynka go-librespot[18644]: time="2026-03-24T03:59:38+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 24 03:59:39 katarynka go-librespot[18644]: time="2026-03-24T03:59:39+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 24 03:59:39 katarynka go-librespot[18644]: time="2026-03-24T03:59:39+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 24 03:59:39 katarynka go-librespot[18644]: time="2026-03-24T03:59:39+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 24 03:59:39 katarynka go-librespot[18644]: time="2026-03-24T03:59:39+01:00" level=info msg="zeroconf server listening on port 36039" Mar 24 03:59:39 katarynka go-librespot[18644]: time="2026-03-24T03:59:39+01:00" level=debug msg="obtained new client token: AADBiM0NFm3Vz7GzYxQSfyCrcpQsujgTK8/LulxuQE2FwFh82LCI/cFS6UwNq7HkbAzsJzWcneu3H+zgfh7xGXmguLaZHU3r5F3/yXLYaBnzoM/q8q910J+otOmHWksl3GYAhSz0PRFRAx6BblfhLLWzYtkAF+OvUydB84+kJCsUvss1ZWr3gk7xTSoDq0WGIVyBoR9MsnwUxx2LrueXlaE++tA+mnuCbkdI/X0W/mMSNY0G0sLP1M+TT18=" Mar 24 03:59:39 katarynka go-librespot[18644]: time="2026-03-24T03:59:39+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 24 03:59:39 katarynka volumio[18284]: info: Initializing connection to go-librespot Websocket Mar 24 03:59:39 katarynka go-librespot[18644]: time="2026-03-24T03:59:39+01:00" level=debug msg="new websocket client" Mar 24 03:59:39 katarynka volumio[18284]: info: Connection to go-librespot Websocket established Mar 24 03:59:39 katarynka go-librespot[18644]: time="2026-03-24T03:59:39+01:00" level=debug msg="completed keyexchange" Mar 24 03:59:39 katarynka go-librespot[18644]: time="2026-03-24T03:59:39+01:00" level=debug msg="completed challenge" Mar 24 03:59:39 katarynka go-librespot[18644]: time="2026-03-24T03:59:39+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 24 03:59:39 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 24 03:59:39 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 24 03:59:39 katarynka volumio[18284]: info: Connection to go-librespot Websocket closed Mar 24 03:59:39 katarynka volumio[18284]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Mar 24 03:59:39 katarynka volumio[18284]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Mar 24 03:59:39 katarynka volumio[18284]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Mar 24 03:59:39 katarynka volumio[18284]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Mar 24 03:59:39 katarynka volumio[18284]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Mar 24 03:59:39 katarynka volumio[18284]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Mar 24 03:59:39 katarynka volumio[18284]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Mar 24 03:59:39 katarynka volumio[18284]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Mar 24 03:59:39 katarynka volumio[18284]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Mar 24 03:59:39 katarynka volumio[18284]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Mar 24 03:59:39 katarynka volumio[18284]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Mar 24 03:59:39 katarynka volumio[18284]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Mar 24 03:59:39 katarynka volumio[18284]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Mar 24 03:59:39 katarynka volumio[18284]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Mar 24 03:59:39 katarynka volumio[18284]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Mar 24 03:59:39 katarynka volumio[18284]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Mar 24 03:59:39 katarynka volumio[18284]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Mar 24 03:59:39 katarynka volumio[18284]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Mar 24 03:59:39 katarynka volumio[18284]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Mar 24 03:59:39 katarynka volumio[18284]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Mar 24 03:59:39 katarynka volumio[18284]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Mar 24 03:59:39 katarynka volumio[18284]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Mar 24 03:59:39 katarynka volumio[18284]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Mar 24 03:59:39 katarynka volumio[18284]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Mar 24 03:59:39 katarynka volumio[18284]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Mar 24 03:59:39 katarynka volumio[18284]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Mar 24 03:59:39 katarynka volumio[18284]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Mar 24 03:59:39 katarynka volumio[18284]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Mar 24 03:59:39 katarynka volumio[18284]: info: Adding plugin bluetooth to MyMusic Plugins Mar 24 03:59:39 katarynka volumio[18284]: info: Adding plugin multiroom to MyMusic Plugins Mar 24 03:59:39 katarynka volumio[18284]: info: Adding plugin metavolumio to MyMusic Plugins Mar 24 03:59:39 katarynka volumio[18284]: info: Adding plugin cd_controller to MyMusic Plugins Mar 24 03:59:39 katarynka volumio[18284]: info: Adding plugin qobuzconnect to MyMusic Plugins Mar 24 03:59:39 katarynka volumio[18284]: info: Adding plugin smart_inputs to MyMusic Plugins Mar 24 03:59:39 katarynka volumio[18284]: info: Adding plugin tidalconnect to MyMusic Plugins Mar 24 03:59:39 katarynka volumio[18284]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Mar 24 03:59:41 katarynka volumio[18284]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Mar 24 03:59:41 katarynka volumio[18284]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Mar 24 03:59:41 katarynka volumio[18284]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 24 03:59:41 katarynka volumio[18284]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 24 03:59:41 katarynka volumio[18284]: info: Starting MyVolumio Remote Streaming Endpoints Mar 24 03:59:41 katarynka volumio[18284]: info: MyVolumio login type: Token Mar 24 03:59:41 katarynka volumio[18284]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Mar 24 03:59:41 katarynka volumio[18284]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Mar 24 03:59:42 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Mar 24 03:59:42 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 24 03:59:42 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 24 03:59:42 katarynka go-librespot[18651]: go-librespot daemon starting... Mar 24 03:59:42 katarynka go-librespot[18652]: time="2026-03-24T03:59:42+01:00" level=info msg="running go-librespot 0.4.0" Mar 24 03:59:42 katarynka go-librespot[18652]: time="2026-03-24T03:59:42+01:00" level=debug msg="app state loaded" Mar 24 03:59:42 katarynka go-librespot[18652]: time="2026-03-24T03:59:42+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 24 03:59:43 katarynka go-librespot[18652]: time="2026-03-24T03:59:43+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 24 03:59:43 katarynka go-librespot[18652]: time="2026-03-24T03:59:43+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 24 03:59:43 katarynka go-librespot[18652]: time="2026-03-24T03:59:43+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 24 03:59:43 katarynka go-librespot[18652]: time="2026-03-24T03:59:43+01:00" level=info msg="zeroconf server listening on port 36651" Mar 24 03:59:43 katarynka go-librespot[18652]: time="2026-03-24T03:59:43+01:00" level=debug msg="obtained new client token: AADSQe+Lq7snaFK+cotALn57q/SI4oORCnvl8QJHf26zMbaymJ9XLA2U/L/h77Va/F72yE1hPUEaEkTp3dMWNPxXO1ypWDbRbOxQR+q7qIIBiVanNsZ7ucneSBhUXmmGKu9jdTnCc6BxoqGAcL1O+m3Ih8WbfdOf2QCdvwBlOB/f+8o64xubsqRR79EJ9+lvh9/Io4ZtuwMELpsR3FAN8ne94rgVj+9ebvl50iv7+sxK9KODq0hLC2cFpBU=" Mar 24 03:59:43 katarynka go-librespot[18652]: time="2026-03-24T03:59:43+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 24 03:59:43 katarynka volumio[18284]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Mar 24 03:59:43 katarynka volumio[18284]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Mar 24 03:59:43 katarynka volumio[18284]: info: Streaming services startup Mar 24 03:59:43 katarynka volumio[18284]: info: Starting Streaming Daemon Mar 24 03:59:43 katarynka sudo[18660]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Mar 24 03:59:43 katarynka sudo[18660]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 24 03:59:43 katarynka volumio[18284]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Mar 24 03:59:43 katarynka sudo[18660]: pam_unix(sudo:session): session closed for user root Mar 24 03:59:43 katarynka volumio[18284]: info: Getting Spotify volume Mar 24 03:59:43 katarynka volumio[18284]: info: Initializing connection to go-librespot Websocket Mar 24 03:59:43 katarynka volumio[18284]: error: Cannot start Volumio Streaming Daemon Mar 24 03:59:43 katarynka volumio[18284]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Mar 24 03:59:43 katarynka volumio[18284]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Mar 24 03:59:43 katarynka go-librespot[18652]: time="2026-03-24T03:59:43+01:00" level=debug msg="new websocket client" Mar 24 03:59:43 katarynka volumio[18284]: 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 24 03:59:43 katarynka volumio[18284]: info: Connection to go-librespot Websocket established Mar 24 03:59:44 katarynka volumio[18284]: info: CoreCommandRouter::volumioGetState Mar 24 03:59:44 katarynka volumio[18284]: info: CorePlayQueue::getTrack 0 Mar 24 03:59:44 katarynka volumio[18284]: SPOTIFY: RECEIVED VOLUMIO VOLUME 96 Mar 24 03:59:44 katarynka volumio[18284]: SPOTIFY: SPOTIFY VOLUME undefined Mar 24 03:59:44 katarynka volumio[18284]: SPOTIFY: VOLUMIO VOLUME 96 Mar 24 03:59:44 katarynka volumio[18284]: info: Aligning Spotify Volume to Volumio Volume Mar 24 03:59:44 katarynka volumio[18284]: info: CoreCommandRouter::volumioGetState Mar 24 03:59:44 katarynka volumio[18284]: info: CorePlayQueue::getTrack 0 Mar 24 03:59:44 katarynka volumio[18284]: info: Setting Spotify Volume from Volumio: 96 Mar 24 03:59:44 katarynka go-librespot[18652]: time="2026-03-24T03:59:44+01:00" level=debug msg="completed keyexchange" Mar 24 03:59:44 katarynka go-librespot[18652]: time="2026-03-24T03:59:44+01:00" level=debug msg="completed challenge" Mar 24 03:59:44 katarynka go-librespot[18652]: time="2026-03-24T03:59: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 24 03:59:44 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 24 03:59:44 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 24 03:59:44 katarynka volumio[18284]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 24 03:59:44 katarynka volumio[18284]: Error: socket hang up Mar 24 03:59:44 katarynka volumio[18284]: at connResetException (node:internal/errors:720:14) Mar 24 03:59:44 katarynka volumio[18284]: at Socket.socketOnEnd (node:_http_client:519:23) Mar 24 03:59:44 katarynka volumio[18284]: at Socket.emit (node:events:526:35) Mar 24 03:59:44 katarynka volumio[18284]: at endReadableNT (node:internal/streams/readable:1376:12) Mar 24 03:59:44 katarynka volumio[18284]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Mar 24 03:59:44 katarynka volumio[18284]: code: 'ECONNRESET', Mar 24 03:59:44 katarynka volumio[18284]: response: undefined Mar 24 03:59:44 katarynka volumio[18284]: } Mar 24 03:59:44 katarynka volumio[18284]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 24 03:59:45 katarynka sudo[18695]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-03-24 03:58' Mar 24 03:59:45 katarynka sudo[18695]: 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"