Mar 25 10:38:01 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Mar 25 10:38:01 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 10:38:02 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 10:38:02 katarynka go-librespot[511]: go-librespot daemon starting... Mar 25 10:38:02 katarynka go-librespot[512]: time="2026-03-25T10:38:02+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 10:38:02 katarynka go-librespot[512]: time="2026-03-25T10:38:02+01:00" level=debug msg="app state loaded" Mar 25 10:38:02 katarynka go-librespot[512]: time="2026-03-25T10:38:02+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 10:38:02 katarynka volumio[32629]: info: Initializing connection to go-librespot Websocket Mar 25 10:38:02 katarynka go-librespot[512]: time="2026-03-25T10:38:02+01:00" level=debug msg="new websocket client" Mar 25 10:38:02 katarynka volumio[32629]: info: Connection to go-librespot Websocket established Mar 25 10:38:02 katarynka go-librespot[512]: time="2026-03-25T10:38:02+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Mar 25 10:38:02 katarynka go-librespot[512]: time="2026-03-25T10:38:02+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Mar 25 10:38:02 katarynka go-librespot[512]: time="2026-03-25T10:38:02+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Mar 25 10:38:02 katarynka volumio[32629]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Mar 25 10:38:02 katarynka volumio[32629]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Mar 25 10:38:02 katarynka volumio[32629]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Mar 25 10:38:02 katarynka volumio[32629]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Mar 25 10:38:02 katarynka volumio[32629]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Mar 25 10:38:02 katarynka volumio[32629]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Mar 25 10:38:02 katarynka volumio[32629]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Mar 25 10:38:02 katarynka volumio[32629]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Mar 25 10:38:02 katarynka volumio[32629]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Mar 25 10:38:02 katarynka volumio[32629]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Mar 25 10:38:02 katarynka volumio[32629]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Mar 25 10:38:02 katarynka volumio[32629]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Mar 25 10:38:02 katarynka volumio[32629]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Mar 25 10:38:02 katarynka volumio[32629]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Mar 25 10:38:02 katarynka volumio[32629]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Mar 25 10:38:02 katarynka volumio[32629]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Mar 25 10:38:02 katarynka volumio[32629]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Mar 25 10:38:02 katarynka volumio[32629]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Mar 25 10:38:02 katarynka volumio[32629]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Mar 25 10:38:02 katarynka volumio[32629]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Mar 25 10:38:02 katarynka volumio[32629]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Mar 25 10:38:02 katarynka volumio[32629]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Mar 25 10:38:02 katarynka volumio[32629]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Mar 25 10:38:02 katarynka volumio[32629]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Mar 25 10:38:02 katarynka volumio[32629]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Mar 25 10:38:02 katarynka volumio[32629]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Mar 25 10:38:02 katarynka volumio[32629]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Mar 25 10:38:02 katarynka volumio[32629]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Mar 25 10:38:02 katarynka volumio[32629]: info: Adding plugin bluetooth to MyMusic Plugins Mar 25 10:38:02 katarynka volumio[32629]: info: Adding plugin multiroom to MyMusic Plugins Mar 25 10:38:02 katarynka go-librespot[512]: time="2026-03-25T10:38:02+01:00" level=info msg="zeroconf server listening on port 36075" Mar 25 10:38:02 katarynka volumio[32629]: info: Adding plugin metavolumio to MyMusic Plugins Mar 25 10:38:02 katarynka volumio[32629]: info: Adding plugin cd_controller to MyMusic Plugins Mar 25 10:38:02 katarynka volumio[32629]: info: Adding plugin qobuzconnect to MyMusic Plugins Mar 25 10:38:02 katarynka volumio[32629]: info: Adding plugin smart_inputs to MyMusic Plugins Mar 25 10:38:02 katarynka volumio[32629]: info: Adding plugin tidalconnect to MyMusic Plugins Mar 25 10:38:02 katarynka volumio[32629]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Mar 25 10:38:02 katarynka go-librespot[512]: time="2026-03-25T10:38:02+01:00" level=debug msg="obtained new client token: AAB7wAnn62xKrtY34dLEY0s0xo8BODSLUW63Htj35+xqMFRK/IucodpESkLH1FDBwv74R3kxVvTn6l1w59b943gzYMXpXVc5hJYncVJL+eRzi+bWGGadBsGTfez+Vqed4vtTWNPGWjKyUNmPqy2ot3a6FFwH0laJPblwz5UfT4y7F9NivavyvR8mDX9ILkSwnI+kfO3RySj5gswL/jg/1m9RBwN3mtDVcZPxPLNWbmSbWLMolxv8j5piQHc=" Mar 25 10:38:02 katarynka go-librespot[512]: time="2026-03-25T10:38:02+01:00" level=warning msg="failed to connect to AP ap-gew4.spotify.com:4070, retrying with a different AP" error="dial tcp 34.158.1.133:4070: connect: connection refused" Mar 25 10:38:02 katarynka go-librespot[512]: time="2026-03-25T10:38:02+01:00" level=debug msg="connected to ap-gew4.spotify.com:443" Mar 25 10:38:03 katarynka go-librespot[512]: time="2026-03-25T10:38:03+01:00" level=debug msg="completed keyexchange" Mar 25 10:38:03 katarynka go-librespot[512]: time="2026-03-25T10:38:03+01:00" level=debug msg="completed challenge" Mar 25 10:38:03 katarynka go-librespot[512]: time="2026-03-25T10:38:03+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 25 10:38:03 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 10:38:03 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 10:38:04 katarynka volumio[32629]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Mar 25 10:38:04 katarynka volumio[32629]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Mar 25 10:38:04 katarynka volumio[32629]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 10:38:04 katarynka volumio[32629]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 10:38:04 katarynka volumio[32629]: info: Starting MyVolumio Remote Streaming Endpoints Mar 25 10:38:04 katarynka volumio[32629]: info: MyVolumio login type: Token Mar 25 10:38:04 katarynka volumio[32629]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Mar 25 10:38:04 katarynka volumio[32629]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Mar 25 10:38:06 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Mar 25 10:38:06 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 10:38:06 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 10:38:06 katarynka go-librespot[520]: go-librespot daemon starting... Mar 25 10:38:06 katarynka go-librespot[521]: time="2026-03-25T10:38:06+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 10:38:06 katarynka go-librespot[521]: time="2026-03-25T10:38:06+01:00" level=debug msg="app state loaded" Mar 25 10:38:06 katarynka go-librespot[521]: time="2026-03-25T10:38:06+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 10:38:06 katarynka volumio[32629]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Mar 25 10:38:06 katarynka volumio[32629]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Mar 25 10:38:06 katarynka volumio[32629]: info: Streaming services startup Mar 25 10:38:06 katarynka volumio[32629]: info: Starting Streaming Daemon Mar 25 10:38:06 katarynka sudo[528]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Mar 25 10:38:06 katarynka sudo[528]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 10:38:06 katarynka volumio[32629]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Mar 25 10:38:06 katarynka sudo[528]: pam_unix(sudo:session): session closed for user root Mar 25 10:38:06 katarynka volumio[32629]: info: Getting Spotify volume Mar 25 10:38:06 katarynka volumio[32629]: info: Connection to go-librespot Websocket closed Mar 25 10:38:06 katarynka volumio[32629]: error: Cannot start Volumio Streaming Daemon Mar 25 10:38:06 katarynka volumio[32629]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Mar 25 10:38:06 katarynka volumio[32629]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Mar 25 10:38:06 katarynka volumio[32629]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Mar 25 10:38:06 katarynka go-librespot[521]: time="2026-03-25T10:38:06+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 25 10:38:06 katarynka go-librespot[521]: time="2026-03-25T10:38:06+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 25 10:38:06 katarynka go-librespot[521]: time="2026-03-25T10:38:06+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 25 10:38:06 katarynka go-librespot[521]: time="2026-03-25T10:38:06+01:00" level=info msg="zeroconf server listening on port 35741" Mar 25 10:38:06 katarynka go-librespot[521]: time="2026-03-25T10:38:06+01:00" level=debug msg="obtained new client token: AAA0eMNFeJZCRWuIeW2o97OsQ9mBIboFo2tt06ZceOWqmKhjz1jF4Q24fDXcEr/D5tjluylwZTjgx5S8qySWOc36s5Za2JUAMlSs7m8zxdJOk/jRpzjAFwYqLDa9XrSwpBpPqsIjY9qGDjZZgOC23kqxDjPROhRIlW6Zny23YqiVLU3N3uVa/KMfBDQ8cngDea736zU/SDCxL0BCypX9eiu0aos8Pgw4wigE91/RqU17xaky64pUYWGx/+Y=" Mar 25 10:38:06 katarynka volumio[32629]: info: CoreCommandRouter::volumioGetState Mar 25 10:38:06 katarynka volumio[32629]: info: CorePlayQueue::getTrack 0 Mar 25 10:38:06 katarynka volumio[32629]: SPOTIFY: RECEIVED VOLUMIO VOLUME 96 Mar 25 10:38:06 katarynka volumio[32629]: SPOTIFY: SPOTIFY VOLUME undefined Mar 25 10:38:06 katarynka volumio[32629]: SPOTIFY: VOLUMIO VOLUME 96 Mar 25 10:38:06 katarynka volumio[32629]: info: Aligning Spotify Volume to Volumio Volume Mar 25 10:38:06 katarynka volumio[32629]: info: CoreCommandRouter::volumioGetState Mar 25 10:38:06 katarynka volumio[32629]: info: CorePlayQueue::getTrack 0 Mar 25 10:38:06 katarynka volumio[32629]: info: Setting Spotify Volume from Volumio: 96 Mar 25 10:38:07 katarynka go-librespot[521]: time="2026-03-25T10:38:07+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 10:38:07 katarynka go-librespot[521]: time="2026-03-25T10:38:07+01:00" level=debug msg="completed keyexchange" Mar 25 10:38:07 katarynka go-librespot[521]: time="2026-03-25T10:38:07+01:00" level=debug msg="completed challenge" Mar 25 10:38:07 katarynka go-librespot[521]: time="2026-03-25T10:38:07+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 25 10:38:07 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 10:38:07 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 10:38:07 katarynka volumio[32629]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 25 10:38:07 katarynka volumio[32629]: Error: socket hang up Mar 25 10:38:07 katarynka volumio[32629]: at connResetException (node:internal/errors:720:14) Mar 25 10:38:07 katarynka volumio[32629]: at Socket.socketOnEnd (node:_http_client:519:23) Mar 25 10:38:07 katarynka volumio[32629]: at Socket.emit (node:events:526:35) Mar 25 10:38:07 katarynka volumio[32629]: at endReadableNT (node:internal/streams/readable:1376:12) Mar 25 10:38:07 katarynka volumio[32629]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Mar 25 10:38:07 katarynka volumio[32629]: code: 'ECONNRESET', Mar 25 10:38:07 katarynka volumio[32629]: response: undefined Mar 25 10:38:07 katarynka volumio[32629]: } Mar 25 10:38:07 katarynka volumio[32629]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 25 10:38:08 katarynka sudo[567]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-03-25 10:37' Mar 25 10:38:08 katarynka sudo[567]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 10:38:08 katarynka sudo[567]: pam_unix(sudo:session): session closed for user root Mar 25 10:38:09 katarynka volumio-remote-updater[622]: [2026-03-25 10:38:09] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Mar 25 10:38:09 katarynka volumio-remote-updater[622]: [2026-03-25 10:38:09] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Mar 25 10:38:09 katarynka systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Mar 25 10:38:09 katarynka systemd[1]: volumio.service: Failed with result 'exit-code'. Mar 25 10:38:09 katarynka systemd[1]: volumio.service: Consumed 49.241s CPU time. Mar 25 10:38:09 katarynka systemd[1]: Started dynamicswap.service - dynamicswap service. Mar 25 10:38:09 katarynka systemd[1]: dynamicswap.service: Deactivated successfully. Mar 25 10:38:09 katarynka systemd[1]: volumio.service: Scheduled restart job, restart counter is at 26289. Mar 25 10:38:09 katarynka systemd[1]: Started dynamicswap.service - dynamicswap service. Mar 25 10:38:09 katarynka systemd[1]: Stopped volumio.service - Volumio Backend Module. Mar 25 10:38:09 katarynka systemd[1]: volumio.service: Consumed 49.241s CPU time. Mar 25 10:38:09 katarynka systemd[1]: Started volumio.service - Volumio Backend Module. Mar 25 10:38:09 katarynka systemd[1]: dynamicswap.service: Deactivated successfully. Mar 25 10:38:10 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Mar 25 10:38:10 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 10:38:10 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 10:38:10 katarynka go-librespot[607]: go-librespot daemon starting... Mar 25 10:38:10 katarynka go-librespot[608]: time="2026-03-25T10:38:10+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 10:38:10 katarynka go-librespot[608]: time="2026-03-25T10:38:10+01:00" level=debug msg="app state loaded" Mar 25 10:38:10 katarynka go-librespot[608]: time="2026-03-25T10:38:10+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 10:38:10 katarynka go-librespot[608]: time="2026-03-25T10:38:10+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 25 10:38:10 katarynka go-librespot[608]: time="2026-03-25T10:38:10+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 25 10:38:10 katarynka go-librespot[608]: time="2026-03-25T10:38:10+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 25 10:38:10 katarynka go-librespot[608]: time="2026-03-25T10:38:10+01:00" level=info msg="zeroconf server listening on port 34467" Mar 25 10:38:10 katarynka go-librespot[608]: time="2026-03-25T10:38:10+01:00" level=debug msg="obtained new client token: AACV2S4UlCENwdFftKNA5dGwvsLO3v0WGtcFnf99zLAgxBKR8wDZw8QKgIdGkDdOLxwrG3tPcdPh5vLQBfo2Kl3hhaSDnNXwA7pKDCHfdV9UNi4iwIwUchw9NfHefl0UAvuXb47jkQxYuH6ELK4v9fFXNnvm/7BA9OAsDUir8xBcgOWIAYt0a1WxrJpOMkw8bfdqQv2A/h/3TyWg4MwIUIxU4X5IbkTY0pqUZ2AfNZXKLx6SwqzDupCDPt0=" Mar 25 10:38:10 katarynka go-librespot[608]: time="2026-03-25T10:38:10+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 10:38:11 katarynka go-librespot[608]: time="2026-03-25T10:38:11+01:00" level=debug msg="completed keyexchange" Mar 25 10:38:11 katarynka go-librespot[608]: time="2026-03-25T10:38:11+01:00" level=debug msg="completed challenge" Mar 25 10:38:11 katarynka go-librespot[608]: time="2026-03-25T10:38:11+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 25 10:38:11 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 10:38:11 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 10:38:13 katarynka volumio[589]: info: ------------------------------------------- Mar 25 10:38:13 katarynka volumio[589]: info: ----- Volumio3 ---- Mar 25 10:38:13 katarynka volumio[589]: info: ------------------------------------------- Mar 25 10:38:13 katarynka volumio[589]: info: ----- System startup ---- Mar 25 10:38:13 katarynka volumio[589]: info: ------------------------------------------- Mar 25 10:38:14 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Mar 25 10:38:14 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 10:38:14 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 10:38:14 katarynka go-librespot[627]: go-librespot daemon starting... Mar 25 10:38:14 katarynka go-librespot[628]: time="2026-03-25T10:38:14+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 10:38:14 katarynka go-librespot[628]: time="2026-03-25T10:38:14+01:00" level=debug msg="app state loaded" Mar 25 10:38:14 katarynka go-librespot[628]: time="2026-03-25T10:38:14+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 10:38:14 katarynka volumio-remote-updater[622]: [2026-03-25 10:38:14] [connect] Successful connection Mar 25 10:38:14 katarynka go-librespot[628]: time="2026-03-25T10:38:14+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Mar 25 10:38:14 katarynka go-librespot[628]: time="2026-03-25T10:38:14+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Mar 25 10:38:14 katarynka go-librespot[628]: time="2026-03-25T10:38:14+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Mar 25 10:38:14 katarynka go-librespot[628]: time="2026-03-25T10:38:14+01:00" level=info msg="zeroconf server listening on port 35951" Mar 25 10:38:14 katarynka volumio[589]: info: MYVOLUMIO Environment detected Mar 25 10:38:14 katarynka go-librespot[628]: time="2026-03-25T10:38:14+01:00" level=debug msg="obtained new client token: AADUQKz/l5vKuGr/nxaSPzJUT/t5xwZIvy9UCNy/gQghRiIHGXnqlymlKkKeI9qIB9SAT4VmZTizo+bKJbnsPOtJnISh9++R3bRAp5pu1+05wkMtmR0sHJ9LkLayYg/2KU+i9vllWxKDRhoOhqL5Vcr2t2DtkZUpcgNHegFOOW220Eq5ofUM/QE9UgEaubUhBUEzsY38k6rmb45v89vOatBsoAiGu9hHxsl14Gel1c40O+VuLn4JNQzyaHY=" Mar 25 10:38:15 katarynka volumio[589]: info: Plugin folders cleanup Mar 25 10:38:15 katarynka volumio[589]: info: Scanning into folder /volumio/app/plugins/ Mar 25 10:38:15 katarynka go-librespot[628]: time="2026-03-25T10:38:15+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 10:38:15 katarynka volumio[589]: info: Scanning category audio_interface Mar 25 10:38:15 katarynka volumio[589]: info: Scanning category miscellanea Mar 25 10:38:15 katarynka volumio[589]: info: Scanning category music_service Mar 25 10:38:15 katarynka volumio[589]: info: Scanning category plugins.json Mar 25 10:38:15 katarynka volumio[589]: info: Scanning category system_controller Mar 25 10:38:15 katarynka volumio[589]: info: Scanning category user_interface Mar 25 10:38:15 katarynka volumio[589]: info: Scanning into folder /data/plugins/ Mar 25 10:38:15 katarynka volumio[589]: info: Scanning category music_service Mar 25 10:38:15 katarynka volumio[589]: info: Plugin folders cleanup completed Mar 25 10:38:15 katarynka volumio[589]: info: ------------------------------------------- Mar 25 10:38:15 katarynka volumio[589]: info: ----- Core plugins startup ---- Mar 25 10:38:15 katarynka volumio[589]: info: ------------------------------------------- Mar 25 10:38:15 katarynka volumio[589]: info: Loading plugins from folder /volumio/app/plugins/ Mar 25 10:38:15 katarynka volumio[589]: info: Adding plugin upnp to MyMusic Plugins Mar 25 10:38:15 katarynka volumio[589]: info: Adding plugin airplay_emulation to MyMusic Plugins Mar 25 10:38:15 katarynka volumio[589]: info: Adding plugin upnp_browser to MyMusic Plugins Mar 25 10:38:15 katarynka volumio[589]: info: Loading plugins from folder /data/plugins/ Mar 25 10:38:15 katarynka volumio[589]: info: Loading plugin "system"... Mar 25 10:38:15 katarynka go-librespot[628]: time="2026-03-25T10:38:15+01:00" level=debug msg="completed keyexchange" Mar 25 10:38:15 katarynka go-librespot[628]: time="2026-03-25T10:38:15+01:00" level=debug msg="completed challenge" Mar 25 10:38:15 katarynka go-librespot[628]: time="2026-03-25T10:38:15+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 25 10:38:15 katarynka volumio[589]: info: Loading plugin "appearance"... Mar 25 10:38:15 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 10:38:15 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 10:38:17 katarynka volumio[589]: info: Loading plugin "network"... Mar 25 10:38:17 katarynka volumio[589]: info: Refreshing Cached IP Addresses Mar 25 10:38:17 katarynka sudo[642]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 25 10:38:17 katarynka sudo[642]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 10:38:17 katarynka sudo[642]: pam_unix(sudo:session): session closed for user root Mar 25 10:38:17 katarynka volumio[589]: info: Loading plugin "services"... Mar 25 10:38:17 katarynka sudo[644]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 25 10:38:17 katarynka volumio[589]: info: Loading plugin "alsa_controller"... Mar 25 10:38:17 katarynka sudo[644]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 10:38:17 katarynka sudo[644]: pam_unix(sudo:session): session closed for user root Mar 25 10:38:17 katarynka sudo[656]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Mar 25 10:38:17 katarynka sudo[656]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 10:38:17 katarynka volumio[589]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 25 10:38:17 katarynka volumio[589]: info: Loading plugin "wizard"... Mar 25 10:38:17 katarynka volumio[589]: info: Loading plugin "networkfs"... Mar 25 10:38:17 katarynka volumio[589]: info: Starting Udev Watcher for removable devices Mar 25 10:38:17 katarynka volumio[589]: info: Ignoring mount for partition: boot Mar 25 10:38:17 katarynka volumio[589]: info: Ignoring mount for partition: volumio Mar 25 10:38:17 katarynka volumio[589]: info: Ignoring mount for partition: volumio_data Mar 25 10:38:17 katarynka volumio[589]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 25 10:38:17 katarynka volumio[589]: info: Loading plugin "volumio_command_line_client"... Mar 25 10:38:17 katarynka volumio[589]: info: Loading plugin "upnp"... Mar 25 10:38:17 katarynka volumio[589]: info: [1774431497600] Starting Upmpd Daemon Mar 25 10:38:17 katarynka volumio[589]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 25 10:38:17 katarynka volumio[589]: info: Loading plugin "my_music"... Mar 25 10:38:17 katarynka volumio[589]: info: Loading plugin "mpd"... Mar 25 10:38:18 katarynka sudo[656]: pam_unix(sudo:session): session closed for user root Mar 25 10:38:18 katarynka volumio[589]: info: Loading plugin "upnp_browser"... Mar 25 10:38:18 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Mar 25 10:38:18 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 10:38:18 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 10:38:18 katarynka go-librespot[678]: go-librespot daemon starting... Mar 25 10:38:18 katarynka go-librespot[679]: time="2026-03-25T10:38:18+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 10:38:18 katarynka go-librespot[679]: time="2026-03-25T10:38:18+01:00" level=debug msg="app state loaded" Mar 25 10:38:18 katarynka go-librespot[679]: time="2026-03-25T10:38:18+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 10:38:18 katarynka go-librespot[679]: time="2026-03-25T10:38:18+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 25 10:38:18 katarynka go-librespot[679]: time="2026-03-25T10:38:18+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 25 10:38:18 katarynka go-librespot[679]: time="2026-03-25T10:38:18+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 25 10:38:18 katarynka go-librespot[679]: time="2026-03-25T10:38:18+01:00" level=info msg="zeroconf server listening on port 45441" Mar 25 10:38:19 katarynka go-librespot[679]: time="2026-03-25T10:38:19+01:00" level=debug msg="obtained new client token: AABbs3wIUU4HPhLQXwqEi2JyTvRk51T6TPJ9LbVtpIc0qjAx9xFcNwDJCYXnE+i61GbE/w5Z1bZtE6Z1erxTI5ZZtjiJ3ExtnC+13BddVdco1fO/Yia/Hwe+1Pn77yvkdWO+lWWHgpUgF+j2plMtFImm7bmjrtr+UvwyATKqTLpwNl1hrxS6wc/pfkWp46WxUE5wsscf7cFjOt0hdw/jKaA7aOwx7+AgY+mSxclJss/NLHr2ps5yeO0U" Mar 25 10:38:19 katarynka go-librespot[679]: time="2026-03-25T10:38:19+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 10:38:19 katarynka go-librespot[679]: time="2026-03-25T10:38:19+01:00" level=debug msg="completed keyexchange" Mar 25 10:38:19 katarynka go-librespot[679]: time="2026-03-25T10:38:19+01:00" level=debug msg="completed challenge" Mar 25 10:38:19 katarynka go-librespot[679]: time="2026-03-25T10:38:19+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 25 10:38:19 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 10:38:19 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 10:38:21 katarynka volumio[589]: info: Starting UPNP Browser Mar 25 10:38:21 katarynka volumio[589]: info: Loading plugin "alarm-clock"... Mar 25 10:38:21 katarynka volumio[589]: info: Loading plugin "airplay_emulation"... Mar 25 10:38:21 katarynka volumio[589]: info: Starting Shairport Sync Mar 25 10:38:21 katarynka volumio[589]: info: Loading plugin "last_100"... Mar 25 10:38:21 katarynka volumio[589]: info: Loading plugin "webradio"... Mar 25 10:38:21 katarynka volumio[589]: info: Loading plugin "i2s_dacs"... Mar 25 10:38:21 katarynka volumio[589]: info: Loading plugin "volumiodiscovery"... Mar 25 10:38:21 katarynka volumio[589]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Mar 25 10:38:21 katarynka volumio[589]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 25 10:38:21 katarynka volumio[589]: *** WARNING *** For more information see Mar 25 10:38:21 katarynka volumio[589]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Mar 25 10:38:21 katarynka volumio[589]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 25 10:38:21 katarynka volumio[589]: *** WARNING *** For more information see Mar 25 10:38:21 katarynka node[589]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Mar 25 10:38:21 katarynka node[589]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 25 10:38:21 katarynka node[589]: *** WARNING *** For more information see Mar 25 10:38:21 katarynka node[589]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Mar 25 10:38:21 katarynka node[589]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 25 10:38:21 katarynka node[589]: *** WARNING *** For more information see Mar 25 10:38:22 katarynka volumio[589]: info: Applying required configuration parameters for plugin volumiodiscovery Mar 25 10:38:22 katarynka volumio[589]: info: Discovery: Started advertising with name: katarynka Mar 25 10:38:22 katarynka volumio[589]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 25 10:38:22 katarynka volumio[589]: info: Loading plugin "spop"... Mar 25 10:38:22 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Mar 25 10:38:22 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 10:38:22 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 10:38:22 katarynka go-librespot[689]: go-librespot daemon starting... Mar 25 10:38:22 katarynka go-librespot[690]: time="2026-03-25T10:38:22+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 10:38:22 katarynka go-librespot[690]: time="2026-03-25T10:38:22+01:00" level=debug msg="app state loaded" Mar 25 10:38:22 katarynka go-librespot[690]: time="2026-03-25T10:38:22+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 10:38:22 katarynka go-librespot[690]: time="2026-03-25T10:38:22+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Mar 25 10:38:22 katarynka go-librespot[690]: time="2026-03-25T10:38:22+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Mar 25 10:38:22 katarynka go-librespot[690]: time="2026-03-25T10:38:22+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Mar 25 10:38:23 katarynka go-librespot[690]: time="2026-03-25T10:38:23+01:00" level=info msg="zeroconf server listening on port 41073" Mar 25 10:38:23 katarynka go-librespot[690]: time="2026-03-25T10:38:23+01:00" level=debug msg="obtained new client token: AAB8Ow5dj0Ko0Fp1Lj8sPLxgQHRUxqcY3Up+f22YmA2KznKf8yWQZZaGUyVulcRrLhZbKdoj6VkLLBB9CrByNDZX1hiIPhlMfhyksFGIovt/dE6HT3qnlkHTA5BQw0NgpwdDsV+iX3Xfp5FLQ5ijRKinD+fHoWyWDNqieo4HBGimtvsjXQf4D4GlFEp/Jtc6ApVypImtbmUSd06pI1mulhnXS+sBs8WTMV/TSkmdBDHgj8ZfsAYEiQA5" Mar 25 10:38:23 katarynka go-librespot[690]: time="2026-03-25T10:38:23+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 10:38:23 katarynka go-librespot[690]: time="2026-03-25T10:38:23+01:00" level=debug msg="completed keyexchange" Mar 25 10:38:23 katarynka go-librespot[690]: time="2026-03-25T10:38:23+01:00" level=debug msg="completed challenge" Mar 25 10:38:23 katarynka go-librespot[690]: time="2026-03-25T10:38:23+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 25 10:38:23 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 10:38:23 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 10:38:24 katarynka volumio[589]: info: Loading plugin "outputs"... Mar 25 10:38:24 katarynka volumio[589]: info: Loading plugin "albumart"... Mar 25 10:38:24 katarynka volumio[589]: info: Plugin example_plugin is not enabled Mar 25 10:38:24 katarynka volumio[589]: info: Loading plugin "inputs"... Mar 25 10:38:24 katarynka volumio[589]: info: Loading plugin "updater_comm"... Mar 25 10:38:24 katarynka volumio[589]: info: Plugin mpdemulation is not enabled Mar 25 10:38:24 katarynka volumio[589]: info: Loading plugin "rest_api"... Mar 25 10:38:24 katarynka volumio[589]: info: Loading plugin "websocket"... Mar 25 10:38:24 katarynka volumio[589]: info: Starting Socket.io Server version 1.7.4 Mar 25 10:38:24 katarynka volumio[589]: info: Loading i18n strings for locale pl Mar 25 10:38:24 katarynka volumio[589]: Updating browse sources language Mar 25 10:38:24 katarynka volumio[589]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 25 10:38:24 katarynka volumio[589]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 25 10:38:24 katarynka volumio[589]: info: CoreCommandRouter::initPlayerControls Mar 25 10:38:24 katarynka volumio[589]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 10:38:24 katarynka volumio[589]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 10:38:24 katarynka volumio[589]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 10:38:24 katarynka volumio[589]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 10:38:24 katarynka volumio[589]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 10:38:24 katarynka volumio[589]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 10:38:24 katarynka volumio[589]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 10:38:24 katarynka volumio[589]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 10:38:24 katarynka volumio[589]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 25 10:38:24 katarynka volumio[589]: Express server listening on port 3000 Mar 25 10:38:24 katarynka volumio[589]: [Metrics] WebUI: 12s 502.56ms Mar 25 10:38:24 katarynka volumio[589]: info: CoreStateMachine::resetVolumioState Mar 25 10:38:24 katarynka volumio[589]: info: CoreStateMachine::getcurrentVolume Mar 25 10:38:24 katarynka volumio[589]: info: CoreCommandRouter::volumioRetrievevolume Mar 25 10:38:25 katarynka volumio[589]: info: Cannot read play queue from file Mar 25 10:38:25 katarynka volumio[589]: info: Volumio Network Manager: Network status updated: 2 Mar 25 10:38:25 katarynka volumio[697]: Forking 3 albumart workers Mar 25 10:38:25 katarynka volumio[589]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 10:38:25 katarynka volumio[589]: info: CoreStateMachine::setRepeat null single undefined Mar 25 10:38:25 katarynka volumio[589]: info: CoreStateMachine::pushState Mar 25 10:38:25 katarynka volumio[589]: info: CorePlayQueue::getTrack 0 Mar 25 10:38:25 katarynka volumio[589]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 25 10:38:25 katarynka volumio[589]: info: CoreCommandRouter::volumioPushState Mar 25 10:38:25 katarynka volumio[589]: info: CoreStateMachine::setRandom null Mar 25 10:38:25 katarynka volumio[589]: info: CoreStateMachine::pushState Mar 25 10:38:25 katarynka volumio[589]: info: CorePlayQueue::getTrack 0 Mar 25 10:38:25 katarynka volumio[589]: info: CoreCommandRouter::volumioPushState Mar 25 10:38:25 katarynka volumio[589]: info: Setting Device type: Raspberry PI Mar 25 10:38:25 katarynka volumio[589]: info: Completed loading Core Plugins Mar 25 10:38:25 katarynka volumio[589]: info: Preparing to generate the ALSA configuration file Mar 25 10:38:25 katarynka volumio[589]: info: VolumeController:: Volume=96 Mute =false Mar 25 10:38:25 katarynka volumio[589]: info: CoreStateMachine::pushState Mar 25 10:38:25 katarynka volumio[589]: info: CorePlayQueue::getTrack 0 Mar 25 10:38:25 katarynka volumio[589]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 25 10:38:25 katarynka volumio[589]: info: CoreCommandRouter::volumioPushState Mar 25 10:38:25 katarynka volumio[589]: info: CoreStateMachine::updateTrackBlock Mar 25 10:38:25 katarynka volumio[589]: info: CorePlayQueue::getTrackBlock Mar 25 10:38:25 katarynka volumio[589]: info: CoreCommandRouter::volumioRetrievevolume Mar 25 10:38:25 katarynka volumio[589]: info: Asound.conf file unchanged, so no further update is needed Mar 25 10:38:25 katarynka volumio[589]: info: Output device has changed, restarting MPD Mar 25 10:38:25 katarynka volumio[589]: info: Output device has changed, restarting Shairport Sync Mar 25 10:38:25 katarynka volumio[589]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 10:38:25 katarynka volumio[589]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 10:38:25 katarynka volumio[589]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 25 10:38:25 katarynka volumio[589]: info: ___________ START PLUGINS ___________ Mar 25 10:38:25 katarynka sudo[755]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 25 10:38:25 katarynka sudo[755]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 10:38:25 katarynka volumio[589]: info: ControllerMpd::onStart: Initializing MPD Mar 25 10:38:25 katarynka volumio[589]: info: Creating MPD Configuration file Mar 25 10:38:25 katarynka sudo[755]: pam_unix(sudo:session): session closed for user root Mar 25 10:38:25 katarynka sudo[757]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 25 10:38:25 katarynka sudo[757]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 10:38:25 katarynka volumio[589]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 25 10:38:25 katarynka volumio[589]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 25 10:38:25 katarynka volumio[589]: info: [1774431505998] CoreMusicLibrary::Adding element Serwery Mediów Mar 25 10:38:26 katarynka volumio[589]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 25 10:38:26 katarynka sudo[764]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 25 10:38:26 katarynka sudo[764]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 10:38:26 katarynka sudo[764]: pam_unix(sudo:session): session closed for user root Mar 25 10:38:26 katarynka volumio[589]: info: UPNP Browser: Client initialized successfully Mar 25 10:38:26 katarynka systemd[1]: Stopping mpd.service - Music Player Daemon... Mar 25 10:38:26 katarynka sudo[767]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 25 10:38:26 katarynka sudo[767]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 10:38:26 katarynka volumio[589]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 10:38:26 katarynka volumio[589]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 10:38:26 katarynka volumio[589]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 25 10:38:26 katarynka volumio[589]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 10:38:26 katarynka volumio[589]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 10:38:26 katarynka systemd[1]: mpd.service: Deactivated successfully. Mar 25 10:38:26 katarynka systemd[1]: Stopped mpd.service - Music Player Daemon. Mar 25 10:38:26 katarynka systemd[1]: mpd.service: Consumed 7.768s CPU time. Mar 25 10:38:26 katarynka systemd[1]: mpd.socket: Deactivated successfully. Mar 25 10:38:26 katarynka systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Mar 25 10:38:26 katarynka systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Mar 25 10:38:26 katarynka volumio[589]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 25 10:38:26 katarynka volumio[589]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 25 10:38:26 katarynka volumio[589]: info: [1774431506303] CoreMusicLibrary::Adding element Last_100 Mar 25 10:38:26 katarynka volumio[589]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 25 10:38:26 katarynka volumio[589]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 25 10:38:26 katarynka volumio[589]: info: [1774431506312] CoreMusicLibrary::Adding element Webradio Mar 25 10:38:26 katarynka volumio[589]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 25 10:38:26 katarynka volumio[589]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 25 10:38:26 katarynka volumio[589]: info: Initializing BBC Radios Mar 25 10:38:26 katarynka systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Mar 25 10:38:26 katarynka systemd[1]: Starting mpd.service - Music Player Daemon... Mar 25 10:38:26 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Mar 25 10:38:26 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 10:38:26 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 10:38:26 katarynka systemd[1]: mpd.service: Deactivated successfully. Mar 25 10:38:26 katarynka systemd[1]: Stopped mpd.service - Music Player Daemon. Mar 25 10:38:26 katarynka go-librespot[794]: go-librespot daemon starting... Mar 25 10:38:26 katarynka systemd[1]: mpd.socket: Deactivated successfully. Mar 25 10:38:26 katarynka systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Mar 25 10:38:26 katarynka systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Mar 25 10:38:26 katarynka systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Mar 25 10:38:26 katarynka systemd[1]: Starting mpd.service - Music Player Daemon... Mar 25 10:38:26 katarynka go-librespot[796]: time="2026-03-25T10:38:26+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 10:38:26 katarynka go-librespot[796]: time="2026-03-25T10:38:26+01:00" level=debug msg="app state loaded" Mar 25 10:38:26 katarynka volumio[589]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 25 10:38:26 katarynka volumio[589]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 10:38:26 katarynka go-librespot[796]: time="2026-03-25T10:38:26+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 10:38:26 katarynka volumio[589]: info: Creating Spotify config file Mar 25 10:38:26 katarynka volumio[589]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 10:38:26 katarynka volumio-remote-updater[622]: [2026-03-25 10:38:26] [connect] Successful connection Mar 25 10:38:27 katarynka sudo[807]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Mar 25 10:38:27 katarynka sudo[807]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Mar 25 10:38:27 katarynka sudo[807]: pam_unix(sudo:session): session closed for user root Mar 25 10:38:27 katarynka go-librespot[796]: time="2026-03-25T10:38:27+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 25 10:38:27 katarynka go-librespot[796]: time="2026-03-25T10:38:27+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 25 10:38:27 katarynka go-librespot[796]: time="2026-03-25T10:38:27+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 25 10:38:27 katarynka go-librespot[796]: time="2026-03-25T10:38:27+01:00" level=info msg="zeroconf server listening on port 45793" Mar 25 10:38:27 katarynka go-librespot[796]: time="2026-03-25T10:38:27+01:00" level=debug msg="obtained new client token: AACvxf5SknfQaHbJ8r+zyXkOShgZjjhThAtGOFT3m+/TanAPkN+II/csIxsex4vWoTh8rlLVGp+y/RNXZBC4K+Npa/Iwt6yUR0UDonwjwTyHZM2l6vy4jhyOXL3vDf3s24+k4BDHbL8gPEVex90mkN3aCufUKOjKUCvBRfQZ5NTrfYW5+fpv2IfzutZ0l1W/DcPad/FI3t2rW8UQEkKUVKvMMwFrgPns85a1QgETRU1fSA1Ow5ydaKHnGus=" Mar 25 10:38:27 katarynka go-librespot[796]: time="2026-03-25T10:38:27+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 10:38:27 katarynka go-librespot[796]: time="2026-03-25T10:38:27+01:00" level=debug msg="completed keyexchange" Mar 25 10:38:27 katarynka go-librespot[796]: time="2026-03-25T10:38:27+01:00" level=debug msg="completed challenge" Mar 25 10:38:27 katarynka go-librespot[796]: time="2026-03-25T10:38:27+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 25 10:38:27 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 10:38:27 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 10:38:28 katarynka volumio[589]: info: Volumio Calling Home Mar 25 10:38:29 katarynka sudo[832]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 25 10:38:29 katarynka volumio[589]: info: Discovery: adding 4d616d77-6a8c-4da2-85a4-840d70f98e51 Mar 25 10:38:29 katarynka volumio[589]: info: Discovery: Found device katarynka Mar 25 10:38:29 katarynka sudo[832]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 10:38:29 katarynka volumio[589]: info: CoreCommandRouter::volumioGetState Mar 25 10:38:29 katarynka volumio[589]: info: CorePlayQueue::getTrack 0 Mar 25 10:38:29 katarynka sudo[832]: pam_unix(sudo:session): session closed for user root Mar 25 10:38:29 katarynka volumio[589]: info: MPD Permissions set Mar 25 10:38:29 katarynka volumio[589]: info: MPD Permissions set Mar 25 10:38:29 katarynka volumio[589]: info: VolumeController:: Volume=96 Mute =false Mar 25 10:38:29 katarynka volumio[589]: info: CoreStateMachine::pushState Mar 25 10:38:29 katarynka volumio[589]: info: CorePlayQueue::getTrack 0 Mar 25 10:38:29 katarynka volumio[589]: info: CoreCommandRouter::volumioPushState Mar 25 10:38:29 katarynka sudo[834]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 25 10:38:29 katarynka volumio-remote-updater[622]: [2026-03-25 10:38:29] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1774431506 101 Mar 25 10:38:29 katarynka sudo[834]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 10:38:29 katarynka sudo[834]: pam_unix(sudo:session): session closed for user root Mar 25 10:38:29 katarynka volumio[589]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 1 Mar 25 10:38:29 katarynka volumio[717]: Starting albumart workers Mar 25 10:38:29 katarynka volumio[589]: info: Spotify config file written Mar 25 10:38:29 katarynka volumio[589]: info: Discovery: this is already registered, 4d616d77-6a8c-4da2-85a4-840d70f98e51 Mar 25 10:38:29 katarynka volumio[589]: info: Discovery: Found device katarynka Mar 25 10:38:29 katarynka volumio[589]: info: CoreCommandRouter::volumioGetState Mar 25 10:38:29 katarynka volumio[589]: info: CorePlayQueue::getTrack 0 Mar 25 10:38:29 katarynka sudo[838]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Mar 25 10:38:29 katarynka sudo[838]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 10:38:29 katarynka volumio[722]: Starting albumart workers Mar 25 10:38:29 katarynka volumio[589]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Mar 25 10:38:29 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 10:38:29 katarynka volumio[589]: info: Volumio called home Mar 25 10:38:29 katarynka volumio[589]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 10:38:29 katarynka volumio[589]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 10:38:29 katarynka volumio[589]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 10:38:29 katarynka volumio[589]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 10:38:29 katarynka volumio[589]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 10:38:29 katarynka volumio[589]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 10:38:29 katarynka volumio[589]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 10:38:29 katarynka volumio[589]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 10:38:29 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 10:38:29 katarynka go-librespot[840]: go-librespot daemon starting... Mar 25 10:38:29 katarynka sudo[838]: pam_unix(sudo:session): session closed for user root Mar 25 10:38:29 katarynka volumio[589]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 10:38:29 katarynka volumio[589]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 10:38:29 katarynka volumio[589]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 10:38:29 katarynka volumio[589]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 10:38:29 katarynka volumio[589]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 10:38:29 katarynka volumio[589]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 10:38:29 katarynka volumio[589]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 10:38:29 katarynka volumio[589]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 10:38:29 katarynka volumio[589]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 10:38:29 katarynka volumio[589]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 10:38:29 katarynka go-librespot[846]: time="2026-03-25T10:38:29+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 10:38:29 katarynka go-librespot[846]: time="2026-03-25T10:38:29+01:00" level=debug msg="app state loaded" Mar 25 10:38:29 katarynka go-librespot[846]: time="2026-03-25T10:38:29+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 10:38:29 katarynka volumio[720]: Starting albumart workers Mar 25 10:38:29 katarynka volumio[589]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 10:38:29 katarynka volumio[589]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 10:38:29 katarynka volumio[589]: info: No need to fix Spotify hosts Mar 25 10:38:30 katarynka go-librespot[846]: time="2026-03-25T10:38:30+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 25 10:38:30 katarynka go-librespot[846]: time="2026-03-25T10:38:30+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 25 10:38:30 katarynka go-librespot[846]: time="2026-03-25T10:38:30+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 25 10:38:30 katarynka go-librespot[846]: time="2026-03-25T10:38:30+01:00" level=info msg="zeroconf server listening on port 43529" Mar 25 10:38:30 katarynka volumio[589]: info: Starting Shairport Sync Mar 25 10:38:30 katarynka volumio[589]: info: Starting Shairport Sync Mar 25 10:38:30 katarynka volumio[589]: info: Starting Shairport Sync Mar 25 10:38:30 katarynka sudo[864]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 25 10:38:30 katarynka sudo[864]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 10:38:30 katarynka go-librespot[846]: time="2026-03-25T10:38:30+01:00" level=debug msg="obtained new client token: AADuso+IjtnKmertxWUVnBmGJ+zTZI7SNZjoaHsqwMq1MUO/Z5QJBswx2nIr88N/kX4/zcm7eWKRemDfAvEIxgjlGL/OcqDAg/J16/SHCqyRMKSMHWGtSjHCdkjIa3TYd4kjXCr6jd53H6yJPQNNJjzwx20WVf2IPfEyQYOYVoxLBvU183tLQHqN9iwY+pNkClQvuTQ8igdDWEROQVnZ8k1yagV++HrcXQkD2dTfJNv5p600SQeWDIloNIM=" Mar 25 10:38:30 katarynka sudo[866]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 25 10:38:30 katarynka sudo[866]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 10:38:30 katarynka sudo[871]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Mar 25 10:38:30 katarynka sudo[871]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 10:38:30 katarynka go-librespot[846]: time="2026-03-25T10:38:30+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 10:38:31 katarynka go-librespot[846]: time="2026-03-25T10:38:31+01:00" level=debug msg="completed keyexchange" Mar 25 10:38:31 katarynka go-librespot[846]: time="2026-03-25T10:38:31+01:00" level=debug msg="completed challenge" Mar 25 10:38:31 katarynka go-librespot[846]: time="2026-03-25T10:38: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 25 10:38:31 katarynka sudo[868]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 25 10:38:31 katarynka sudo[868]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 10:38:31 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 10:38:31 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 10:38:31 katarynka systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Mar 25 10:38:31 katarynka sudo[871]: pam_unix(sudo:session): session closed for user root Mar 25 10:38:31 katarynka systemd[1]: shairport-sync.service: Deactivated successfully. Mar 25 10:38:31 katarynka systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 25 10:38:31 katarynka systemd[1]: shairport-sync.service: Consumed 2.339s CPU time. Mar 25 10:38:31 katarynka systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 25 10:38:31 katarynka sudo[864]: pam_unix(sudo:session): session closed for user root Mar 25 10:38:31 katarynka systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Mar 25 10:38:31 katarynka sudo[866]: pam_unix(sudo:session): session closed for user root Mar 25 10:38:31 katarynka systemd[1]: shairport-sync.service: Deactivated successfully. Mar 25 10:38:31 katarynka systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 25 10:38:31 katarynka systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 25 10:38:31 katarynka sudo[868]: pam_unix(sudo:session): session closed for user root Mar 25 10:38:31 katarynka volumio[589]: info: Upmpdcli Daemon Started Mar 25 10:38:31 katarynka volumio[589]: info: An error occurred while refreshing Spotify Token Error: Bad Request Mar 25 10:38:31 katarynka volumio[589]: info: Shairport-Sync Started Mar 25 10:38:31 katarynka volumio[589]: Error adding Membership: Error: addMembership EINVAL Mar 25 10:38:31 katarynka volumio[589]: info: Shairport-Sync Started Mar 25 10:38:31 katarynka volumio[589]: info: Shairport-Sync Started Mar 25 10:38:31 katarynka volumio[589]: info: CoreCommandRouter::volumioGetState Mar 25 10:38:31 katarynka volumio[589]: info: CorePlayQueue::getTrack 0 Mar 25 10:38:33 katarynka volumio[589]: info: go-librespot daemon successfully initialized Mar 25 10:38:34 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Mar 25 10:38:34 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 10:38:34 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 10:38:34 katarynka go-librespot[921]: go-librespot daemon starting... Mar 25 10:38:34 katarynka go-librespot[922]: time="2026-03-25T10:38:34+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 10:38:34 katarynka go-librespot[922]: time="2026-03-25T10:38:34+01:00" level=debug msg="app state loaded" Mar 25 10:38:34 katarynka go-librespot[922]: time="2026-03-25T10:38:34+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 10:38:34 katarynka go-librespot[922]: time="2026-03-25T10:38:34+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Mar 25 10:38:34 katarynka go-librespot[922]: time="2026-03-25T10:38:34+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Mar 25 10:38:34 katarynka go-librespot[922]: time="2026-03-25T10:38:34+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Mar 25 10:38:34 katarynka go-librespot[922]: time="2026-03-25T10:38:34+01:00" level=info msg="zeroconf server listening on port 36513" Mar 25 10:38:34 katarynka mpd[811]: 2026-03-25T10:38:34 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Mar 25 10:38:34 katarynka systemd[1]: Started mpd.service - Music Player Daemon. Mar 25 10:38:34 katarynka go-librespot[922]: time="2026-03-25T10:38:34+01:00" level=debug msg="obtained new client token: AACVF/ag5PieoBxWV4B/eCIb33wltx7+cjHXUqTmtW6AXoEcsHDl0kTjMJYE521KTcSZ7L+BqwBVQLSolo2jb9pQaUT0iJbFVBMuSaUaCA/DTQCcFLNL9xz3WodN/FJmLJMoFCUFGga5ttCPhjR/1Yn4z3qXCUxyuutV0/2iv5i9kfi9jEdQgwu+C3hffGmyYkebwBUMKKllSA9Mz/ZSYT4eGGlILgu2T+2MUxFb6bWV7kd4AiRP6uiZZ/E=" Mar 25 10:38:34 katarynka sudo[757]: pam_unix(sudo:session): session closed for user root Mar 25 10:38:34 katarynka sudo[767]: pam_unix(sudo:session): session closed for user root Mar 25 10:38:34 katarynka volumio[589]: info: Completed starting Core Plugins Mar 25 10:38:34 katarynka volumio[589]: info: ------------------------------------------- Mar 25 10:38:34 katarynka volumio[589]: info: ----- MyVolumio plugins startup ---- Mar 25 10:38:34 katarynka volumio[589]: info: ------------------------------------------- Mar 25 10:38:34 katarynka volumio[589]: info: [MyVolumio PluginManager] Fetching plans data.... Mar 25 10:38:34 katarynka go-librespot[922]: time="2026-03-25T10:38:34+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 10:38:35 katarynka go-librespot[922]: time="2026-03-25T10:38:35+01:00" level=debug msg="completed keyexchange" Mar 25 10:38:35 katarynka go-librespot[922]: time="2026-03-25T10:38:35+01:00" level=debug msg="completed challenge" Mar 25 10:38:35 katarynka go-librespot[922]: time="2026-03-25T10:38:35+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 25 10:38:35 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 10:38:35 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 10:38:35 katarynka volumio[589]: error: MPD error: The expression evaluated to a falsy value: Mar 25 10:38:35 katarynka volumio[589]: assert.ok(self.idling) Mar 25 10:38:35 katarynka volumio[589]: error: The expression evaluated to a falsy value: Mar 25 10:38:35 katarynka volumio[589]: assert.ok(self.idling) Mar 25 10:38:35 katarynka volumio[589]: info: MPD running with PID811 Mar 25 10:38:35 katarynka volumio[589]: ,establishing connection Mar 25 10:38:35 katarynka volumio[589]: error: updateQueue error: null Mar 25 10:38:35 katarynka volumio[589]: error: updateQueue error: null Mar 25 10:38:36 katarynka volumio[589]: info: Initializing connection to go-librespot Websocket Mar 25 10:38:36 katarynka volumio[589]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 25 10:38:37 katarynka sudo[953]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Mar 25 10:38:37 katarynka sudo[953]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 10:38:38 katarynka sudo[955]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Mar 25 10:38:38 katarynka sudo[955]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 10:38:38 katarynka systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Mar 25 10:38:38 katarynka systemd[1]: mpd_monitor.service: Deactivated successfully. Mar 25 10:38:38 katarynka systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Mar 25 10:38:38 katarynka systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Mar 25 10:38:38 katarynka sudo[953]: pam_unix(sudo:session): session closed for user root Mar 25 10:38:38 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 11. Mar 25 10:38:38 katarynka sudo[955]: pam_unix(sudo:session): session closed for user root Mar 25 10:38:38 katarynka mpd_monitor.sh[958]: MPD Monitor Service: Starting MPD Monitor Service Mar 25 10:38:38 katarynka volumio[589]: info: Successfully started MPD Monitor Mar 25 10:38:38 katarynka volumio[589]: info: Successfully started MPD Monitor Mar 25 10:38:38 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 10:38:38 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 10:38:38 katarynka go-librespot[963]: go-librespot daemon starting... Mar 25 10:38:38 katarynka go-librespot[964]: time="2026-03-25T10:38:38+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 10:38:38 katarynka go-librespot[964]: time="2026-03-25T10:38:38+01:00" level=debug msg="app state loaded" Mar 25 10:38:38 katarynka go-librespot[964]: time="2026-03-25T10:38:38+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 10:38:38 katarynka go-librespot[964]: time="2026-03-25T10:38:38+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 25 10:38:38 katarynka go-librespot[964]: time="2026-03-25T10:38:38+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 25 10:38:38 katarynka go-librespot[964]: time="2026-03-25T10:38:38+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 25 10:38:38 katarynka go-librespot[964]: time="2026-03-25T10:38:38+01:00" level=info msg="zeroconf server listening on port 32909" Mar 25 10:38:38 katarynka go-librespot[964]: time="2026-03-25T10:38:38+01:00" level=debug msg="obtained new client token: AAD8uqypHtJ9d2pI+vM26nKU4Fhdb5PBden0Gfe1qFv82PIK1qZzk/ETJPzxIaOETSliMIWwzwYgnro6cEmkMCB8F/G2W5FS2plMP4CK2uMrM7olGDWqMjgb02BqwiV6mh7WUIH1DNEuc3oaUMBj4l79VVVgH3/+Ov/+vGxOibPdDoMCglG+DyQ+H9ZYtR0KS/YrQ2C6uRENmxTwqoDm80e7MtK5KjdkGjUrjvRe9rj19rUNlvWAboIlLos=" Mar 25 10:38:38 katarynka go-librespot[964]: time="2026-03-25T10:38:38+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 10:38:38 katarynka go-librespot[964]: time="2026-03-25T10:38:38+01:00" level=debug msg="completed keyexchange" Mar 25 10:38:38 katarynka go-librespot[964]: time="2026-03-25T10:38:38+01:00" level=debug msg="completed challenge" Mar 25 10:38:38 katarynka go-librespot[964]: time="2026-03-25T10:38: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 25 10:38:39 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 10:38:39 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 10:38:39 katarynka volumio[589]: info: Initializing connection to go-librespot Websocket Mar 25 10:38:39 katarynka volumio[589]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 25 10:38:40 katarynka volumio[589]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Mar 25 10:38:42 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 12. Mar 25 10:38:42 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 10:38:42 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 10:38:42 katarynka go-librespot[972]: go-librespot daemon starting... Mar 25 10:38:42 katarynka go-librespot[973]: time="2026-03-25T10:38:42+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 10:38:42 katarynka go-librespot[973]: time="2026-03-25T10:38:42+01:00" level=debug msg="app state loaded" Mar 25 10:38:42 katarynka go-librespot[973]: time="2026-03-25T10:38:42+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 10:38:42 katarynka go-librespot[973]: time="2026-03-25T10:38:42+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 25 10:38:42 katarynka go-librespot[973]: time="2026-03-25T10:38:42+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 25 10:38:42 katarynka go-librespot[973]: time="2026-03-25T10:38:42+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 25 10:38:42 katarynka go-librespot[973]: time="2026-03-25T10:38:42+01:00" level=info msg="zeroconf server listening on port 36583" Mar 25 10:38:42 katarynka volumio[589]: info: Initializing connection to go-librespot Websocket Mar 25 10:38:42 katarynka go-librespot[973]: time="2026-03-25T10:38:42+01:00" level=debug msg="new websocket client" Mar 25 10:38:42 katarynka volumio[589]: info: Connection to go-librespot Websocket established Mar 25 10:38:42 katarynka go-librespot[973]: time="2026-03-25T10:38:42+01:00" level=debug msg="obtained new client token: AAC4JpkZ/OCixU+l8VttDB9othsm2k735uBOPBxrsjchSmNv3vgnaVPRQtxEshMtsuxuDS6BhF97lcd26RBepoRy1bOj+VYFiu1xlbBIFzxqBlUSnJNCdTfOEMd/K13cqEDtlYAe9tCKeJDK/sU/3+fGuaWWP4901dBLnzR5lorlJUofzfIYyw5PrvBjhKp3Xx7TyywkoJ9QQNTHmeU11JjxSu6zhuTE0LW6I7gzYFre4aX96IJmkocgjNY=" Mar 25 10:38:43 katarynka go-librespot[973]: time="2026-03-25T10:38:43+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 10:38:43 katarynka volumio[589]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Mar 25 10:38:43 katarynka volumio[589]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Mar 25 10:38:43 katarynka volumio[589]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Mar 25 10:38:43 katarynka volumio[589]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Mar 25 10:38:43 katarynka volumio[589]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Mar 25 10:38:43 katarynka volumio[589]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Mar 25 10:38:43 katarynka volumio[589]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Mar 25 10:38:43 katarynka volumio[589]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Mar 25 10:38:43 katarynka volumio[589]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Mar 25 10:38:43 katarynka volumio[589]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Mar 25 10:38:43 katarynka volumio[589]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Mar 25 10:38:43 katarynka volumio[589]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Mar 25 10:38:43 katarynka volumio[589]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Mar 25 10:38:43 katarynka volumio[589]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Mar 25 10:38:43 katarynka volumio[589]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Mar 25 10:38:43 katarynka volumio[589]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Mar 25 10:38:43 katarynka volumio[589]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Mar 25 10:38:43 katarynka volumio[589]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Mar 25 10:38:43 katarynka volumio[589]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Mar 25 10:38:43 katarynka volumio[589]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Mar 25 10:38:43 katarynka volumio[589]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Mar 25 10:38:43 katarynka volumio[589]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Mar 25 10:38:43 katarynka volumio[589]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Mar 25 10:38:43 katarynka volumio[589]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Mar 25 10:38:43 katarynka volumio[589]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Mar 25 10:38:43 katarynka volumio[589]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Mar 25 10:38:43 katarynka volumio[589]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Mar 25 10:38:43 katarynka volumio[589]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Mar 25 10:38:43 katarynka volumio[589]: info: Adding plugin bluetooth to MyMusic Plugins Mar 25 10:38:43 katarynka volumio[589]: info: Adding plugin multiroom to MyMusic Plugins Mar 25 10:38:43 katarynka volumio[589]: info: Adding plugin metavolumio to MyMusic Plugins Mar 25 10:38:43 katarynka volumio[589]: info: Adding plugin cd_controller to MyMusic Plugins Mar 25 10:38:43 katarynka volumio[589]: info: Adding plugin qobuzconnect to MyMusic Plugins Mar 25 10:38:43 katarynka volumio[589]: info: Adding plugin smart_inputs to MyMusic Plugins Mar 25 10:38:43 katarynka volumio[589]: info: Adding plugin tidalconnect to MyMusic Plugins Mar 25 10:38:43 katarynka go-librespot[973]: time="2026-03-25T10:38:43+01:00" level=debug msg="completed keyexchange" Mar 25 10:38:43 katarynka go-librespot[973]: time="2026-03-25T10:38:43+01:00" level=debug msg="completed challenge" Mar 25 10:38:43 katarynka volumio[589]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Mar 25 10:38:43 katarynka go-librespot[973]: time="2026-03-25T10:38:43+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 25 10:38:43 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 10:38:43 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 10:38:45 katarynka volumio[589]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Mar 25 10:38:45 katarynka volumio[589]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Mar 25 10:38:45 katarynka volumio[589]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 10:38:45 katarynka volumio[589]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 10:38:45 katarynka volumio[589]: info: Starting MyVolumio Remote Streaming Endpoints Mar 25 10:38:45 katarynka volumio[589]: info: MyVolumio login type: Token Mar 25 10:38:45 katarynka volumio[589]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Mar 25 10:38:45 katarynka volumio[589]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Mar 25 10:38:46 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 13. Mar 25 10:38:46 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 10:38:46 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 10:38:46 katarynka go-librespot[981]: go-librespot daemon starting... Mar 25 10:38:47 katarynka go-librespot[982]: time="2026-03-25T10:38:47+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 10:38:47 katarynka go-librespot[982]: time="2026-03-25T10:38:47+01:00" level=debug msg="app state loaded" Mar 25 10:38:47 katarynka go-librespot[982]: time="2026-03-25T10:38:47+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 10:38:47 katarynka volumio[589]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Mar 25 10:38:47 katarynka volumio[589]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Mar 25 10:38:47 katarynka volumio[589]: info: Streaming services startup Mar 25 10:38:47 katarynka volumio[589]: info: Starting Streaming Daemon Mar 25 10:38:47 katarynka sudo[992]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Mar 25 10:38:47 katarynka sudo[992]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 10:38:47 katarynka volumio[589]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Mar 25 10:38:47 katarynka sudo[992]: pam_unix(sudo:session): session closed for user root Mar 25 10:38:47 katarynka go-librespot[982]: time="2026-03-25T10:38:47+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 25 10:38:47 katarynka go-librespot[982]: time="2026-03-25T10:38:47+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 25 10:38:47 katarynka go-librespot[982]: time="2026-03-25T10:38:47+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 25 10:38:47 katarynka go-librespot[982]: time="2026-03-25T10:38:47+01:00" level=info msg="zeroconf server listening on port 41975" Mar 25 10:38:47 katarynka volumio[589]: info: Getting Spotify volume Mar 25 10:38:47 katarynka volumio[589]: info: Connection to go-librespot Websocket closed Mar 25 10:38:47 katarynka volumio[589]: error: Cannot start Volumio Streaming Daemon Mar 25 10:38:47 katarynka volumio[589]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Mar 25 10:38:47 katarynka volumio[589]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Mar 25 10:38:47 katarynka go-librespot[982]: time="2026-03-25T10:38:47+01:00" level=debug msg="obtained new client token: AADZuKn2QJYO5nbK9PxSKqkLuQULwrE2iGXv4aIdViHThO2yFtwQz/SdkOsz07dkj2YBij6mhzS+TtSrwXfRKce1Tj5OOiusMyUzU+zeOFMiz+8ALfWeDPfzjZuaj/GAAJez0gdy/ajJD8qVT7G1jhXGPBlFpxmYfvhleupMhEdgIxN+trJVaMnV8OiSZ03tMPudWssSOOLAD217lVo6Auoikps8ha3fzzYgKezo49eTqrYtg8dLnBcGuIQ=" Mar 25 10:38:47 katarynka volumio[589]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Mar 25 10:38:47 katarynka go-librespot[982]: time="2026-03-25T10:38:47+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 10:38:47 katarynka go-librespot[982]: time="2026-03-25T10:38:47+01:00" level=debug msg="completed keyexchange" Mar 25 10:38:47 katarynka go-librespot[982]: time="2026-03-25T10:38:47+01:00" level=debug msg="completed challenge" Mar 25 10:38:47 katarynka go-librespot[982]: time="2026-03-25T10:38:47+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 25 10:38:47 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 10:38:47 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 10:38:47 katarynka volumio[589]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 25 10:38:47 katarynka volumio[589]: Error: socket hang up Mar 25 10:38:47 katarynka volumio[589]: at connResetException (node:internal/errors:720:14) Mar 25 10:38:47 katarynka volumio[589]: at Socket.socketOnEnd (node:_http_client:519:23) Mar 25 10:38:47 katarynka volumio[589]: at Socket.emit (node:events:526:35) Mar 25 10:38:47 katarynka volumio[589]: at endReadableNT (node:internal/streams/readable:1376:12) Mar 25 10:38:47 katarynka volumio[589]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Mar 25 10:38:47 katarynka volumio[589]: code: 'ECONNRESET', Mar 25 10:38:47 katarynka volumio[589]: response: undefined Mar 25 10:38:47 katarynka volumio[589]: } Mar 25 10:38:47 katarynka volumio[589]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 25 10:38:49 katarynka sudo[1029]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-03-25 10:37' Mar 25 10:38:49 katarynka sudo[1029]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 10:38:49 katarynka sudo[1029]: pam_unix(sudo:session): session closed for user root Mar 25 10:38:50 katarynka systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Mar 25 10:38:50 katarynka volumio-remote-updater[622]: [2026-03-25 10:38:49] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Mar 25 10:38:50 katarynka volumio-remote-updater[622]: [2026-03-25 10:38:49] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Mar 25 10:38:50 katarynka systemd[1]: volumio.service: Failed with result 'exit-code'. Mar 25 10:38:50 katarynka systemd[1]: volumio.service: Consumed 49.068s CPU time. Mar 25 10:38:50 katarynka systemd[1]: Started dynamicswap.service - dynamicswap service. Mar 25 10:38:50 katarynka systemd[1]: volumio.service: Scheduled restart job, restart counter is at 26290. Mar 25 10:38:50 katarynka systemd[1]: dynamicswap.service: Deactivated successfully. Mar 25 10:38:50 katarynka systemd[1]: Stopped volumio.service - Volumio Backend Module. Mar 25 10:38:50 katarynka systemd[1]: volumio.service: Consumed 49.068s CPU time. Mar 25 10:38:50 katarynka systemd[1]: Started volumio.service - Volumio Backend Module. Mar 25 10:38:51 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 14. Mar 25 10:38:51 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 10:38:51 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 10:38:51 katarynka go-librespot[1051]: go-librespot daemon starting... Mar 25 10:38:51 katarynka go-librespot[1052]: time="2026-03-25T10:38:51+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 10:38:51 katarynka go-librespot[1052]: time="2026-03-25T10:38:51+01:00" level=debug msg="app state loaded" Mar 25 10:38:51 katarynka go-librespot[1052]: time="2026-03-25T10:38:51+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 10:38:51 katarynka go-librespot[1052]: time="2026-03-25T10:38:51+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 25 10:38:51 katarynka go-librespot[1052]: time="2026-03-25T10:38:51+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 25 10:38:51 katarynka go-librespot[1052]: time="2026-03-25T10:38:51+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 25 10:38:51 katarynka go-librespot[1052]: time="2026-03-25T10:38:51+01:00" level=info msg="zeroconf server listening on port 42231" Mar 25 10:38:51 katarynka go-librespot[1052]: time="2026-03-25T10:38:51+01:00" level=debug msg="obtained new client token: AAA9RHdbnxsJtVonb8AwLh5bQhgdfSCylC6CuCIXfC1s472gCWtts60LjV1wQ+dzg5UCsFxvDOr1ncGEndz4l+VeEO7YUDwJp9DFaKQ7fJ++jif0MQ84baUXEzOjjtUC/C6ZaIeUiPR/5+4J+sB/ghtk+qWcFTlypdydKQMMPWaaMAgrE/k5EOapB76+6HvoaVwkZnGA4q3SGmCwXa4oTIVs55v0PgcYe+QVAThYYCanvstvW9roiH7F1w4=" Mar 25 10:38:51 katarynka go-librespot[1052]: time="2026-03-25T10:38:51+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 10:38:52 katarynka go-librespot[1052]: time="2026-03-25T10:38:52+01:00" level=debug msg="completed keyexchange" Mar 25 10:38:52 katarynka go-librespot[1052]: time="2026-03-25T10:38:52+01:00" level=debug msg="completed challenge" Mar 25 10:38:52 katarynka go-librespot[1052]: time="2026-03-25T10:38:52+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 25 10:38:52 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 10:38:52 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 10:38:53 katarynka volumio[1040]: info: ------------------------------------------- Mar 25 10:38:54 katarynka volumio[1040]: info: ----- Volumio3 ---- Mar 25 10:38:54 katarynka volumio[1040]: info: ------------------------------------------- Mar 25 10:38:54 katarynka volumio[1040]: info: ----- System startup ---- Mar 25 10:38:54 katarynka volumio[1040]: info: ------------------------------------------- Mar 25 10:38:55 katarynka volumio-remote-updater[622]: [2026-03-25 10:38:55] [connect] Successful connection Mar 25 10:38:55 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 15. Mar 25 10:38:55 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 10:38:55 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 10:38:55 katarynka go-librespot[1068]: go-librespot daemon starting... Mar 25 10:38:55 katarynka go-librespot[1069]: time="2026-03-25T10:38:55+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 10:38:55 katarynka go-librespot[1069]: time="2026-03-25T10:38:55+01:00" level=debug msg="app state loaded" Mar 25 10:38:55 katarynka go-librespot[1069]: time="2026-03-25T10:38:55+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 10:38:55 katarynka volumio[1040]: info: MYVOLUMIO Environment detected Mar 25 10:38:55 katarynka volumio[1040]: info: Plugin folders cleanup Mar 25 10:38:55 katarynka volumio[1040]: info: Scanning into folder /volumio/app/plugins/ Mar 25 10:38:55 katarynka volumio[1040]: info: Scanning category audio_interface Mar 25 10:38:55 katarynka volumio[1040]: info: Scanning category miscellanea Mar 25 10:38:55 katarynka volumio[1040]: info: Scanning category music_service Mar 25 10:38:55 katarynka volumio[1040]: info: Scanning category plugins.json Mar 25 10:38:55 katarynka volumio[1040]: info: Scanning category system_controller Mar 25 10:38:55 katarynka volumio[1040]: info: Scanning category user_interface Mar 25 10:38:55 katarynka volumio[1040]: info: Scanning into folder /data/plugins/ Mar 25 10:38:55 katarynka volumio[1040]: info: Scanning category music_service Mar 25 10:38:55 katarynka volumio[1040]: info: Plugin folders cleanup completed Mar 25 10:38:55 katarynka volumio[1040]: info: ------------------------------------------- Mar 25 10:38:55 katarynka volumio[1040]: info: ----- Core plugins startup ---- Mar 25 10:38:55 katarynka volumio[1040]: info: ------------------------------------------- Mar 25 10:38:55 katarynka volumio[1040]: info: Loading plugins from folder /volumio/app/plugins/ Mar 25 10:38:55 katarynka volumio[1040]: info: Adding plugin upnp to MyMusic Plugins Mar 25 10:38:55 katarynka volumio[1040]: info: Adding plugin airplay_emulation to MyMusic Plugins Mar 25 10:38:55 katarynka volumio[1040]: info: Adding plugin upnp_browser to MyMusic Plugins Mar 25 10:38:55 katarynka volumio[1040]: info: Loading plugins from folder /data/plugins/ Mar 25 10:38:55 katarynka volumio[1040]: info: Loading plugin "system"... Mar 25 10:38:55 katarynka go-librespot[1069]: time="2026-03-25T10:38:55+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Mar 25 10:38:55 katarynka go-librespot[1069]: time="2026-03-25T10:38:55+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Mar 25 10:38:55 katarynka go-librespot[1069]: time="2026-03-25T10:38:55+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Mar 25 10:38:55 katarynka go-librespot[1069]: time="2026-03-25T10:38:55+01:00" level=info msg="zeroconf server listening on port 33005" Mar 25 10:38:55 katarynka volumio[1040]: info: Loading plugin "appearance"... Mar 25 10:38:55 katarynka go-librespot[1069]: time="2026-03-25T10:38:55+01:00" level=debug msg="obtained new client token: AADu/kPLZmQeE2asKF8aSXH9eKw1+3/pxS777Jcu3W4A4aFddJEQTXNdbzR0lYMN9ynrapR4HqM6vKB8MhmO1QugBZ+pzDhAWQ6dQ0mXQkYrJfEddWCDdgqUkv5jr9rIJS7kx6Hqe6Tf4KA5xMdg5FXmnffT40AZWL1JWJIqGREyWQAUn3wvJ41KWiXsEr+162P87oCtn/zkyv9Axka4bbbFkQpzh+V8BRq7SLCYVgeYWQmTlV5sAJkIwYE=" Mar 25 10:38:55 katarynka go-librespot[1069]: time="2026-03-25T10:38:55+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 10:38:56 katarynka go-librespot[1069]: time="2026-03-25T10:38:56+01:00" level=debug msg="completed keyexchange" Mar 25 10:38:56 katarynka go-librespot[1069]: time="2026-03-25T10:38:56+01:00" level=debug msg="completed challenge" Mar 25 10:38:56 katarynka go-librespot[1069]: time="2026-03-25T10:38:56+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 25 10:38:56 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 10:38:56 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 10:38:57 katarynka volumio[1040]: info: Loading plugin "network"... Mar 25 10:38:57 katarynka volumio[1040]: info: Refreshing Cached IP Addresses Mar 25 10:38:57 katarynka sudo[1083]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 25 10:38:57 katarynka sudo[1083]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 10:38:57 katarynka sudo[1083]: pam_unix(sudo:session): session closed for user root Mar 25 10:38:57 katarynka sudo[1085]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 25 10:38:57 katarynka volumio[1040]: info: Loading plugin "services"... Mar 25 10:38:57 katarynka sudo[1085]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 10:38:57 katarynka volumio[1040]: info: Loading plugin "alsa_controller"... Mar 25 10:38:57 katarynka sudo[1085]: pam_unix(sudo:session): session closed for user root Mar 25 10:38:57 katarynka sudo[1093]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Mar 25 10:38:57 katarynka sudo[1093]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 10:38:58 katarynka volumio[1040]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 25 10:38:58 katarynka volumio[1040]: info: Loading plugin "wizard"... Mar 25 10:38:58 katarynka volumio[1040]: info: Loading plugin "networkfs"... Mar 25 10:38:58 katarynka volumio[1040]: info: Starting Udev Watcher for removable devices Mar 25 10:38:58 katarynka volumio[1040]: info: Ignoring mount for partition: boot Mar 25 10:38:58 katarynka volumio[1040]: info: Ignoring mount for partition: volumio Mar 25 10:38:58 katarynka volumio[1040]: info: Ignoring mount for partition: volumio_data Mar 25 10:38:58 katarynka volumio[1040]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 25 10:38:58 katarynka volumio[1040]: info: Loading plugin "volumio_command_line_client"... Mar 25 10:38:58 katarynka volumio[1040]: info: Loading plugin "upnp"... Mar 25 10:38:58 katarynka volumio[1040]: info: [1774431538240] Starting Upmpd Daemon Mar 25 10:38:58 katarynka volumio[1040]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 25 10:38:58 katarynka volumio[1040]: info: Loading plugin "my_music"... Mar 25 10:38:58 katarynka volumio[1040]: info: Loading plugin "mpd"... Mar 25 10:38:58 katarynka sudo[1093]: pam_unix(sudo:session): session closed for user root Mar 25 10:38:58 katarynka volumio[1040]: info: Loading plugin "upnp_browser"... Mar 25 10:38:59 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 16. Mar 25 10:38:59 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 10:38:59 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 10:38:59 katarynka go-librespot[1119]: go-librespot daemon starting... Mar 25 10:38:59 katarynka go-librespot[1120]: time="2026-03-25T10:38:59+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 10:38:59 katarynka go-librespot[1120]: time="2026-03-25T10:38:59+01:00" level=debug msg="app state loaded" Mar 25 10:38:59 katarynka go-librespot[1120]: time="2026-03-25T10:38:59+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 10:38:59 katarynka go-librespot[1120]: time="2026-03-25T10:38:59+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 25 10:38:59 katarynka go-librespot[1120]: time="2026-03-25T10:38:59+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 25 10:38:59 katarynka go-librespot[1120]: time="2026-03-25T10:38:59+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 25 10:38:59 katarynka go-librespot[1120]: time="2026-03-25T10:38:59+01:00" level=info msg="zeroconf server listening on port 33557" Mar 25 10:38:59 katarynka go-librespot[1120]: time="2026-03-25T10:38:59+01:00" level=debug msg="obtained new client token: AADkg6W4/HWMngiKP7leBHDp5kZhA2zr2hEOw0pffALOMjVVrzG/xb3q9WGsVxo6J5aN4V5o5WPmkoG980FVhIqvKC6CprjcwV4PNJwpWG/HRMzr14cBnBT3ZuYBbi4IpOFFizUZ9YeD8aiQuh/Csiz0Ptb6097StwzVZTFvhpezetCriUcf60i8REYInYJIk80fkwg6HO+Ms/hYA+bgBSOy4ieDMNYdG0tD2qsHEyucK2OGrAf5qIo/oRE=" Mar 25 10:38:59 katarynka go-librespot[1120]: time="2026-03-25T10:38:59+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 10:39:00 katarynka go-librespot[1120]: time="2026-03-25T10:39:00+01:00" level=debug msg="completed keyexchange" Mar 25 10:39:00 katarynka go-librespot[1120]: time="2026-03-25T10:39:00+01:00" level=debug msg="completed challenge" Mar 25 10:39:00 katarynka go-librespot[1120]: time="2026-03-25T10:39:00+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 25 10:39:00 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 10:39:00 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 10:39:01 katarynka volumio[1040]: info: Starting UPNP Browser Mar 25 10:39:01 katarynka volumio[1040]: info: Loading plugin "alarm-clock"... Mar 25 10:39:02 katarynka volumio[1040]: info: Loading plugin "airplay_emulation"... Mar 25 10:39:02 katarynka volumio[1040]: info: Starting Shairport Sync Mar 25 10:39:02 katarynka volumio[1040]: info: Loading plugin "last_100"... Mar 25 10:39:02 katarynka volumio[1040]: info: Loading plugin "webradio"... Mar 25 10:39:02 katarynka volumio[1040]: info: Loading plugin "i2s_dacs"... Mar 25 10:39:02 katarynka volumio[1040]: info: Loading plugin "volumiodiscovery"... Mar 25 10:39:02 katarynka volumio[1040]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Mar 25 10:39:02 katarynka volumio[1040]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 25 10:39:02 katarynka volumio[1040]: *** WARNING *** For more information see Mar 25 10:39:02 katarynka volumio[1040]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Mar 25 10:39:02 katarynka volumio[1040]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 25 10:39:02 katarynka node[1040]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Mar 25 10:39:02 katarynka volumio[1040]: *** WARNING *** For more information see Mar 25 10:39:02 katarynka node[1040]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 25 10:39:02 katarynka node[1040]: *** WARNING *** For more information see Mar 25 10:39:02 katarynka node[1040]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Mar 25 10:39:02 katarynka node[1040]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 25 10:39:02 katarynka node[1040]: *** WARNING *** For more information see Mar 25 10:39:02 katarynka volumio[1040]: info: Applying required configuration parameters for plugin volumiodiscovery Mar 25 10:39:02 katarynka volumio[1040]: info: Discovery: Started advertising with name: katarynka Mar 25 10:39:02 katarynka volumio[1040]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 25 10:39:02 katarynka volumio[1040]: info: Loading plugin "spop"... Mar 25 10:39:03 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 17. Mar 25 10:39:03 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 10:39:03 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 10:39:03 katarynka go-librespot[1129]: go-librespot daemon starting... Mar 25 10:39:03 katarynka go-librespot[1130]: time="2026-03-25T10:39:03+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 10:39:03 katarynka go-librespot[1130]: time="2026-03-25T10:39:03+01:00" level=debug msg="app state loaded" Mar 25 10:39:03 katarynka go-librespot[1130]: time="2026-03-25T10:39:03+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 10:39:03 katarynka go-librespot[1130]: time="2026-03-25T10:39:03+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Mar 25 10:39:03 katarynka go-librespot[1130]: time="2026-03-25T10:39:03+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Mar 25 10:39:03 katarynka go-librespot[1130]: time="2026-03-25T10:39:03+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Mar 25 10:39:03 katarynka go-librespot[1130]: time="2026-03-25T10:39:03+01:00" level=info msg="zeroconf server listening on port 39455" Mar 25 10:39:03 katarynka go-librespot[1130]: time="2026-03-25T10:39:03+01:00" level=debug msg="obtained new client token: AABMAyGCtP1YiNzWGQICyiteIfPbQnHZAAwkG92pNyJ0vDv5sZYeDf/JhsjEOuz/ISvT7fCWYJz+PlT0nNP4HeKPJYQMQH3WqiM3WmTFFRt8h6KbZJyuINwm7Dm+V9dVqPYqraRm47YRoblpKlYW+u/TcvnGEQFjrUmgN2zHcQJt/13mSYAPWUOWQyUuWEAAu3sPfJZA1pJc/pOspRfutdRH9Qb0OYGn3bScueA0so75+b6OZmZscHOdEbE=" Mar 25 10:39:04 katarynka go-librespot[1130]: time="2026-03-25T10:39:04+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 10:39:04 katarynka go-librespot[1130]: time="2026-03-25T10:39:04+01:00" level=debug msg="completed keyexchange" Mar 25 10:39:04 katarynka go-librespot[1130]: time="2026-03-25T10:39:04+01:00" level=debug msg="completed challenge" Mar 25 10:39:04 katarynka go-librespot[1130]: time="2026-03-25T10:39:04+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 25 10:39:04 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 10:39:04 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 10:39:04 katarynka volumio[1040]: info: Loading plugin "outputs"... Mar 25 10:39:04 katarynka volumio[1040]: info: Loading plugin "albumart"... Mar 25 10:39:04 katarynka volumio[1040]: info: Plugin example_plugin is not enabled Mar 25 10:39:04 katarynka volumio[1040]: info: Loading plugin "inputs"... Mar 25 10:39:04 katarynka volumio[1040]: info: Loading plugin "updater_comm"... Mar 25 10:39:05 katarynka volumio[1040]: info: Plugin mpdemulation is not enabled Mar 25 10:39:05 katarynka volumio[1040]: info: Loading plugin "rest_api"... Mar 25 10:39:05 katarynka volumio[1040]: info: Loading plugin "websocket"... Mar 25 10:39:05 katarynka volumio[1040]: info: Starting Socket.io Server version 1.7.4 Mar 25 10:39:05 katarynka volumio[1040]: info: Loading i18n strings for locale pl Mar 25 10:39:05 katarynka volumio[1040]: Updating browse sources language Mar 25 10:39:05 katarynka volumio[1040]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 25 10:39:05 katarynka volumio[1040]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 25 10:39:05 katarynka volumio[1040]: info: CoreCommandRouter::initPlayerControls Mar 25 10:39:05 katarynka volumio[1040]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 10:39:05 katarynka volumio[1040]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 10:39:05 katarynka volumio[1040]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 10:39:05 katarynka volumio[1040]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 10:39:05 katarynka volumio[1040]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 10:39:05 katarynka volumio[1040]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 10:39:05 katarynka volumio[1040]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 10:39:05 katarynka volumio[1040]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 10:39:05 katarynka volumio[1040]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 25 10:39:05 katarynka volumio[1040]: Express server listening on port 3000 Mar 25 10:39:05 katarynka volumio[1040]: [Metrics] WebUI: 12s 584.48ms Mar 25 10:39:05 katarynka volumio[1040]: info: CoreStateMachine::resetVolumioState Mar 25 10:39:05 katarynka volumio[1040]: info: CoreStateMachine::getcurrentVolume Mar 25 10:39:05 katarynka volumio[1040]: info: CoreCommandRouter::volumioRetrievevolume Mar 25 10:39:05 katarynka volumio[1040]: info: Cannot read play queue from file Mar 25 10:39:05 katarynka volumio[1040]: info: Volumio Network Manager: Network status updated: 2 Mar 25 10:39:05 katarynka volumio[1138]: Forking 3 albumart workers Mar 25 10:39:06 katarynka volumio[1040]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 10:39:06 katarynka volumio[1040]: info: CoreStateMachine::setRepeat null single undefined Mar 25 10:39:06 katarynka volumio[1040]: info: CoreStateMachine::pushState Mar 25 10:39:06 katarynka volumio[1040]: info: CorePlayQueue::getTrack 0 Mar 25 10:39:06 katarynka volumio[1040]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 25 10:39:06 katarynka volumio[1040]: info: CoreCommandRouter::volumioPushState Mar 25 10:39:06 katarynka volumio[1040]: info: CoreStateMachine::setRandom null Mar 25 10:39:06 katarynka volumio[1040]: info: CoreStateMachine::pushState Mar 25 10:39:06 katarynka volumio[1040]: info: CorePlayQueue::getTrack 0 Mar 25 10:39:06 katarynka volumio[1040]: info: CoreCommandRouter::volumioPushState Mar 25 10:39:06 katarynka volumio[1040]: info: Setting Device type: Raspberry PI Mar 25 10:39:06 katarynka volumio[1040]: info: Completed loading Core Plugins Mar 25 10:39:06 katarynka volumio[1040]: info: Preparing to generate the ALSA configuration file Mar 25 10:39:06 katarynka volumio[1040]: info: VolumeController:: Volume=96 Mute =false Mar 25 10:39:06 katarynka volumio[1040]: info: CoreStateMachine::pushState Mar 25 10:39:06 katarynka volumio[1040]: info: CorePlayQueue::getTrack 0 Mar 25 10:39:06 katarynka volumio[1040]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 25 10:39:06 katarynka volumio[1040]: info: CoreCommandRouter::volumioPushState Mar 25 10:39:06 katarynka volumio[1040]: info: CoreStateMachine::updateTrackBlock Mar 25 10:39:06 katarynka volumio[1040]: info: CorePlayQueue::getTrackBlock Mar 25 10:39:06 katarynka volumio[1040]: info: CoreCommandRouter::volumioRetrievevolume Mar 25 10:39:06 katarynka volumio[1040]: info: Asound.conf file unchanged, so no further update is needed Mar 25 10:39:06 katarynka volumio[1040]: info: Output device has changed, restarting MPD Mar 25 10:39:06 katarynka volumio[1040]: info: Output device has changed, restarting Shairport Sync Mar 25 10:39:06 katarynka volumio[1040]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 10:39:06 katarynka volumio[1040]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 10:39:06 katarynka sudo[1193]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 25 10:39:06 katarynka sudo[1193]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 10:39:06 katarynka sudo[1193]: pam_unix(sudo:session): session closed for user root Mar 25 10:39:06 katarynka sudo[1195]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 25 10:39:06 katarynka sudo[1195]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 10:39:06 katarynka volumio[1040]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 25 10:39:06 katarynka volumio[1040]: info: ___________ START PLUGINS ___________ Mar 25 10:39:06 katarynka volumio[1040]: info: ControllerMpd::onStart: Initializing MPD Mar 25 10:39:06 katarynka volumio[1040]: info: Creating MPD Configuration file Mar 25 10:39:06 katarynka systemd[1]: Stopping mpd.service - Music Player Daemon... Mar 25 10:39:06 katarynka volumio[1040]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 25 10:39:06 katarynka volumio[1040]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 25 10:39:06 katarynka volumio[1040]: info: [1774431546701] CoreMusicLibrary::Adding element Serwery Mediów Mar 25 10:39:06 katarynka volumio[1040]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 25 10:39:06 katarynka volumio[1040]: info: UPNP Browser: Client initialized successfully Mar 25 10:39:06 katarynka sudo[1203]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 25 10:39:06 katarynka sudo[1203]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 10:39:06 katarynka volumio[1040]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 10:39:06 katarynka volumio[1040]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 10:39:06 katarynka systemd[1]: mpd.service: Deactivated successfully. Mar 25 10:39:06 katarynka systemd[1]: Stopped mpd.service - Music Player Daemon. Mar 25 10:39:06 katarynka systemd[1]: mpd.service: Consumed 7.800s CPU time. Mar 25 10:39:06 katarynka systemd[1]: mpd.socket: Deactivated successfully. Mar 25 10:39:06 katarynka systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Mar 25 10:39:06 katarynka systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Mar 25 10:39:06 katarynka sudo[1203]: pam_unix(sudo:session): session closed for user root Mar 25 10:39:06 katarynka sudo[1205]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 25 10:39:06 katarynka sudo[1205]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 10:39:06 katarynka volumio[1040]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 25 10:39:06 katarynka volumio[1040]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 10:39:06 katarynka volumio[1040]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 10:39:06 katarynka systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Mar 25 10:39:06 katarynka systemd[1]: Starting mpd.service - Music Player Daemon... Mar 25 10:39:06 katarynka volumio[1040]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 25 10:39:06 katarynka volumio[1040]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 25 10:39:06 katarynka volumio[1040]: info: [1774431546980] CoreMusicLibrary::Adding element Last_100 Mar 25 10:39:06 katarynka volumio[1040]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 25 10:39:06 katarynka systemd[1]: mpd.service: Deactivated successfully. Mar 25 10:39:06 katarynka systemd[1]: Stopped mpd.service - Music Player Daemon. Mar 25 10:39:07 katarynka systemd[1]: mpd.socket: Deactivated successfully. Mar 25 10:39:07 katarynka systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Mar 25 10:39:07 katarynka systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Mar 25 10:39:07 katarynka volumio[1040]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 25 10:39:07 katarynka volumio[1040]: info: [1774431547021] CoreMusicLibrary::Adding element Webradio Mar 25 10:39:07 katarynka volumio[1040]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 25 10:39:07 katarynka systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Mar 25 10:39:07 katarynka volumio[1040]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 25 10:39:07 katarynka systemd[1]: Starting mpd.service - Music Player Daemon... Mar 25 10:39:07 katarynka volumio[1040]: info: Initializing BBC Radios Mar 25 10:39:07 katarynka volumio[1040]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 25 10:39:07 katarynka volumio[1040]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 10:39:07 katarynka volumio[1040]: info: Creating Spotify config file Mar 25 10:39:07 katarynka volumio[1040]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 10:39:07 katarynka volumio-remote-updater[622]: [2026-03-25 10:39:07] [connect] Successful connection Mar 25 10:39:07 katarynka sudo[1219]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Mar 25 10:39:07 katarynka sudo[1219]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Mar 25 10:39:07 katarynka sudo[1219]: pam_unix(sudo:session): session closed for user root Mar 25 10:39:07 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 18. Mar 25 10:39:07 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 10:39:08 katarynka go-librespot[1238]: go-librespot daemon starting... Mar 25 10:39:08 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 10:39:08 katarynka go-librespot[1243]: time="2026-03-25T10:39:08+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 10:39:08 katarynka volumio[1040]: info: Volumio Calling Home Mar 25 10:39:08 katarynka go-librespot[1243]: time="2026-03-25T10:39:08+01:00" level=info msg="zeroconf server listening on port 40959" Mar 25 10:39:09 katarynka volumio[1156]: Starting albumart workers Mar 25 10:39:09 katarynka volumio[1040]: info: Discovery: adding 4d616d77-6a8c-4da2-85a4-840d70f98e51 Mar 25 10:39:09 katarynka volumio[1040]: info: Discovery: Found device katarynka Mar 25 10:39:09 katarynka volumio[1159]: Starting albumart workers Mar 25 10:39:09 katarynka volumio[1040]: info: CoreCommandRouter::volumioGetState Mar 25 10:39:09 katarynka volumio[1040]: info: CorePlayQueue::getTrack 0 Mar 25 10:39:10 katarynka volumio[1040]: info: MPD Permissions set Mar 25 10:39:10 katarynka volumio[1040]: info: MPD Permissions set Mar 25 10:39:10 katarynka volumio[1040]: info: VolumeController:: Volume=96 Mute =false Mar 25 10:39:10 katarynka volumio[1040]: info: CoreStateMachine::pushState Mar 25 10:39:10 katarynka sudo[1269]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 25 10:39:10 katarynka sudo[1269]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 10:39:10 katarynka sudo[1267]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 25 10:39:10 katarynka sudo[1267]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 10:39:10 katarynka volumio[1040]: info: CorePlayQueue::getTrack 0 Mar 25 10:39:10 katarynka volumio[1040]: info: CoreCommandRouter::volumioPushState Mar 25 10:39:10 katarynka sudo[1267]: pam_unix(sudo:session): session closed for user root Mar 25 10:39:10 katarynka sudo[1269]: pam_unix(sudo:session): session closed for user root Mar 25 10:39:10 katarynka volumio[1040]: info: Discovery: this is already registered, 4d616d77-6a8c-4da2-85a4-840d70f98e51 Mar 25 10:39:10 katarynka volumio[1040]: info: Discovery: Found device katarynka Mar 25 10:39:10 katarynka volumio[1040]: info: CoreCommandRouter::volumioGetState Mar 25 10:39:10 katarynka volumio[1040]: info: CorePlayQueue::getTrack 0 Mar 25 10:39:10 katarynka volumio-remote-updater[622]: [2026-03-25 10:39:10] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1774431547 101 Mar 25 10:39:10 katarynka volumio[1040]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 1 Mar 25 10:39:10 katarynka volumio[1040]: info: Volumio called home Mar 25 10:39:10 katarynka volumio[1040]: info: Spotify config file written Mar 25 10:39:10 katarynka sudo[1274]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Mar 25 10:39:10 katarynka sudo[1274]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 10:39:10 katarynka volumio[1158]: Starting albumart workers Mar 25 10:39:10 katarynka systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Mar 25 10:39:10 katarynka volumio[1040]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Mar 25 10:39:10 katarynka systemd[1]: go-librespot-daemon.service: Deactivated successfully. Mar 25 10:39:10 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 10:39:10 katarynka volumio[1040]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 10:39:10 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 10:39:10 katarynka go-librespot[1278]: go-librespot daemon starting... Mar 25 10:39:10 katarynka sudo[1274]: pam_unix(sudo:session): session closed for user root Mar 25 10:39:10 katarynka volumio[1040]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 10:39:10 katarynka volumio[1040]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 10:39:10 katarynka volumio[1040]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 10:39:10 katarynka volumio[1040]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 10:39:10 katarynka volumio[1040]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 10:39:10 katarynka volumio[1040]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 10:39:10 katarynka volumio[1040]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 10:39:10 katarynka go-librespot[1279]: time="2026-03-25T10:39:10+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 10:39:10 katarynka go-librespot[1279]: time="2026-03-25T10:39:10+01:00" level=debug msg="app state loaded" Mar 25 10:39:10 katarynka go-librespot[1279]: time="2026-03-25T10:39:10+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 10:39:10 katarynka volumio[1040]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 10:39:10 katarynka volumio[1040]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 10:39:10 katarynka volumio[1040]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 10:39:10 katarynka volumio[1040]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 10:39:10 katarynka volumio[1040]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 10:39:10 katarynka volumio[1040]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 10:39:10 katarynka volumio[1040]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 10:39:10 katarynka volumio[1040]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 10:39:10 katarynka volumio[1040]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 10:39:10 katarynka volumio[1040]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 10:39:11 katarynka volumio[1040]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 10:39:11 katarynka volumio[1040]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 25 10:39:11 katarynka volumio[1040]: info: No need to fix Spotify hosts Mar 25 10:39:11 katarynka go-librespot[1279]: time="2026-03-25T10:39:11+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 25 10:39:11 katarynka go-librespot[1279]: time="2026-03-25T10:39:11+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 25 10:39:11 katarynka go-librespot[1279]: time="2026-03-25T10:39:11+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 25 10:39:11 katarynka go-librespot[1279]: time="2026-03-25T10:39:11+01:00" level=info msg="zeroconf server listening on port 45301" Mar 25 10:39:11 katarynka go-librespot[1279]: time="2026-03-25T10:39:11+01:00" level=debug msg="obtained new client token: AAAo5mPa5BONlxWDIrZFJqp11phbYWGzhsxxDE4xDbD3Tl1qmvtBKy2a8/108kBCqHHS0wAg8W6rluXT1iiqiax0PGQ2ccVhbZVLWBQiLbr2gxNUvNK2A5Lq2AjGD+VmVDK73FE73j/+a81UPwudDx6AfuRSwS476j8u7HpNonnw1ruzG+WNmYtR2Ks5CINff0W6Ocmhf1GQvhFYrVotsyX2wlJf4Akw6urOHRfM1MLb6iqK5TkEKv8ufBI=" Mar 25 10:39:11 katarynka go-librespot[1279]: time="2026-03-25T10:39:11+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 10:39:11 katarynka volumio[1040]: info: Starting Shairport Sync Mar 25 10:39:11 katarynka volumio[1040]: info: Starting Shairport Sync Mar 25 10:39:11 katarynka go-librespot[1279]: time="2026-03-25T10:39:11+01:00" level=debug msg="completed keyexchange" Mar 25 10:39:11 katarynka go-librespot[1279]: time="2026-03-25T10:39:11+01:00" level=debug msg="completed challenge" Mar 25 10:39:11 katarynka volumio[1040]: info: Starting Shairport Sync Mar 25 10:39:11 katarynka go-librespot[1279]: time="2026-03-25T10:39:11+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 25 10:39:11 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 10:39:11 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 10:39:11 katarynka sudo[1306]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 25 10:39:12 katarynka sudo[1306]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 10:39:12 katarynka sudo[1308]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 25 10:39:12 katarynka sudo[1311]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 25 10:39:12 katarynka sudo[1311]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 10:39:12 katarynka sudo[1308]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 10:39:12 katarynka sudo[1312]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Mar 25 10:39:12 katarynka sudo[1312]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 10:39:12 katarynka systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Mar 25 10:39:12 katarynka volumio[1040]: info: CoreCommandRouter::volumioGetState Mar 25 10:39:12 katarynka volumio[1040]: info: CorePlayQueue::getTrack 0 Mar 25 10:39:12 katarynka systemd[1]: shairport-sync.service: Deactivated successfully. Mar 25 10:39:12 katarynka systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 25 10:39:12 katarynka systemd[1]: shairport-sync.service: Consumed 2.240s CPU time. Mar 25 10:39:12 katarynka systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Mar 25 10:39:12 katarynka sudo[1306]: pam_unix(sudo:session): session closed for user root Mar 25 10:39:12 katarynka volumio[1040]: info: An error occurred while refreshing Spotify Token Error: Bad Request Mar 25 10:39:12 katarynka volumio[1040]: info: Shairport-Sync Started Mar 25 10:39:12 katarynka sudo[1308]: pam_unix(sudo:session): session closed for user root Mar 25 10:39:12 katarynka volumio[1040]: Error adding Membership: Error: addMembership EINVAL Mar 25 10:39:12 katarynka volumio[1040]: info: Shairport-Sync Started Mar 25 10:39:12 katarynka sudo[1311]: pam_unix(sudo:session): session closed for user root Mar 25 10:39:12 katarynka volumio[1040]: info: Shairport-Sync Started Mar 25 10:39:12 katarynka sudo[1312]: pam_unix(sudo:session): session closed for user root Mar 25 10:39:12 katarynka volumio[1040]: info: Upmpdcli Daemon Started Mar 25 10:39:14 katarynka volumio[1040]: info: go-librespot daemon successfully initialized Mar 25 10:39:15 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Mar 25 10:39:15 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 10:39:15 katarynka mpd[1237]: 2026-03-25T10:39:15 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Mar 25 10:39:15 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 10:39:15 katarynka go-librespot[1345]: go-librespot daemon starting... Mar 25 10:39:15 katarynka systemd[1]: Started mpd.service - Music Player Daemon. Mar 25 10:39:15 katarynka sudo[1195]: pam_unix(sudo:session): session closed for user root Mar 25 10:39:15 katarynka sudo[1205]: pam_unix(sudo:session): session closed for user root Mar 25 10:39:15 katarynka go-librespot[1348]: time="2026-03-25T10:39:15+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 10:39:15 katarynka go-librespot[1348]: time="2026-03-25T10:39:15+01:00" level=debug msg="app state loaded" Mar 25 10:39:15 katarynka go-librespot[1348]: time="2026-03-25T10:39:15+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 10:39:15 katarynka volumio[1040]: info: Completed starting Core Plugins Mar 25 10:39:15 katarynka volumio[1040]: info: ------------------------------------------- Mar 25 10:39:15 katarynka volumio[1040]: info: ----- MyVolumio plugins startup ---- Mar 25 10:39:15 katarynka volumio[1040]: info: ------------------------------------------- Mar 25 10:39:15 katarynka volumio[1040]: info: [MyVolumio PluginManager] Fetching plans data.... Mar 25 10:39:15 katarynka volumio[1040]: error: MPD error: The expression evaluated to a falsy value: Mar 25 10:39:15 katarynka volumio[1040]: assert.ok(self.idling) Mar 25 10:39:15 katarynka volumio[1040]: error: The expression evaluated to a falsy value: Mar 25 10:39:15 katarynka volumio[1040]: assert.ok(self.idling) Mar 25 10:39:15 katarynka volumio[1040]: info: MPD running with PID1237 Mar 25 10:39:15 katarynka volumio[1040]: ,establishing connection Mar 25 10:39:15 katarynka volumio[1040]: error: updateQueue error: null Mar 25 10:39:15 katarynka volumio[1040]: error: updateQueue error: null Mar 25 10:39:15 katarynka go-librespot[1348]: time="2026-03-25T10:39:15+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Mar 25 10:39:15 katarynka go-librespot[1348]: time="2026-03-25T10:39:15+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Mar 25 10:39:15 katarynka go-librespot[1348]: time="2026-03-25T10:39:15+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Mar 25 10:39:15 katarynka go-librespot[1348]: time="2026-03-25T10:39:15+01:00" level=info msg="zeroconf server listening on port 39217" Mar 25 10:39:15 katarynka go-librespot[1348]: time="2026-03-25T10:39:15+01:00" level=debug msg="obtained new client token: AAAP38wAhuIvRWeGmlXtEfZ8oimt4g7FpZFE9dzlX8OjtKov+7sYVpnevvoElPU0HJXtoCkUkutZllF2isvdPoEhmsvocOMsMm9R/+gdnv2XX0qpAhr6CwLudXHw80v+VHu/pURPfpMbclkMusfranmAud+ykwKSO8AlxPWFCfzgmchsia1XwyxyUzs8SaXQdYNDhj2w7wld6sZUuFd8OF3pLvcGNGpnrJYN7Hqmcqv7V14aDPb9oeDCPM4=" Mar 25 10:39:15 katarynka go-librespot[1348]: time="2026-03-25T10:39:15+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 10:39:16 katarynka go-librespot[1348]: time="2026-03-25T10:39:16+01:00" level=debug msg="completed keyexchange" Mar 25 10:39:16 katarynka go-librespot[1348]: time="2026-03-25T10:39:16+01:00" level=debug msg="completed challenge" Mar 25 10:39:16 katarynka go-librespot[1348]: time="2026-03-25T10:39:16+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 25 10:39:16 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 10:39:16 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 10:39:17 katarynka volumio[1040]: info: Initializing connection to go-librespot Websocket Mar 25 10:39:17 katarynka volumio[1040]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 25 10:39:18 katarynka sudo[1361]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Mar 25 10:39:18 katarynka sudo[1361]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 10:39:18 katarynka sudo[1367]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Mar 25 10:39:18 katarynka sudo[1367]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 10:39:18 katarynka systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Mar 25 10:39:18 katarynka systemd[1]: mpd_monitor.service: Deactivated successfully. Mar 25 10:39:18 katarynka systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Mar 25 10:39:18 katarynka systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Mar 25 10:39:18 katarynka sudo[1361]: pam_unix(sudo:session): session closed for user root Mar 25 10:39:18 katarynka mpd_monitor.sh[1380]: MPD Monitor Service: Starting MPD Monitor Service Mar 25 10:39:18 katarynka sudo[1367]: pam_unix(sudo:session): session closed for user root Mar 25 10:39:18 katarynka volumio[1040]: info: Successfully started MPD Monitor Mar 25 10:39:18 katarynka volumio[1040]: info: Successfully started MPD Monitor Mar 25 10:39:19 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Mar 25 10:39:19 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 10:39:19 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 10:39:19 katarynka go-librespot[1384]: go-librespot daemon starting... Mar 25 10:39:19 katarynka go-librespot[1385]: time="2026-03-25T10:39:19+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 10:39:19 katarynka go-librespot[1385]: time="2026-03-25T10:39:19+01:00" level=debug msg="app state loaded" Mar 25 10:39:19 katarynka go-librespot[1385]: time="2026-03-25T10:39:19+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 10:39:19 katarynka go-librespot[1385]: time="2026-03-25T10:39:19+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 25 10:39:19 katarynka go-librespot[1385]: time="2026-03-25T10:39:19+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 25 10:39:19 katarynka go-librespot[1385]: time="2026-03-25T10:39:19+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 25 10:39:19 katarynka go-librespot[1385]: time="2026-03-25T10:39:19+01:00" level=info msg="zeroconf server listening on port 43997" Mar 25 10:39:19 katarynka go-librespot[1385]: time="2026-03-25T10:39:19+01:00" level=debug msg="obtained new client token: AAAgNKB2emMdTR9n8zi7vhTILyj6SJwJeLa8mGkSG7cMw7XcvGqg0REO0qWKd0lTOhDwoV+rohtHf9RlYtjSSk/x9HF3TtXG3mRpyvVF5BwlwVKOPH+4Dh0aOZPpGhBFIRSzeiDwTaCS6UPfzdpzYX7bhXhj21eNwPbgulp4nRPfcbeZpy84IkuvMcXSdva1pghh8Y0zWFRRZDrnkF7Jy090eMc7e0qo3qEnasHDORWAt+DkrgGMUxzDMjo=" Mar 25 10:39:19 katarynka go-librespot[1385]: time="2026-03-25T10:39:19+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 10:39:19 katarynka go-librespot[1385]: time="2026-03-25T10:39:19+01:00" level=debug msg="completed keyexchange" Mar 25 10:39:19 katarynka go-librespot[1385]: time="2026-03-25T10:39:19+01:00" level=debug msg="completed challenge" Mar 25 10:39:19 katarynka go-librespot[1385]: time="2026-03-25T10:39:19+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 25 10:39:20 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 10:39:20 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 10:39:20 katarynka volumio[1040]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Mar 25 10:39:20 katarynka volumio[1040]: info: Initializing connection to go-librespot Websocket Mar 25 10:39:20 katarynka volumio[1040]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 25 10:39:23 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Mar 25 10:39:23 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 10:39:23 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 10:39:23 katarynka go-librespot[1392]: go-librespot daemon starting... Mar 25 10:39:23 katarynka go-librespot[1393]: time="2026-03-25T10:39:23+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 10:39:23 katarynka go-librespot[1393]: time="2026-03-25T10:39:23+01:00" level=debug msg="app state loaded" Mar 25 10:39:23 katarynka go-librespot[1393]: time="2026-03-25T10:39:23+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 10:39:23 katarynka go-librespot[1393]: time="2026-03-25T10:39:23+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Mar 25 10:39:23 katarynka go-librespot[1393]: time="2026-03-25T10:39:23+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Mar 25 10:39:23 katarynka go-librespot[1393]: time="2026-03-25T10:39:23+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Mar 25 10:39:23 katarynka go-librespot[1393]: time="2026-03-25T10:39:23+01:00" level=info msg="zeroconf server listening on port 46507" Mar 25 10:39:23 katarynka volumio[1040]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Mar 25 10:39:23 katarynka volumio[1040]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Mar 25 10:39:23 katarynka volumio[1040]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Mar 25 10:39:23 katarynka volumio[1040]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Mar 25 10:39:23 katarynka volumio[1040]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Mar 25 10:39:23 katarynka volumio[1040]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Mar 25 10:39:23 katarynka volumio[1040]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Mar 25 10:39:23 katarynka volumio[1040]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Mar 25 10:39:23 katarynka volumio[1040]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Mar 25 10:39:23 katarynka volumio[1040]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Mar 25 10:39:23 katarynka volumio[1040]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Mar 25 10:39:23 katarynka volumio[1040]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Mar 25 10:39:23 katarynka volumio[1040]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Mar 25 10:39:23 katarynka volumio[1040]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Mar 25 10:39:23 katarynka volumio[1040]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Mar 25 10:39:23 katarynka volumio[1040]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Mar 25 10:39:23 katarynka volumio[1040]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Mar 25 10:39:23 katarynka volumio[1040]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Mar 25 10:39:23 katarynka volumio[1040]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Mar 25 10:39:23 katarynka volumio[1040]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Mar 25 10:39:23 katarynka volumio[1040]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Mar 25 10:39:23 katarynka volumio[1040]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Mar 25 10:39:23 katarynka volumio[1040]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Mar 25 10:39:23 katarynka volumio[1040]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Mar 25 10:39:23 katarynka volumio[1040]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Mar 25 10:39:23 katarynka volumio[1040]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Mar 25 10:39:23 katarynka volumio[1040]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Mar 25 10:39:23 katarynka volumio[1040]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Mar 25 10:39:23 katarynka volumio[1040]: info: Adding plugin bluetooth to MyMusic Plugins Mar 25 10:39:23 katarynka volumio[1040]: info: Adding plugin multiroom to MyMusic Plugins Mar 25 10:39:23 katarynka volumio[1040]: info: Adding plugin metavolumio to MyMusic Plugins Mar 25 10:39:23 katarynka volumio[1040]: info: Adding plugin cd_controller to MyMusic Plugins Mar 25 10:39:23 katarynka volumio[1040]: info: Adding plugin qobuzconnect to MyMusic Plugins Mar 25 10:39:23 katarynka volumio[1040]: info: Adding plugin smart_inputs to MyMusic Plugins Mar 25 10:39:23 katarynka volumio[1040]: info: Adding plugin tidalconnect to MyMusic Plugins Mar 25 10:39:23 katarynka volumio[1040]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Mar 25 10:39:23 katarynka go-librespot[1393]: time="2026-03-25T10:39:23+01:00" level=debug msg="obtained new client token: AABYf1P8VDRWvocH3uvTu2GB7qgK47gFyc0gDv88fSxUKh0GcZtBHxF+yhJp1bL/fjloGN9zhYVSTl2gcL9PpVgaPR4EB1mB+IupZ6Oc1n7qOqPt7kW5xz87gwCUm7b1oT0SUOIY+bXguQrcH//IhV/Ig8OeHNApXN4qBgvvDDgMmPHTCq9dmwk5TZs+8iqWSqqpdGRzjnFu8fOMSAL1Yd4pQLi+JNRO6Z73W7Gx+pRJ1JJ9Y/RgYtufzYA=" Mar 25 10:39:23 katarynka go-librespot[1393]: time="2026-03-25T10:39:23+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 10:39:23 katarynka go-librespot[1393]: time="2026-03-25T10:39:23+01:00" level=debug msg="completed keyexchange" Mar 25 10:39:23 katarynka go-librespot[1393]: time="2026-03-25T10:39:23+01:00" level=debug msg="completed challenge" Mar 25 10:39:24 katarynka go-librespot[1393]: time="2026-03-25T10:39:24+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 25 10:39:24 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 10:39:24 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 10:39:25 katarynka volumio[1040]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Mar 25 10:39:25 katarynka volumio[1040]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Mar 25 10:39:25 katarynka volumio[1040]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 10:39:25 katarynka volumio[1040]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 10:39:25 katarynka volumio[1040]: info: Starting MyVolumio Remote Streaming Endpoints Mar 25 10:39:25 katarynka volumio[1040]: info: MyVolumio login type: Token Mar 25 10:39:25 katarynka volumio[1040]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Mar 25 10:39:25 katarynka volumio[1040]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Mar 25 10:39:27 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Mar 25 10:39:27 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 10:39:27 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 10:39:27 katarynka go-librespot[1400]: go-librespot daemon starting... Mar 25 10:39:27 katarynka go-librespot[1401]: time="2026-03-25T10:39:27+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 10:39:27 katarynka go-librespot[1401]: time="2026-03-25T10:39:27+01:00" level=debug msg="app state loaded" Mar 25 10:39:27 katarynka go-librespot[1401]: time="2026-03-25T10:39:27+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 10:39:27 katarynka volumio[1040]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Mar 25 10:39:27 katarynka volumio[1040]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Mar 25 10:39:27 katarynka volumio[1040]: info: Streaming services startup Mar 25 10:39:27 katarynka volumio[1040]: info: Starting Streaming Daemon Mar 25 10:39:27 katarynka go-librespot[1401]: time="2026-03-25T10:39:27+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 25 10:39:27 katarynka go-librespot[1401]: time="2026-03-25T10:39:27+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 25 10:39:27 katarynka go-librespot[1401]: time="2026-03-25T10:39:27+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 25 10:39:27 katarynka go-librespot[1401]: time="2026-03-25T10:39:27+01:00" level=info msg="zeroconf server listening on port 41805" Mar 25 10:39:27 katarynka sudo[1409]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Mar 25 10:39:27 katarynka sudo[1409]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 10:39:27 katarynka volumio[1040]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Mar 25 10:39:27 katarynka sudo[1409]: pam_unix(sudo:session): session closed for user root Mar 25 10:39:27 katarynka volumio[1040]: info: Initializing connection to go-librespot Websocket Mar 25 10:39:27 katarynka go-librespot[1401]: time="2026-03-25T10:39:27+01:00" level=debug msg="obtained new client token: AAAjRlkPrauV0RhFo2l15aMXBkKm1GAewHEEe/fVDx2rDr/dw/z5/99/lR2MZUqAMXDp7IEy3r1qw5N/KXxb2mOU72gALQRWBVufCTv4PP1gD6AUcUkBqRtll7nvYFS8O5dVISDUop0BLCayb/zImG//5xOW+qddOsY+2VzmK+qiAGIFh05EQ3Rnf+hsycpbsALrscgXCHE/f2Ga4DJwq5kZQEYt2bwfd/evVRZ8guwEI9CY9CVR3FXGW2w=" Mar 25 10:39:27 katarynka volumio[1040]: error: Cannot start Volumio Streaming Daemon Mar 25 10:39:27 katarynka volumio[1040]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Mar 25 10:39:27 katarynka volumio[1040]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Mar 25 10:39:27 katarynka go-librespot[1401]: time="2026-03-25T10:39:27+01:00" level=debug msg="new websocket client" Mar 25 10:39:27 katarynka volumio[1040]: info: Connection to go-librespot Websocket established Mar 25 10:39:28 katarynka go-librespot[1401]: time="2026-03-25T10:39:27+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 10:39:28 katarynka go-librespot[1401]: time="2026-03-25T10:39:28+01:00" level=debug msg="completed keyexchange" Mar 25 10:39:28 katarynka go-librespot[1401]: time="2026-03-25T10:39:28+01:00" level=debug msg="completed challenge" Mar 25 10:39:28 katarynka go-librespot[1401]: time="2026-03-25T10:39:28+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 25 10:39:28 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 10:39:28 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 10:39:28 katarynka volumio[1040]: info: Connection to go-librespot Websocket closed Mar 25 10:39:28 katarynka volumio[1040]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Mar 25 10:39:29 katarynka volumio[1040]: info: MyVolumio token set successfully Mar 25 10:39:29 katarynka volumio[1040]: info: MYVOLUMIO: Adding device Mar 25 10:39:29 katarynka volumio[1040]: info: MYVOLUMIO: Evaluating Server Mar 25 10:39:30 katarynka volumio[1040]: info: MyVolumio status changed Mar 25 10:39:30 katarynka volumio[1040]: info: Streaming services startup Mar 25 10:39:30 katarynka volumio[1040]: info: Starting Streaming Daemon Mar 25 10:39:30 katarynka volumio[1040]: info: Removing browser output: myVolumio user plan is not superstar Mar 25 10:39:30 katarynka volumio[1040]: info: Removing audio output: Mar 25 10:39:30 katarynka volumio[1040]: info: Stoppping Tunnel 1 Mar 25 10:39:30 katarynka sudo[1451]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Mar 25 10:39:30 katarynka sudo[1451]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 10:39:30 katarynka sudo[1453]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Mar 25 10:39:30 katarynka sudo[1453]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 25 10:39:30 katarynka sudo[1451]: pam_unix(sudo:session): session closed for user root Mar 25 10:39:30 katarynka volumio[1040]: error: Cannot start Volumio Streaming Daemon Mar 25 10:39:30 katarynka volumio[1040]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Mar 25 10:39:30 katarynka volumio[1040]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Mar 25 10:39:30 katarynka systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Mar 25 10:39:30 katarynka systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Mar 25 10:39:30 katarynka systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Mar 25 10:39:30 katarynka systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Mar 25 10:39:30 katarynka systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Mar 25 10:39:30 katarynka systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Mar 25 10:39:30 katarynka systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Mar 25 10:39:30 katarynka systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Mar 25 10:39:30 katarynka sudo[1453]: pam_unix(sudo:session): session closed for user root Mar 25 10:39:30 katarynka volumio[1040]: info: Remote SSH Stopped Mar 25 10:39:30 katarynka volumio[1040]: info: Setting Geolocation for MyVolumio to eu6 Mar 25 10:39:30 katarynka volumio[1040]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 10:39:30 katarynka volumio[1040]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 10:39:30 katarynka volumio[1040]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 25 10:39:30 katarynka volumio[1040]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Mar 25 10:39:31 katarynka volumio[1040]: info: Getting Spotify volume Mar 25 10:39:31 katarynka volumio[1040]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 25 10:39:31 katarynka volumio[1040]: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 25 10:39:31 katarynka volumio[1040]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Mar 25 10:39:31 katarynka volumio[1040]: errno: -111, Mar 25 10:39:31 katarynka volumio[1040]: code: 'ECONNREFUSED', Mar 25 10:39:31 katarynka volumio[1040]: syscall: 'connect', Mar 25 10:39:31 katarynka volumio[1040]: address: '127.0.0.1', Mar 25 10:39:31 katarynka volumio[1040]: port: 9879, Mar 25 10:39:31 katarynka volumio[1040]: response: undefined Mar 25 10:39:31 katarynka volumio[1040]: } Mar 25 10:39:31 katarynka volumio[1040]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 25 10:39:31 katarynka systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Mar 25 10:39:31 katarynka systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Mar 25 10:39:31 katarynka systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Mar 25 10:39:31 katarynka go-librespot[1467]: go-librespot daemon starting... Mar 25 10:39:31 katarynka go-librespot[1469]: time="2026-03-25T10:39:31+01:00" level=info msg="running go-librespot 0.4.0" Mar 25 10:39:31 katarynka go-librespot[1469]: time="2026-03-25T10:39:31+01:00" level=debug msg="app state loaded" Mar 25 10:39:31 katarynka go-librespot[1469]: time="2026-03-25T10:39:31+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 25 10:39:31 katarynka go-librespot[1469]: time="2026-03-25T10:39: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-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 25 10:39:31 katarynka go-librespot[1469]: time="2026-03-25T10:39:31+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 25 10:39:31 katarynka go-librespot[1469]: time="2026-03-25T10:39:31+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 25 10:39:31 katarynka go-librespot[1469]: time="2026-03-25T10:39:31+01:00" level=info msg="zeroconf server listening on port 34593" Mar 25 10:39:31 katarynka go-librespot[1469]: time="2026-03-25T10:39:31+01:00" level=debug msg="obtained new client token: AABdD/YTKpfgBw1oo4mqsAe6XEDcgJupujifHd570/6Lnec+rz24UFWUain+eJ6QTdwk2TKSgr9nF1M4I1Qh4OjI3G0n/kaV0FcriW7yg8IPaoS23fT6ZlwKjMLl9vTOA+DeT2sY24fasGGXiS0P2+n+nfWsE2zjFTkAW/vrVDXWJMcAzzPwX89dyC3+dRv7RJ54KpO3rhLwTxNtuMbuBshpdkIs1Ed7gYohRNHImOUfHytJYJJk8MHMnzg=" Mar 25 10:39:31 katarynka go-librespot[1469]: time="2026-03-25T10:39:31+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 25 10:39:32 katarynka go-librespot[1469]: time="2026-03-25T10:39:32+01:00" level=debug msg="completed keyexchange" Mar 25 10:39:32 katarynka go-librespot[1469]: time="2026-03-25T10:39:32+01:00" level=debug msg="completed challenge" Mar 25 10:39:32 katarynka go-librespot[1469]: time="2026-03-25T10:39:32+01:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Mar 25 10:39:32 katarynka systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 25 10:39:32 katarynka systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 25 10:39:32 katarynka sudo[1484]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-03-25 10:38' Mar 25 10:39:32 katarynka sudo[1484]: 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"